SetupFramework: log thread error to console

Because logger.error from a non-main thread is lost.

+ Increase verbosity of virtualenv exception.
+ Introduce LocalExecution.py library.
+ Include multiple other style improvements.
+ Add some ssh.py improvements:
  + Accept also commands of OptionString type.
  + Introduce a limited form of raise_from for exception chaining.
  + Add include_reason argument to exec_cmd_no_error.

Change-Id: I0cd92bcdaa1a5c4cc20cb99067593fc3b40d2c31
Signed-off-by: Vratko Polak <vrpolak@cisco.com>

1 files changed, 53 insertions, 74 deletions

diff --git a/resources/libraries/python/SetupFramework.py b/resources/libraries/python/SetupFramework.py
index 9aff15278e..a1e4e7a679 100644
--- a/resources/libraries/python/SetupFramework.py
+++ b/resources/libraries/python/SetupFramework.py
@@ -1,4 +1,4 @@
-# Copyright (c) 2018 Cisco and/or its affiliates.
+# Copyright (c) 2019 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:
@@ -16,18 +16,16 @@ nodes. All tasks required to be run before the actual tests are started is
 supposed to end up here.
 """
 
-import datetime
 from os import environ, remove
 from os.path import basename
-from shlex import split
-from subprocess import Popen, PIPE
 from tempfile import NamedTemporaryFile
 import threading
 
 from robot.api import logger
 
-from resources.libraries.python.ssh import SSH
 from resources.libraries.python.Constants import Constants as con
+from resources.libraries.python.ssh import exec_cmd_no_error, scp_node
+from resources.libraries.python.LocalExecution import run
 from resources.libraries.python.topology import NodeType
 
 __all__ = ["SetupFramework"]
@@ -54,18 +52,9 @@ def pack_framework_dir():
     file_name = tmpfile.name
     tmpfile.close()
 
-    proc = Popen(
-        split("tar --sparse --exclude-vcs --exclude=output*.xml "
-              "--exclude=./tmp -zcf {0} ."
-              .format(file_name)), stdout=PIPE, stderr=PIPE)
-    (stdout, stderr) = proc.communicate()
-
-    logger.debug(stdout)
-    logger.debug(stderr)
-
-    return_code = proc.wait()
-    if return_code != 0:
-        raise RuntimeError("Could not pack testing framework.")
+    run(["tar", "--sparse", "--exclude-vcs", "--exclude=output*.xml",
+         "--exclude=./tmp", "-zcf", file_name, "."],
+        check=True, msg="Could not pack testing framework")
 
     return file_name
 
@@ -79,12 +68,10 @@ def copy_tarball_to_node(tarball, node):
     :type node: dict
     :returns: nothing
     """
-    logger.console('Copying tarball to {0}'.format(node['host']))
-    ssh = SSH()
-    ssh.connect(node)
-
-    ssh.scp(tarball, "/tmp/")
-    logger.console('Copying tarball to {0} done'.format(node['host']))
+    host = node['host']
+    logger.console('Copying tarball to {0} starts.'.format(host))
+    scp_node(node, tarball, "/tmp/")
+    logger.console('Copying tarball to {0} done.'.format(host))
 
 
 def extract_tarball_at_node(tarball, node):
@@ -99,18 +86,16 @@ def extract_tarball_at_node(tarball, node):
     :returns: nothing
     :raises RuntimeError: When failed to unpack tarball.
     """
-    logger.console('Extracting tarball to {0} on {1}'
-                   .format(con.REMOTE_FW_DIR, node['host']))
-    ssh = SSH()
-    ssh.connect(node)
-    (ret_code, _, _) = ssh.exec_command(
-        'sudo rm -rf {1}; mkdir {1} ; tar -zxf {0} -C {1}; rm -f {0}'
-        .format(tarball, con.REMOTE_FW_DIR), timeout=30)
-    if ret_code != 0:
-        raise RuntimeError('Failed to extract {0} at node {1}'
-                           .format(tarball, node['host']))
-    logger.console('Extracting tarball to {0} on {1} done'
-                   .format(con.REMOTE_FW_DIR, node['host']))
+    host = node['host']
+    logger.console('Extracting tarball to {0} on {1} starts.'
+                   .format(con.REMOTE_FW_DIR, host))
+    exec_cmd_no_error(
+        node, "sudo rm -rf {1}; mkdir {1}; tar -zxf {0} -C {1};"
+        " rm -f {0}".format(tarball, con.REMOTE_FW_DIR),
+        message='Failed to extract {0} at node {1}'.format(tarball, host),
+        timeout=30, include_reason=True)
+    logger.console('Extracting tarball to {0} on {1} done.'
+                   .format(con.REMOTE_FW_DIR, host))
 
 
 def create_env_directory_at_node(node):
@@ -121,21 +106,16 @@ def create_env_directory_at_node(node):
     :returns: nothing
     :raises RuntimeError: When failed to setup virtualenv.
     """
-    logger.console('Virtualenv setup including requirements.txt on {0}'
-                   .format(node['host']))
-    ssh = SSH()
-    ssh.connect(node)
-    (ret_code, _, _) = ssh.exec_command(
-        'cd {0} && rm -rf env && '
-        'virtualenv --system-site-packages --never-download env && '
-        '. env/bin/activate && '
-        'pip install -r requirements.txt'
-        .format(con.REMOTE_FW_DIR), timeout=100)
-    if ret_code != 0:
-        raise RuntimeError('Virtualenv setup including requirements.txt on {0}'
-                           .format(node['host']))
-
-    logger.console('Virtualenv on {0} created'.format(node['host']))
+    host = node['host']
+    logger.console('Virtualenv setup including requirements.txt on {0} starts.'
+                   .format(host))
+    exec_cmd_no_error(
+        node, 'cd {0} && rm -rf env'
+        ' && virtualenv --system-site-packages --never-download env'
+        ' && source env/bin/activate && pip install -r requirements.txt'
+        .format(con.REMOTE_FW_DIR), timeout=100, include_reason=True,
+        message="Failed install at node {host}".format(host=host))
+    logger.console('Virtualenv setup on {0} done.'.format(host))
 
 
 def setup_node(node, tarball, remote_tarball, results=None):
@@ -152,17 +132,18 @@ def setup_node(node, tarball, remote_tarball, results=None):
     :returns: True - success, False - error
     :rtype: bool
     """
+    host = node['host']
     try:
         copy_tarball_to_node(tarball, node)
         extract_tarball_at_node(remote_tarball, node)
         if node['type'] == NodeType.TG:
             create_env_directory_at_node(node)
     except RuntimeError as exc:
-        logger.error("Node {0} setup failed, error:'{1}'"
-                     .format(node['host'], exc.message))
+        logger.console("Node {node} setup failed, error: {err!r}".format(
+            node=host, err=exc))
         result = False
     else:
-        logger.console('Setup of node {0} done'.format(node['host']))
+        logger.console('Setup of node {0} done.'.format(host))
         result = True
 
     if isinstance(results, list):
@@ -186,16 +167,15 @@ def delete_framework_dir(node):
     :param node: Node to delete framework directory on.
     :type node: dict
     """
-    logger.console('Deleting framework directory on {0}'
-                   .format(node['host']))
-    ssh = SSH()
-    ssh.connect(node)
-    (ret_code, _, _) = ssh.exec_command(
-        'sudo rm -rf {0}'
-        .format(con.REMOTE_FW_DIR), timeout=100)
-    if ret_code != 0:
-        raise RuntimeError('Deleting framework directory on {0} failed'
-                           .format(node))
+    host = node['host']
+    logger.console(
+        'Deleting framework directory on {0} starts.'.format(host))
+    exec_cmd_no_error(
+        node, 'sudo rm -rf {0}'.format(con.REMOTE_FW_DIR),
+        message="Framework delete failed at node {host}".format(host=host),
+        timeout=100, include_reason=True)
+    logger.console(
+        'Deleting framework directory on {0} done.'.format(host))
 
 
 def cleanup_node(node, results=None):
@@ -208,13 +188,14 @@ def cleanup_node(node, results=None):
     :returns: True - success, False - error
     :rtype: bool
     """
+    host = node['host']
     try:
         delete_framework_dir(node)
     except RuntimeError:
-        logger.error("Cleanup of node {0} failed".format(node['host']))
+        logger.error("Cleanup of node {0} failed.".format(host))
         result = False
     else:
-        logger.console('Cleanup of node {0} done'.format(node['host']))
+        logger.console('Cleanup of node {0} done.'.format(host))
         result = True
 
     if isinstance(results, list):
@@ -249,10 +230,8 @@ class SetupFramework(object):
         threads = []
 
         for node in nodes.values():
-            thread = threading.Thread(target=setup_node, args=(node,
-                                                               tarball,
-                                                               remote_tarball,
-                                                               results))
+            args = node, tarball, remote_tarball, results
+            thread = threading.Thread(target=setup_node, args=args)
             thread.start()
             threads.append(thread)
 
@@ -266,9 +245,9 @@ class SetupFramework(object):
 
         delete_local_tarball(tarball)
         if all(results):
-            logger.console('All nodes are ready')
+            logger.console('All nodes are ready.')
         else:
-            raise RuntimeError('Failed to setup framework')
+            raise RuntimeError('Failed to setup framework.')
 
 
 class CleanupFramework(object):
@@ -293,7 +272,7 @@ class CleanupFramework(object):
             threads.append(thread)
 
         logger.info(
-            'Executing node cleanups in parallel, waiting for threads to end')
+            'Executing node cleanups in parallel, waiting for threads to end.')
 
         for thread in threads:
             thread.join()
@@ -301,6 +280,6 @@ class CleanupFramework(object):
         logger.info('Results: {0}'.format(results))
 
         if all(results):
-            logger.console('All nodes cleaned up')
+            logger.console('All nodes cleaned up.')
         else:
-            raise RuntimeError('Failed to cleaned up framework')
+            raise RuntimeError('Failed to cleaned up framework.')