FrameworkSetup: increase timeout
[csit.git] / resources / libraries / python / SetupFramework.py
index a1e4e7a..26a07c3 100644 (file)
@@ -1,4 +1,4 @@
-# Copyright (c) 2019 Cisco and/or its affiliates.
+# Copyright (c) 2021 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:
@@ -17,9 +17,9 @@ supposed to end up here.
 """
 
 from os import environ, remove
-from os.path import basename
 from tempfile import NamedTemporaryFile
 import threading
+import traceback
 
 from robot.api import logger
 
@@ -28,7 +28,7 @@ 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"]
+__all__ = [u"SetupFramework"]
 
 
 def pack_framework_dir():
@@ -40,21 +40,25 @@ def pack_framework_dir():
     """
 
     try:
-        directory = environ["TMPDIR"]
+        directory = environ[u"TMPDIR"]
     except KeyError:
         directory = None
 
     if directory is not None:
-        tmpfile = NamedTemporaryFile(suffix=".tgz", prefix="csit-testing-",
-                                     dir="{0}".format(directory))
+        tmpfile = NamedTemporaryFile(
+            suffix=u".tgz", prefix=u"csit-testing-", dir=f"{directory}"
+        )
     else:
-        tmpfile = NamedTemporaryFile(suffix=".tgz", prefix="csit-testing-")
+        tmpfile = NamedTemporaryFile(suffix=u".tgz", prefix=u"csit-testing-")
     file_name = tmpfile.name
     tmpfile.close()
 
-    run(["tar", "--sparse", "--exclude-vcs", "--exclude=output*.xml",
-         "--exclude=./tmp", "-zcf", file_name, "."],
-        check=True, msg="Could not pack testing framework")
+    run(
+        [
+            u"tar", u"--sparse", u"--exclude-vcs", u"--exclude=output*.xml",
+            u"--exclude=./tmp", u"-zcf", file_name, u"."
+        ], msg=u"Could not pack testing framework"
+    )
 
     return file_name
 
@@ -68,10 +72,15 @@ def copy_tarball_to_node(tarball, node):
     :type node: dict
     :returns: nothing
     """
-    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))
+    logger.console(
+        f"Copying tarball to {node[u'type']} host {node[u'host']}, "
+        f"port {node[u'port']} starts."
+    )
+    scp_node(node, tarball, u"/tmp/")
+    logger.console(
+        f"Copying tarball to {node[u'type']} host {node[u'host']}, "
+        f"port {node[u'port']} done."
+    )
 
 
 def extract_tarball_at_node(tarball, node):
@@ -86,64 +95,94 @@ def extract_tarball_at_node(tarball, node):
     :returns: nothing
     :raises RuntimeError: When failed to unpack tarball.
     """
-    host = node['host']
-    logger.console('Extracting tarball to {0} on {1} starts.'
-                   .format(con.REMOTE_FW_DIR, host))
+    logger.console(
+        f"Extracting tarball to {con.REMOTE_FW_DIR} on {node[u'type']} "
+        f"host {node[u'host']}, port {node[u'port']} starts."
+    )
+    cmd = f"sudo rm -rf {con.REMOTE_FW_DIR}; mkdir {con.REMOTE_FW_DIR}; " \
+        f"tar -zxf {tarball} -C {con.REMOTE_FW_DIR}; rm -f {tarball}"
     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))
+        node, cmd,
+        message=f"Failed to extract {tarball} at node {node[u'type']} "
+        f"host {node[u'host']}, port {node[u'port']}",
+        timeout=90, include_reason=True
+    )
+    logger.console(
+        f"Extracting tarball to {con.REMOTE_FW_DIR} on {node[u'type']} "
+        f"host {node[u'host']}, port {node[u'port']} done."
+    )
 
 
 def create_env_directory_at_node(node):
     """Create fresh virtualenv to a directory, install pip requirements.
 
+    Return stdout and stderr of the command,
+    so we see which installs are behaving weird (e.g. attempting download).
+
     :param node: Node to create virtualenv on.
     :type node: dict
-    :returns: nothing
+    :returns: Stdout and stderr.
+    :rtype: str, str
     :raises RuntimeError: When failed to setup virtualenv.
     """
-    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))
+    logger.console(
+        f"Virtualenv setup including requirements.txt on {node[u'type']} "
+        f"host {node[u'host']}, port {node[u'port']} starts."
+    )
+    cmd = f"cd {con.REMOTE_FW_DIR} && rm -rf env && virtualenv " \
+        f"-p $(which python3) --system-site-packages --never-download env " \
+        f"&& source env/bin/activate && ANSIBLE_SKIP_CONFLICT_CHECK=1 " \
+        f"pip3 install -r requirements.txt"
+    stdout, stderr = exec_cmd_no_error(
+        node, cmd, timeout=100, include_reason=True,
+        message=f"Failed install at node {node[u'type']} host {node[u'host']}, "
+        f"port {node[u'port']}"
+    )
+    logger.console(
+        f"Virtualenv setup on {node[u'type']} host {node[u'host']}, "
+        f"port {node[u'port']} done."
+    )
+    return stdout, stderr
 
 
-def setup_node(node, tarball, remote_tarball, results=None):
+def setup_node(node, tarball, remote_tarball, results=None, logs=None):
     """Copy a tarball to a node and extract it.
 
     :param node: A node where the tarball will be copied and extracted.
     :param tarball: Local path of tarball to be copied.
     :param remote_tarball: Remote path of the tarball.
     :param results: A list where to store the result of node setup, optional.
+    :param logs: A list where to store anything that should be logged.
     :type node: dict
     :type tarball: str
     :type remote_tarball: str
     :type results: list
+    :type logs: list
     :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.console("Node {node} setup failed, error: {err!r}".format(
-            node=host, err=exc))
+        if node[u"type"] == NodeType.TG:
+            stdout, stderr = create_env_directory_at_node(node)
+            if isinstance(logs, list):
+                logs.append(f"{node[u'host']} Env stdout: {stdout}")
+                logs.append(f"{node[u'host']} Env stderr: {stderr}")
+    except Exception:
+        # any exception must result in result = False
+        # since this runs in a thread and can't be caught anywhere else
+        err_msg = f"Node {node[u'type']} host {node[u'host']}, " \
+                  f"port {node[u'port']} setup failed."
+        logger.console(err_msg)
+        if isinstance(logs, list):
+            logs.append(f"{err_msg} Exception: {traceback.format_exc()}")
         result = False
     else:
-        logger.console('Setup of node {0} done.'.format(host))
+        logger.console(
+            f"Setup of node {node[u'type']} host {node[u'host']}, "
+            f"port {node[u'port']} done."
+        )
         result = True
 
     if isinstance(results, list):
@@ -167,35 +206,48 @@ def delete_framework_dir(node):
     :param node: Node to delete framework directory on.
     :type node: dict
     """
-    host = node['host']
     logger.console(
-        'Deleting framework directory on {0} starts.'.format(host))
+        f"Deleting framework directory on {node[u'type']} host {node[u'host']},"
+        f" port {node[u'port']} starts."
+    )
     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)
+        node, f"sudo rm -rf {con.REMOTE_FW_DIR}",
+        message=f"Framework delete failed at node {node[u'type']} "
+        f"host {node[u'host']}, port {node[u'port']}",
+        timeout=100, include_reason=True
+    )
     logger.console(
-        'Deleting framework directory on {0} done.'.format(host))
+        f"Deleting framework directory on {node[u'type']} host {node[u'host']},"
+        f" port {node[u'port']} done."
+    )
 
 
-def cleanup_node(node, results=None):
+def cleanup_node(node, results=None, logs=None):
     """Delete a tarball from a node.
 
     :param node: A node where the tarball will be delete.
     :param results: A list where to store the result of node cleanup, optional.
+    :param logs: A list where to store anything that should be logged.
     :type node: dict
     :type results: list
+    :type logs: list
     :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(host))
+    except Exception:
+        err_msg = f"Cleanup of node {node[u'type']} host {node[u'host']}, " \
+                  f"port {node[u'port']} failed."
+        logger.console(err_msg)
+        if isinstance(logs, list):
+            logs.append(f"{err_msg} Exception: {traceback.format_exc()}")
         result = False
     else:
-        logger.console('Cleanup of node {0} done.'.format(host))
+        logger.console(
+            f"Cleanup of node {node[u'type']} host {node[u'host']}, "
+            f"port {node[u'port']} done."
+        )
         result = True
 
     if isinstance(results, list):
@@ -203,7 +255,7 @@ def cleanup_node(node, results=None):
     return result
 
 
-class SetupFramework(object):
+class SetupFramework:
     """Setup suite run on topology nodes.
 
     Many VAT/CLI based tests need the scripts at remote hosts before executing
@@ -221,36 +273,46 @@ class SetupFramework(object):
         """
 
         tarball = pack_framework_dir()
-        msg = 'Framework packed to {0}'.format(tarball)
+        msg = f"Framework packed to {tarball}"
         logger.console(msg)
         logger.trace(msg)
-        remote_tarball = "/tmp/{0}".format(basename(tarball))
+        remote_tarball = f"{tarball}"
 
-        results = []
-        threads = []
+        results = list()
+        logs = list()
+        threads = list()
 
         for node in nodes.values():
-            args = node, tarball, remote_tarball, results
+            args = node, tarball, remote_tarball, results, logs
             thread = threading.Thread(target=setup_node, args=args)
             thread.start()
             threads.append(thread)
 
         logger.info(
-            'Executing node setups in parallel, waiting for threads to end')
+            u"Executing node setups in parallel, waiting for threads to end."
+        )
 
         for thread in threads:
             thread.join()
 
-        logger.info('Results: {0}'.format(results))
+        logger.info(f"Results: {results}")
+
+        for log in logs:
+            logger.trace(log)
 
         delete_local_tarball(tarball)
         if all(results):
-            logger.console('All nodes are ready.')
+            logger.console(u"All nodes are ready.")
+            for node in nodes.values():
+                logger.info(
+                    f"Setup of node {node[u'type']} host {node[u'host']}, "
+                    f"port {node[u'port']} done."
+                )
         else:
-            raise RuntimeError('Failed to setup framework.')
+            raise RuntimeError(u"Failed to setup framework.")
 
 
-class CleanupFramework(object):
+class CleanupFramework:
     """Clean up suite run on topology nodes."""
 
     @staticmethod
@@ -262,24 +324,29 @@ class CleanupFramework(object):
         :raises RuntimeError: If cleanup framework failed.
         """
 
-        results = []
-        threads = []
+        results = list()
+        logs = list()
+        threads = list()
 
         for node in nodes.values():
             thread = threading.Thread(target=cleanup_node,
-                                      args=(node, results))
+                                      args=(node, results, logs))
             thread.start()
             threads.append(thread)
 
         logger.info(
-            'Executing node cleanups in parallel, waiting for threads to end.')
+            u"Executing node cleanups in parallel, waiting for threads to end."
+        )
 
         for thread in threads:
             thread.join()
 
-        logger.info('Results: {0}'.format(results))
+        logger.info(f"Results: {results}")
+
+        for log in logs:
+            logger.trace(log)
 
         if all(results):
-            logger.console('All nodes cleaned up.')
+            logger.console(u"All nodes cleaned up.")
         else:
-            raise RuntimeError('Failed to cleaned up framework.')
+            raise RuntimeError(u"Failed to cleaned up framework.")