FIX: SSH socket reading error

Currently if the command timeouts due to the nature of script execution
we are trying to again read from socket after timeout on seesion
expired. This patch is supposed to fix the behaviour and eliminate the
second read from channel after it was cloed.

Change-Id: Ib0028e901eb6ff4d10ca77d2ea19f9e770e6cef4
Signed-off-by: Peter Mikus <pmikus@cisco.com>

2 files changed, 18 insertions, 19 deletions

diff --git a/resources/libraries/python/TrafficScriptExecutor.py b/resources/libraries/python/TrafficScriptExecutor.py
index 58d48d3ca9..13696dee8d 100644
--- a/resources/libraries/python/TrafficScriptExecutor.py
+++ b/resources/libraries/python/TrafficScriptExecutor.py
@@ -13,8 +13,6 @@
 
 """Traffic script executor library."""
 
-from robot.api import logger
-
 from resources.libraries.python.constants import Constants
 from resources.libraries.python.ssh import SSH
 
@@ -55,7 +53,6 @@ class TrafficScriptExecutor(object):
         :raises RuntimeError: ARP reply timeout.
         :raises RuntimeError: Traffic script execution failed.
         """
-        logger.trace("{}".format(timeout))
         ssh = SSH()
         ssh.connect(node)
         cmd = ("cd {}; " +
@@ -65,12 +62,9 @@ class TrafficScriptExecutor(object):
                "resources/traffic_scripts/{} {}") \
                   .format(Constants.REMOTE_FW_DIR, script_file_name,
                           script_args)
-        (ret_code, stdout, stderr) = ssh.exec_command_sudo(
-            'sh -c "{}"'.format(TrafficScriptExecutor._escape(cmd)),
+        ret_code, stdout, stderr = ssh.exec_command_sudo(
+            'sh -c "{cmd}"'.format(cmd=TrafficScriptExecutor._escape(cmd)),
             timeout=timeout)
-        logger.debug("stdout: {}".format(stdout))
-        logger.debug("stderr: {}".format(stderr))
-        logger.debug("ret_code: {}".format(ret_code))
         if ret_code != 0:
             if "RuntimeError: ICMP echo Rx timeout" in stderr:
                 raise RuntimeError("ICMP echo Rx timeout")
diff --git a/resources/libraries/python/ssh.py b/resources/libraries/python/ssh.py
index 7fa10bcb51..469d77ffc2 100644
--- a/resources/libraries/python/ssh.py
+++ b/resources/libraries/python/ssh.py
@@ -136,15 +136,19 @@ class SSH(object):
         stderr = StringIO.StringIO()
         try:
             chan = self._ssh.get_transport().open_session(timeout=5)
+            peer = self._ssh.get_transport().getpeername()
         except AttributeError:
             self._reconnect()
             chan = self._ssh.get_transport().open_session(timeout=5)
+            peer = self._ssh.get_transport().getpeername()
         except SSHException:
             self._reconnect()
             chan = self._ssh.get_transport().open_session(timeout=5)
+            peer = self._ssh.get_transport().getpeername()
         chan.settimeout(timeout)
-        logger.trace('exec_command on {0}: {1}'
-                     .format(self._ssh.get_transport().getpeername(), cmd))
+
+        logger.trace('exec_command on {peer} with timeout {timeout}: {cmd}'
+                     .format(peer=peer, timeout=timeout, cmd=cmd))
 
         start = time()
         chan.exec_command(cmd)
@@ -157,10 +161,11 @@ class SSH(object):
 
             if time() - start > timeout:
                 raise SSHTimeout(
-                    'Timeout exception during execution of command: {0}\n'
-                    'Current contents of stdout buffer: {1}\n'
-                    'Current contents of stderr buffer: {2}\n'
-                    .format(cmd, stdout.getvalue(), stderr.getvalue())
+                    'Timeout exception during execution of command: {cmd}\n'
+                    'Current contents of stdout buffer: {stdout}\n'
+                    'Current contents of stderr buffer: {stderr}\n'
+                    .format(cmd=cmd, stdout=stdout.getvalue(),
+                            stderr=stderr.getvalue())
                 )
 
             sleep(0.1)
@@ -173,12 +178,12 @@ class SSH(object):
             stderr.write(chan.recv_stderr(self.__MAX_RECV_BUF))
 
         end = time()
-        logger.trace('exec_command on {0} took {1} seconds'.format(
-            self._ssh.get_transport().getpeername(), end-start))
+        logger.trace('exec_command on {peer} took {total} seconds'.
+                     format(peer=peer, total=end-start))
 
-        logger.trace('return RC {}'.format(return_code))
-        logger.trace('return STDOUT {}'.format(stdout.getvalue()))
-        logger.trace('return STDERR {}'.format(stderr.getvalue()))
+        logger.trace('return RC {rc}'.format(rc=return_code))
+        logger.trace('return STDOUT {stdout}'.format(stdout=stdout.getvalue()))
+        logger.trace('return STDERR {stderr}'.format(stderr=stderr.getvalue()))
         return return_code, stdout.getvalue(), stderr.getvalue()
 
     def exec_command_sudo(self, cmd, cmd_input=None, timeout=30):