FIX: VAT SSH timeout

Currently when VAT cannot connect to VPP via direct API call, there is
inner timeout of ~100s until it quits and returns RC. In our code we are
setting outer timeout to 10/15s to detect if VAT is not responding. If
VAT does not respond quickly enough due to e.g VPP crash, we are
incorrectly reporting SSHTimout exception.

This fix is suppose to set correct timeout values and also to set some
of the calls like show run|hard|err / clear to detect whether they were
successfull or not.

+ Various small library cleanup.

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

4 files changed, 56 insertions, 61 deletions

diff --git a/resources/libraries/python/VatExecutor.py b/resources/libraries/python/VatExecutor.py
index c50fdbaf9a..f29e278e67 100644
--- a/resources/libraries/python/VatExecutor.py
+++ b/resources/libraries/python/VatExecutor.py
@@ -1,4 +1,4 @@
-# Copyright (c) 2016 Cisco and/or its affiliates.
+# Copyright (c) 2018 Cisco and/or its affiliates.
 # Licensed under the Apache License, Version 2.0 (the "License");
 # you may not use this file except in compliance with the License.
 # You may obtain a copy of the License at:
@@ -70,9 +70,10 @@ class VatExecutor(object):
         self._stdout = None
         self._stderr = None
         self._ret_code = None
+        self._script_name = None
 
-    def execute_script(self, vat_name, node, timeout=15, json_out=True):
-        """Copy local_path script to node, execute it and return result.
+    def execute_script(self, vat_name, node, timeout=120, json_out=True):
+        """Execute local_path script on node, and store result.
 
         :param vat_name: Name of the vat script file. Only the file name of
         the script is required, the resources path is prepended automatically.
@@ -83,31 +84,28 @@ class VatExecutor(object):
         :type node: dict
         :type timeout: int
         :type json_out: bool
-        :returns: Status code, stdout and stderr of executed VAT script.
-        :rtype: tuple
         :raises RuntimeError: If VAT script execution failed.
         """
-
         ssh = SSH()
         try:
             ssh.connect(node)
         except:
             raise SSHException("Cannot open SSH connection to execute VAT "
-                               "command(s) from template {0}".format(vat_name))
+                               "command(s) from vat script {name}"
+                               .format(name=vat_name))
 
         remote_file_path = '{0}/{1}/{2}'.format(Constants.REMOTE_FW_DIR,
                                                 Constants.RESOURCES_TPL_VAT,
                                                 vat_name)
-        # TODO this overwrites the output if the vat script has been used twice
-        # remote_file_out = remote_file_path + ".out"
 
-        cmd = "sudo -S {vat} {json} in {input} script".format(
-            vat=Constants.VAT_BIN_NAME,
+        cmd = "{vat_bin} {json} in {vat_path} script".format(
+            vat_bin=Constants.VAT_BIN_NAME,
             json="json" if json_out is True else "",
-            input=remote_file_path)
+            vat_path=remote_file_path)
 
         try:
-            (ret_code, stdout, stderr) = ssh.exec_command(cmd, timeout)
+            ret_code, stdout, stderr = ssh.exec_command_sudo(cmd=cmd,
+                                                             timeout=timeout)
         except SSHTimeout:
             logger.error("VAT script execution timeout: {0}".format(cmd))
             raise
@@ -117,12 +115,12 @@ class VatExecutor(object):
         self._ret_code = ret_code
         self._stdout = stdout
         self._stderr = stderr
+        self._script_name = vat_name
 
-        # TODO: download vpp_api_test output file
-        # self._delete_files(node, remote_file_path, remote_file_out)
-
-    def scp_and_execute_script(self, vat_name, node, timeout=15, json_out=True):
+    def scp_and_execute_script(self, vat_name, node, timeout=120,
+                               json_out=True):
         """Copy vat_name script to node, execute it and return result.
+        Store the content of vat script in VAT history.
 
         :param vat_name: Name of the vat script file.
         Full path and name of the script is required.
@@ -133,80 +131,80 @@ class VatExecutor(object):
         :type node: dict
         :type timeout: int
         :type json_out: bool
-        :returns: Status code, stdout and stderr of executed VAT script.
-        :rtype: tuple
         :raises RuntimeError: If VAT script execution failed.
         """
-
         ssh = SSH()
         try:
             ssh.connect(node)
         except:
             raise SSHException("Cannot open SSH connection to execute VAT "
-                               "command(s) from template {0}".format(vat_name))
+                               "command(s) from vat script {name}"
+                               .format(name=vat_name))
 
         ssh.scp(vat_name, vat_name)
 
-        cmd = "sudo -S {vat} {json} in {input} script".format(
+        cmd = "{vat_bin} {json} in {vat_path} script".format(
+            vat_bin=Constants.VAT_BIN_NAME,
             json="json" if json_out is True else "",
-            vat=Constants.VAT_BIN_NAME,
-            input=vat_name)
+            vat_path=vat_name)
 
         with open(vat_name, 'r') as tmp_f:
             VatHistory.add_to_vat_history(node, tmp_f.read())
 
         try:
-            (ret_code, stdout, stderr) = ssh.exec_command(cmd, timeout)
+            ret_code, stdout, stderr = ssh.exec_command_sudo(cmd=cmd,
+                                                             timeout=timeout)
         except SSHTimeout:
-            logger.error("VAT script execution timeout: {0}".format(cmd))
+            logger.error("VAT script execution timeout: {cmd}".format(cmd=cmd))
             raise
         except:
-            raise RuntimeError("VAT script execution failed: {0}".format(cmd))
+            raise RuntimeError("VAT script execution failed: {cmd}"
+                               .format(cmd=cmd))
 
         self._ret_code = ret_code
         self._stdout = stdout
         self._stderr = stderr
+        self._script_name = vat_name
 
         self._delete_files(node, vat_name)
 
-    def scp_and_execute_cli_script(self, fname, node, timeout=15,
+    def scp_and_execute_cli_script(self, vat_name, node, timeout=120,
                                    json_out=True):
         """Copy vat_name script to node, execute it and return result.
+        Store the content of vat script in VAT history.
 
-        :param fname: Name of the VPP script file.
+        :param vat_name: Name of the VPP script file.
         Full path and name of the script is required.
         :param node: Node to execute the VPP script on.
         :param timeout: Seconds to allow the script to run.
         :param json_out: Require JSON output.
-        :type fname: str
+        :type vat_name: str
         :type node: dict
         :type timeout: int
         :type json_out: bool
-        :returns: Status code, stdout and stderr of executed CLI script.
-        :rtype: tuple
         :raises RuntimeError: If CLI script execution failed.
         """
-
         ssh = SSH()
         try:
             ssh.connect(node)
         except:
-            raise SSHException("Cannot open SSH connection to execute CLI "
-                               "command(s) from template {0}".format(fname))
+            raise SSHException("Cannot open SSH connection to execute VAT "
+                               "command(s) from vat script {name}"
+                               .format(name=vat_name))
 
-        ssh.scp(fname, fname)
+        ssh.scp(vat_name, vat_name)
 
-        cmd = "{vat} {json}".format(json="json" if json_out is True else "",
-                                    vat=Constants.VAT_BIN_NAME)
-        cmd_input = "exec exec {0}".format(fname)
+        cmd = "{vat_bin} {json}".format(vat_bin=Constants.VAT_BIN_NAME,
+                                        json="json" if json_out is True else "")
+        cmd_input = "exec exec {vat_path}".format(vat_path=vat_name)
 
         VatHistory.add_to_vat_history(node, cmd_input)
-        with open(fname, 'r') as tmp_f:
+        with open(vat_name, 'r') as tmp_f:
             VatHistory.add_to_vat_history(node, tmp_f.read())
 
         try:
-            (ret_code, stdout, stderr) = ssh.exec_command_sudo(cmd, cmd_input,
-                                                               timeout)
+            ret_code, stdout, stderr = ssh.exec_command_sudo(cmd, cmd_input,
+                                                             timeout)
         except SSHTimeout:
             logger.error("CLI script execution timeout: {0}{1}".
                          format(cmd, "<<< " + cmd_input if cmd_input else ""))
@@ -218,10 +216,11 @@ class VatExecutor(object):
         self._ret_code = ret_code
         self._stdout = stdout
         self._stderr = stderr
+        self._script_name = cmd_input
 
-        self._delete_files(node, fname)
+        self._delete_files(node, vat_name)
 
-    def execute_script_json_out(self, vat_name, node, timeout=15):
+    def execute_script_json_out(self, vat_name, node, timeout=120):
         """Pass all arguments to 'execute_script' method, then cleanup returned
         json output.
 
@@ -249,7 +248,7 @@ class VatExecutor(object):
         ssh = SSH()
         ssh.connect(node)
         files = " ".join([str(x) for x in files])
-        ssh.exec_command("rm {0}".format(files))
+        ssh.exec_command("rm {files}".format(files=files))
 
     def script_should_have_failed(self):
         """Read return code from last executed script and raise exception if the
@@ -258,7 +257,8 @@ class VatExecutor(object):
             raise Exception("First execute the script!")
         if self._ret_code == 0:
             raise AssertionError(
-                "Script execution passed, but failure was expected")
+                "VAT Script execution passed, but failure was expected: {cmd}"
+                .format(cmd=self._script_name))
 
     def script_should_have_passed(self):
         """Read return code from last executed script and raise exception if the
@@ -267,7 +267,8 @@ class VatExecutor(object):
             raise Exception("First execute the script!")
         if self._ret_code != 0:
             raise AssertionError(
-                "Script execution failed, but success was expected")
+                "VAT Script execution failed, but success was expected: {cmd}"
+                .format(cmd=self._script_name))
 
     def get_script_stdout(self):
         """Returns value of stdout from last executed script."""
diff --git a/resources/libraries/python/VppCounters.py b/resources/libraries/python/VppCounters.py
index 8247a1e8ab..5dc14a9a4e 100644
--- a/resources/libraries/python/VppCounters.py
+++ b/resources/libraries/python/VppCounters.py
@@ -26,16 +26,6 @@ class VppCounters(object):
     def __init__(self):
         self._stats_table = None
 
-    def vpp_nodes_clear_interface_counters(self, nodes):
-        """Clear interface counters on all VPP nodes in topology.
-
-        :param nodes: Nodes in topology.
-        :type nodes: dict
-        """
-        for node in nodes.values():
-            if node['type'] == NodeType.DUT:
-                self.vpp_clear_interface_counters(node)
-
     @staticmethod
     def vpp_show_errors(node):
         """Run "show errors" debug CLI command.
@@ -45,6 +35,7 @@ class VppCounters(object):
         """
         vat = VatExecutor()
         vat.execute_script("show_errors.vat", node, json_out=False)
+        vat.script_should_have_passed()
 
     @staticmethod
     def vpp_show_errors_verbose(node):
@@ -55,6 +46,7 @@ class VppCounters(object):
         """
         vat = VatExecutor()
         vat.execute_script("show_errors_verbose.vat", node, json_out=False)
+        vat.script_should_have_passed()
 
     @staticmethod
     def vpp_show_errors_on_all_duts(nodes, verbose=False):
@@ -82,6 +74,7 @@ class VppCounters(object):
         """
         vat = VatExecutor()
         vat.execute_script("show_runtime.vat", node, json_out=False)
+        vat.script_should_have_passed()
 
     @staticmethod
     def show_runtime_counters_on_all_duts(nodes):
@@ -103,6 +96,7 @@ class VppCounters(object):
         """
         vat = VatExecutor()
         vat.execute_script("show_runtime_verbose.vat", node, json_out=False)
+        vat.script_should_have_passed()
 
     @staticmethod
     def vpp_show_hardware_detail(node):
@@ -113,6 +107,7 @@ class VppCounters(object):
         """
         vat = VatExecutor()
         vat.execute_script("show_hardware_detail.vat", node, json_out=False)
+        vat.script_should_have_passed()
 
     @staticmethod
     def vpp_clear_runtime(node):
@@ -123,6 +118,7 @@ class VppCounters(object):
         """
         vat = VatExecutor()
         vat.execute_script("clear_runtime.vat", node, json_out=False)
+        vat.script_should_have_passed()
 
     @staticmethod
     def clear_runtime_counters_on_all_duts(nodes):
diff --git a/resources/libraries/python/ssh.py b/resources/libraries/python/ssh.py
index 11b05837bf..7fa10bcb51 100644
--- a/resources/libraries/python/ssh.py
+++ b/resources/libraries/python/ssh.py
@@ -132,7 +132,6 @@ class SSH(object):
         :rtype: tuple(int, str, str)
         :raise SSHTimeout: If command is not finished in timeout time.
         """
-        start = time()
         stdout = StringIO.StringIO()
         stderr = StringIO.StringIO()
         try:
@@ -147,6 +146,7 @@ class SSH(object):
         logger.trace('exec_command on {0}: {1}'
                      .format(self._ssh.get_transport().getpeername(), cmd))
 
+        start = time()
         chan.exec_command(cmd)
         while not chan.exit_status_ready() and timeout is not None:
             if chan.recv_ready():
@@ -176,8 +176,6 @@ class SSH(object):
         logger.trace('exec_command on {0} took {1} seconds'.format(
             self._ssh.get_transport().getpeername(), end-start))
 
-        logger.trace('chan_recv/_stderr took {} seconds'.format(time()-end))
-
         logger.trace('return RC {}'.format(return_code))
         logger.trace('return STDOUT {}'.format(stdout.getvalue()))
         logger.trace('return STDERR {}'.format(stderr.getvalue()))
diff --git a/resources/libraries/robot/shared/counters.robot b/resources/libraries/robot/shared/counters.robot
index 8a3e611faa..fdc26af2dd 100644
--- a/resources/libraries/robot/shared/counters.robot
+++ b/resources/libraries/robot/shared/counters.robot
@@ -19,7 +19,7 @@
 | Clear interface counters on all vpp nodes in topology
 | | [Documentation] | Clear interface counters on all VPP nodes in topology
 | | [Arguments] | ${nodes}
-| | Vpp Nodes Clear Interface Counters | ${nodes}
+| | Clear Interface Counters on all DUTs | ${nodes}
 
 | Check ipv4 interface counter
 | | [Documentation] | Check that ipv4 interface counter has right value