From 4d2e646f21659a6540312779190b03aed91395d5 Mon Sep 17 00:00:00 2001 From: Jan Gelety Date: Thu, 5 Oct 2017 13:20:20 +0200 Subject: [PATCH] CSIT-828: Fix the output of failed VAT execution Change-Id: Id387bd685142dcfaa17f0236e930e40e6c0bce5a Signed-off-by: Jan Gelety --- resources/libraries/python/VatExecutor.py | 220 +++++++++++++++++++++++------- resources/libraries/python/ssh.py | 14 +- 2 files changed, 181 insertions(+), 53 deletions(-) diff --git a/resources/libraries/python/VatExecutor.py b/resources/libraries/python/VatExecutor.py index a3f12bf46f..841bd0c6cb 100644 --- a/resources/libraries/python/VatExecutor.py +++ b/resources/libraries/python/VatExecutor.py @@ -15,32 +15,55 @@ import json +from paramiko.ssh_exception import SSHException from robot.api import logger -from resources.libraries.python.ssh import SSH +from resources.libraries.python.ssh import SSH, SSHTimeout from resources.libraries.python.constants import Constants from resources.libraries.python.VatHistory import VatHistory - __all__ = ['VatExecutor'] -def cleanup_vat_json_output(json_output): +def cleanup_vat_json_output(json_output, vat_name=None): """Return VAT JSON output cleaned from VAT clutter. Clean up VAT JSON output from clutter like vat# prompts and such. :param json_output: Cluttered JSON output. + :param vat_name: Name of the VAT script. + :type json_output: JSON + :type vat_name: str :returns: Cleaned up output JSON string. + :rtype: JSON """ retval = json_output clutter = ['vat#', 'dump_interface_table error: Misc'] + if vat_name: + remote_file_path = '{0}/{1}/{2}'.format(Constants.REMOTE_FW_DIR, + Constants.RESOURCES_TPL_VAT, + vat_name) + clutter.append("{0}(2):".format(remote_file_path)) for garbage in clutter: retval = retval.replace(garbage, '') return retval +def get_vpp_pid(node): + """Get PID of running VPP process. + + :param node: DUT node. + :type node: dict + :returns: PID of VPP process / List of PIDs if more VPP processes are + running on the DUT node. + :rtype: int or list + """ + import resources.libraries.python.DUTSetup as PidLib + pid = PidLib.DUTSetup.get_vpp_pid(node) + return pid + + class VatExecutor(object): """Contains methods for executing VAT commands on DUTs.""" def __init__(self): @@ -48,7 +71,7 @@ class VatExecutor(object): self._stderr = None self._ret_code = None - def execute_script(self, vat_name, node, timeout=10, json_out=True): + def execute_script(self, vat_name, node, timeout=15, json_out=True): """Copy local_path script to node, execute it and return result. :param vat_name: Name of the vat script file. Only the file name of @@ -56,11 +79,21 @@ class VatExecutor(object): :param node: Node to execute the VAT script on. :param timeout: Seconds to allow the script to run. :param json_out: Require JSON output. - :return: (rc, stdout, stderr) tuple. + :type vat_name: str + :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() - ssh.connect(node) + try: + ssh.connect(node) + except: + raise SSHException("Cannot open SSH connection to execute VAT " + "command(s) from template {0}".format(vat_name)) remote_file_path = '{0}/{1}/{2}'.format(Constants.REMOTE_FW_DIR, Constants.RESOURCES_TPL_VAT, @@ -68,23 +101,27 @@ class VatExecutor(object): # 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} < {input}".format( + cmd = "sudo -S {vat} {json} in {input} script".format( vat=Constants.VAT_BIN_NAME, json="json" if json_out is True else "", input=remote_file_path) - (ret_code, stdout, stderr) = ssh.exec_command(cmd, timeout) + + try: + (ret_code, stdout, stderr) = ssh.exec_command(cmd, timeout) + except SSHTimeout: + logger.error("VAT script execution timeout: {0}".format(cmd)) + raise + except: + raise RuntimeError("VAT script execution failed: {0}".format(cmd)) + self._ret_code = ret_code self._stdout = stdout self._stderr = stderr - logger.trace("Command '{0}' returned {1}'".format(cmd, self._ret_code)) - logger.trace("stdout: '{0}'".format(self._stdout)) - logger.trace("stderr: '{0}'".format(self._stderr)) - # 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=10, json_out=True): + def scp_and_execute_script(self, vat_name, node, timeout=15, json_out=True): """Copy vat_name script to node, execute it and return result. :param vat_name: Name of the vat script file. @@ -96,31 +133,40 @@ class VatExecutor(object): :type node: dict :type timeout: int :type json_out: bool - :returns: Status code, stdout and stderr of executed script + :returns: Status code, stdout and stderr of executed VAT script. :rtype: tuple + :raises RuntimeError: If VAT script execution failed. """ ssh = SSH() - ssh.connect(node) + try: + ssh.connect(node) + except: + raise SSHException("Cannot open SSH connection to execute VAT " + "command(s) from template {0}".format(vat_name)) ssh.scp(vat_name, vat_name) - cmd = "sudo -S {vat} {json} < {input}".format( + cmd = "sudo -S {vat} {json} in {input} script".format( json="json" if json_out is True else "", vat=Constants.VAT_BIN_NAME, input=vat_name) - (ret_code, stdout, stderr) = ssh.exec_command(cmd, timeout) + + try: + (ret_code, stdout, stderr) = ssh.exec_command(cmd, timeout) + except SSHTimeout: + logger.error("VAT script execution timeout: {0}".format(cmd)) + raise + except: + raise RuntimeError("VAT script execution failed: {0}".format(cmd)) + self._ret_code = ret_code self._stdout = stdout self._stderr = stderr - logger.trace("Command '{0}' returned {1}'".format(cmd, self._ret_code)) - logger.trace("stdout: '{0}'".format(self._stdout)) - logger.trace("stderr: '{0}'".format(self._stderr)) - self._delete_files(node, vat_name) - def scp_and_execute_cli_script(self, fname, node, timeout=10, + def scp_and_execute_cli_script(self, fname, node, timeout=15, json_out=True): """Copy vat_name script to node, execute it and return result. @@ -129,39 +175,59 @@ class VatExecutor(object): :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 vat_name: str + :type fname: str :type node: dict :type timeout: int :type json_out: bool - :returns: Status code, stdout and stderr of executed script + :returns: Status code, stdout and stderr of executed CLI script. :rtype: tuple + :raises RuntimeError: If CLI script execution failed. """ ssh = SSH() - ssh.connect(node) + try: + ssh.connect(node) + except: + raise SSHException("Cannot open SSH connection to execute CLI " + "command(s) from template {0}".format(fname)) ssh.scp(fname, fname) cmd = "{vat} {json}".format(json="json" if json_out is True else "", vat=Constants.VAT_BIN_NAME) cmd_input = "exec exec {0}".format(fname) - (ret_code, stdout, stderr) = ssh.exec_command_sudo(cmd, cmd_input, - timeout) + + try: + (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 "")) + raise + except: + raise RuntimeError("CLI script execution failed: {0}{1}".format( + cmd, "<<< " + cmd_input if cmd_input else "")) + self._ret_code = ret_code self._stdout = stdout self._stderr = stderr - logger.trace("Command '{0}' returned {1}'".format(cmd, self._ret_code)) - logger.trace("stdout: '{0}'".format(self._stdout)) - logger.trace("stderr: '{0}'".format(self._stderr)) - self._delete_files(node, fname) - def execute_script_json_out(self, vat_name, node, timeout=10): + def execute_script_json_out(self, vat_name, node, timeout=15): """Pass all arguments to 'execute_script' method, then cleanup returned - json output.""" + json output. + + :param vat_name: Name of the vat script file. Only the file name of + the script is required, the resources path is prepended automatically. + :param node: Node to execute the VAT script on. + :param timeout: Seconds to allow the script to run. + :type vat_name: str + :type node: dict + :type timeout: int + """ self.execute_script(vat_name, node, timeout, json_out=True) - self._stdout = cleanup_vat_json_output(self._stdout) + self._stdout = cleanup_vat_json_output(self._stdout, vat_name=vat_name) @staticmethod def _delete_files(node, *files): @@ -239,11 +305,37 @@ class VatTerminal(object): self._node = node self._ssh = SSH() self._ssh.connect(self._node) - self._tty = self._ssh.interactive_terminal_open() - self._ssh.interactive_terminal_exec_command( - self._tty, - 'sudo -S {}{}'.format(Constants.VAT_BIN_NAME, json_text), - self.__VAT_PROMPT) + try: + self._tty = self._ssh.interactive_terminal_open() + except Exception: + raise RuntimeError("Cannot open interactive terminal on node {0}". + format(self._node)) + + for _ in range(3): + try: + self._ssh.interactive_terminal_exec_command( + self._tty, + 'sudo -S {0}{1}'.format(Constants.VAT_BIN_NAME, json_text), + self.__VAT_PROMPT) + except Exception: + continue + else: + break + else: + vpp_pid = get_vpp_pid(self._node) + if vpp_pid: + if isinstance(vpp_pid, int): + logger.trace("VPP running on node {0}". + format(self._node['host'])) + else: + logger.error("More instances of VPP running on node {0}.". + format(self._node['host'])) + else: + logger.error("VPP not running on node {0}.". + format(self._node['host'])) + raise RuntimeError("Failed to open VAT console on node {0}". + format(self._node['host'])) + self._exec_failure = False self.vat_stdout = None @@ -262,16 +354,29 @@ class VatTerminal(object): None if not in JSON mode. """ VatHistory.add_to_vat_history(self._node, cmd) - logger.debug("Executing command in VAT terminal: {}".format(cmd)) + logger.debug("Executing command in VAT terminal: {0}".format(cmd)) try: out = self._ssh.interactive_terminal_exec_command(self._tty, cmd, self.__VAT_PROMPT) self.vat_stdout = out - except: + except Exception: self._exec_failure = True - raise + vpp_pid = get_vpp_pid(self._node) + if vpp_pid: + if isinstance(vpp_pid, int): + raise RuntimeError("VPP running on node {0} but VAT command" + " {1} execution failed.". + format(self._node['host'], cmd)) + else: + raise RuntimeError("More instances of VPP running on node " + "{0}. VAT command {1} execution failed.". + format(self._node['host'], cmd)) + else: + raise RuntimeError("VPP not running on node {0}. VAT command " + "{1} execution failed.". + format(self._node['host'], cmd)) - logger.debug("VAT output: {}".format(out)) + logger.debug("VAT output: {0}".format(out)) if self.json: obj_start = out.find('{') obj_end = out.rfind('}') @@ -279,7 +384,7 @@ class VatTerminal(object): array_end = out.rfind(']') if obj_start == -1 and array_start == -1: - raise RuntimeError("VAT: no JSON data.") + raise RuntimeError("VAT command {0}: no JSON data.".format(cmd)) if obj_start < array_start or array_start == -1: start = obj_start @@ -297,10 +402,29 @@ class VatTerminal(object): """Close VAT terminal.""" # interactive terminal is dead, we only need to close session if not self._exec_failure: - self._ssh.interactive_terminal_exec_command(self._tty, - 'quit', - self.__LINUX_PROMPT) - self._ssh.interactive_terminal_close(self._tty) + try: + self._ssh.interactive_terminal_exec_command(self._tty, + 'quit', + self.__LINUX_PROMPT) + except Exception: + vpp_pid = get_vpp_pid(self._node) + if vpp_pid: + if isinstance(vpp_pid, int): + logger.trace("VPP running on node {0}.". + format(self._node['host'])) + else: + logger.error("More instances of VPP running on node " + "{0}.".format(self._node['host'])) + else: + logger.error("VPP not running on node {0}.". + format(self._node['host'])) + raise RuntimeError("Failed to close VAT console on node {0}". + format(self._node['host'])) + try: + self._ssh.interactive_terminal_close(self._tty) + except: + raise RuntimeError("Cannot close interactive terminal on node {0}". + format(self._node['host'])) def vat_terminal_exec_cmd_from_template(self, vat_template_file, **args): """Execute VAT script from a file. diff --git a/resources/libraries/python/ssh.py b/resources/libraries/python/ssh.py index 5777c32001..87fc02d3dd 100644 --- a/resources/libraries/python/ssh.py +++ b/resources/libraries/python/ssh.py @@ -157,10 +157,10 @@ class SSH(object): if time() - start > timeout: raise SSHTimeout( - 'Timeout exception.\n' - 'Current contents of stdout buffer: {0}\n' - 'Current contents of stderr buffer: {1}\n' - .format(stdout.getvalue(), stderr.getvalue()) + '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()) ) sleep(0.1) @@ -260,6 +260,7 @@ class SSH(object): logger.error('Channel exit status ready') break except socket.timeout: + logger.error('Socket timeout: {0}'.format(buf)) raise Exception('Socket timeout: {0}'.format(buf)) return chan @@ -293,7 +294,10 @@ class SSH(object): logger.error('Channel exit status ready') break except socket.timeout: - raise Exception('Socket timeout: {0}'.format(buf)) + logger.error('Socket timeout during execution of command: ' + '{0}\nBuffer content:\n{1}'.format(cmd, buf)) + raise Exception('Socket timeout during execution of command: ' + '{0}\nBuffer content:\n{1}'.format(cmd, buf)) tmp = buf.replace(cmd.replace('\n', ''), '') for item in prompt: tmp.replace(item, '') -- 2.16.6