Merge lp:~nuclearbob/utah/ssh-stacktrace into lp:utah

[Max Brustkern]

I added stacktrace logging for external failures for ssh connections. When I run this command to connect to a machine that doesn't exist:
PYTHONPATH=. ./examples/run_utah_tests.py --skip-provisioning --name blarg /usr/share/utah/client/examples/pass.run
I get this:
2013-08-06 10:52:01,780 ssh INFO: Checking for ssh availability
2013-08-06 10:52:01,781 ssh DEBUG: Traceback (most recent call last):
  File "/home/max/bzr/utah/utah/provisioning/ssh.py", line 316, in sshcheck
    key_filename=config.sshprivatekey)
  File "/usr/lib/python2.7/dist-packages/paramiko/client.py", line 282, in connect
    for (family, socktype, proto, canonname, sockaddr) in socket.getaddrinfo(hostname, port, socket.AF_UNSPEC, socket.SOCK_STREAM):
gaierror: [Errno -2] Name or service not known

2013-08-06 10:52:01,781 ssh DEBUG: Caught [Errno -2] Name or service not known, retrying sshcheck() in 3 seconds

[Andy Doan (doanac)]

review: Approve

[lp:~nuclearbob/utah/ssh-stacktrace]

987. By Andy Doan on 2013-08-06

Logging stacktraces for SSH failures

=== modified file 'utah/provisioning/ssh.py'
--- utah/provisioning/ssh.py	2013-06-10 07:07:59 +0000
+++ utah/provisioning/ssh.py	2013-08-06 14:55:35 +0000
@@ -24,6 +24,7 @@
 import socket
 
 from stat import S_ISDIR
+from traceback import format_exc
 
 import paramiko
 
@@ -123,6 +124,7 @@
                 # Make sure socket.timeout is raised
                 channel.recv(0)
             except socket.timeout:
+                self.ssh_logger.debug(format_exc())
                 raise utah.timeout.UTAHTimeout(
                     'SSH command timed out {!r} after {} seconds'
                     .format(commandstring, timeout))
@@ -130,12 +132,14 @@
             retval = channel.recv_exit_status()
 
         except paramiko.BadHostKeyException as err:
+            self.ssh_logger.debug(format_exc())
             raise UTAHProvisioningException(
                 'Host key exception encountered; '
                 'machine may be in use by another process: {}'
                 .format(err), external=True)
         except (paramiko.AuthenticationException, paramiko.SSHException,
                 socket.error) as err:
+            self.ssh_logger.debug(format_exc())
             raise UTAHProvisioningException(err)
         finally:
             self.ssh_logger.debug('Closing SSH connection')
@@ -206,12 +210,14 @@
                 remotepath = os.path.join(target, os.path.basename(localpath))
                 sftp_client.put(localpath, remotepath)
         except paramiko.BadHostKeyException as err:
+            self.ssh_logger.debug(format_exc())
             raise UTAHProvisioningException(
                 'Host key exception encountered; '
                 'machine may be in use by another process: {}'
                 .format(err), external=True)
         except (paramiko.AuthenticationException, paramiko.SSHException,
                 socket.error) as err:
+            self.ssh_logger.debug(format_exc())
             raise UTAHProvisioningException(err)
         finally:
             self.ssh_client.close()
@@ -250,12 +256,14 @@
                                      .format(remotepath, target))
                 sftp_client.get(remotepath, localpath)
         except paramiko.BadHostKeyException as err:
+            self.ssh_logger.debug(format_exc())
             raise UTAHProvisioningException(
                 'Host key exception encountered; '
                 'machine may be in use by another process: {}'
                 .format(err), external=True)
         except (paramiko.AuthenticationException, paramiko.SSHException,
                 socket.error) as err:
+            self.ssh_logger.debug(format_exc())
             raise UTAHProvisioningException(err)
         finally:
             self.ssh_client.close()
@@ -307,14 +315,17 @@
                                     username=config.user,
                                     key_filename=config.sshprivatekey)
         except paramiko.BadHostKeyException as err:
+            self.ssh_logger.debug(format_exc())
             raise UTAHProvisioningException(
                 'Host key exception encountered; '
                 'machine may be in use by another process: {}'
                 .format(err), external=True)
         except (paramiko.AuthenticationException,
                 paramiko.SSHException) as err:
+            self.ssh_logger.debug(format_exc())
             raise UTAHProvisioningException(err)
         except socket.error as err:
+            self.ssh_logger.debug(format_exc())
             raise UTAHProvisioningException(str(err), retry=True)
         finally:
             self.ssh_client.close()
@@ -377,6 +388,7 @@
                 self.pingpoll(timeout=self.connectivity_timeout,
                               checktimeout=self.check_timeout)
             except utah.timeout.UTAHTimeout:
+                self.ssh_logger.debug(format_exc())
                 # Ignore timeout for ping, since depending on the network
                 # configuration ssh might still work despite the ping failure.
                 self.logger.warning('Network connectivity (ping) failure')