HC Test: Fix intermittent failures of HC startup

 - rework "check Honeycomb startup state" keyword
 - increase timeout value for startup
 - add separators to Honeycomb log file between test suites
 - other minor fixes:
    - remove usused import from NAT suite
    - fix loop in ICMPv6 ND proxy traffic script
    - add teardown to LISP cases
    - update prerequisites for sub-interface SPAN test

Change-Id: I2f714ffc1d2e8435d3abe690d8bd15099e071c9a
Signed-off-by: selias <samelias@cisco.com>

6 files changed, 161 insertions, 105 deletions

diff --git a/resources/libraries/python/constants.py b/resources/libraries/python/constants.py
index 051a21cf02..a8d40a2a26 100644
--- a/resources/libraries/python/constants.py
+++ b/resources/libraries/python/constants.py
@@ -41,6 +41,9 @@ class Constants(object):
     # Honeycomb persistence files location
     REMOTE_HC_PERSIST = '/var/lib/honeycomb/persist'
 
+    # Honeycomb log file location
+    REMOTE_HC_LOG = '/var/log/honeycomb/honeycomb.log'
+
     # Honeycomb templates location
     RESOURCES_TPL_HC = 'resources/templates/honeycomb'
 
diff --git a/resources/libraries/python/honeycomb/HcAPIKwInterfaces.py b/resources/libraries/python/honeycomb/HcAPIKwInterfaces.py
index 17ed3b8246..09c9ae9a3b 100644
--- a/resources/libraries/python/honeycomb/HcAPIKwInterfaces.py
+++ b/resources/libraries/python/honeycomb/HcAPIKwInterfaces.py
@@ -1088,6 +1088,9 @@ class InterfaceKeywords(object):
         :raises KeyError: If the parameter 'match' is invalid.
         """
 
+        super_interface = Topology.convert_interface_reference(
+            node, super_interface, "name")
+
         match_type = {
             "default":
                 {"default": {}},
diff --git a/resources/libraries/python/honeycomb/HoneycombSetup.py b/resources/libraries/python/honeycomb/HoneycombSetup.py
index aa6f26d856..9ac217909e 100644
--- a/resources/libraries/python/honeycomb/HoneycombSetup.py
+++ b/resources/libraries/python/honeycomb/HoneycombSetup.py
@@ -14,6 +14,7 @@
 """Implementation of keywords for Honeycomb setup."""
 
 from json import loads
+from time import time, sleep
 
 from ipaddress import IPv6Address, AddressValueError
 
@@ -136,106 +137,104 @@ class HoneycombSetup(object):
                     node['host']))
 
     @staticmethod
-    def check_honeycomb_startup_state(*nodes):
-        """Check state of Honeycomb service during startup on specified nodes.
+    def check_honeycomb_startup_state(node, timeout=360, retries=20,
+                                      interval=15):
+        """Repeatedly check the status of Honeycomb startup until it is fully
+        started or until timeout or max retries is reached.
 
-        Reads html path from template file oper_vpp_version.url.
-
-        Honeycomb nodes reply with connection refused or the following status
-        codes depending on startup progress: codes 200, 401, 403, 404, 500, 503
-
-        :param nodes: List of DUT nodes starting Honeycomb.
-        :type nodes: list
-        :return: True if all GETs returned code 200(OK).
-        :rtype bool
-        """
-        path = HcUtil.read_path_from_url_file("oper_vpp_version")
-        expected_status_codes = (HTTPCodes.UNAUTHORIZED,
-                                 HTTPCodes.FORBIDDEN,
-                                 HTTPCodes.NOT_FOUND,
-                                 HTTPCodes.SERVICE_UNAVAILABLE,
-                                 HTTPCodes.INTERNAL_SERVER_ERROR)
+        :param node: Honeycomb node.
+        :param timeout: Timeout value in seconds.
+        :param retries: Max number of retries.
+        :param interval: Interval between checks, in seconds.
+        :type node: dict
+        :type timeout: int
+        :type retries: int
+        :type interval: int
+        :raises HoneycombError: If the Honeycomb process IP cannot be found,
+        or if timeout or number of retries is exceeded."""
 
-        for node in nodes:
-            if node['type'] == NodeType.DUT:
-                HoneycombSetup.print_ports(node)
-                try:
-                    status_code, _ = HTTPRequest.get(node, path,
-                                                     enable_logging=False)
-                except HTTPRequestError:
-                    ssh = SSH()
-                    ssh.connect(node)
-                    ret_code, _, _ = ssh.exec_command_sudo(
-                        "tail -n 100 /var/log/syslog")
-                    if ret_code != 0:
-                        # It's probably Centos
-                        ssh.exec_command_sudo("tail -n 100 /var/log/messages")
-                    raise
-                if status_code == HTTPCodes.OK:
-                    logger.info("Honeycomb on node {0} is up and running".
-                                format(node['host']))
-                elif status_code in expected_status_codes:
-                    if status_code == HTTPCodes.UNAUTHORIZED:
-                        logger.info('Unauthorized. If this triggers keyword '
-                                    'timeout, verify Honeycomb username and '
-                                    'password.')
-                    raise HoneycombError('Honeycomb on node {0} running but '
-                                         'not yet ready.'.format(node['host']),
-                                         enable_logging=False)
-                else:
-                    raise HoneycombError('Unexpected return code: {0}.'.
-                                         format(status_code))
-
-                status_code, _ = HcUtil.get_honeycomb_data(
-                    node, "config_vpp_interfaces")
-                if status_code != HTTPCodes.OK:
-                    raise HoneycombError('Honeycomb on node {0} running but '
-                                         'not yet ready.'.format(node['host']),
-                                         enable_logging=False)
-        return True
+        ssh = SSH()
+        ssh.connect(node)
+        ret_code, pid, _ = ssh.exec_command("pgrep honeycomb")
+        if ret_code != 0:
+            raise HoneycombError("No process named 'honeycomb' found.")
+
+        pid = int(pid)
+        count = 0
+        start = time()
+        while time() - start < timeout and count < retries:
+            count += 1
+            ret_code, _, _ = ssh.exec_command(
+                " | ".join([
+                    "sudo tail -n 1000 /var/log/syslog",
+                    "grep {pid}".format(pid=pid),
+                    "grep 'Honeycomb started successfully!'"])
+            )
+            if ret_code != 0:
+                logger.debug(
+                    "Attempt #{count} failed on log check.".format(
+                        count=count))
+                sleep(interval)
+                continue
+            status_code_version, _ = HcUtil.get_honeycomb_data(
+                node, "oper_vpp_version")
+            status_code_if_cfg, _ = HcUtil.get_honeycomb_data(
+                node, "config_vpp_interfaces")
+            status_code_if_oper, _ = HcUtil.get_honeycomb_data(
+                node, "oper_vpp_interfaces")
+            if status_code_if_cfg == HTTPCodes.OK\
+                    and status_code_if_cfg == HTTPCodes.OK\
+                    and status_code_if_oper == HTTPCodes.OK:
+                logger.info("Check successful, Honeycomb is up and running.")
+                break
+            else:
+                logger.debug(
+                    "Attempt ${count} failed on Restconf check. Status codes:\n"
+                    "Version: {version}\n"
+                    "Interface config: {if_cfg}\n"
+                    "Interface operational: {if_oper}".format(
+                        count=count,
+                        version=status_code_version,
+                        if_cfg=status_code_if_cfg,
+                        if_oper=status_code_if_oper))
+                sleep(interval)
+                continue
+        else:
+            _, vpp_status, _ = ssh.exec_command("service vpp status")
+            ret_code, hc_log, _ = ssh.exec_command(
+                " | ".join([
+                    "sudo tail -n 1000 /var/log/syslog",
+                    "grep {pid}".format(pid=pid)]))
+            raise HoneycombError(
+                "Timeout or max retries exceeded. Status of VPP:\n"
+                "{vpp_status}\n"
+                "Syslog entries filtered by Honeycomb's pid:\n"
+                "{hc_log}".format(vpp_status=vpp_status, hc_log=hc_log))
 
     @staticmethod
-    def check_honeycomb_shutdown_state(*nodes):
+    def check_honeycomb_shutdown_state(node):
         """Check state of Honeycomb service during shutdown on specified nodes.
 
         Honeycomb nodes reply with connection refused or the following status
         codes depending on shutdown progress: codes 200, 404.
 
-        :param nodes: List of DUT nodes stopping Honeycomb.
-        :type nodes: list
+        :param node: List of DUT nodes stopping Honeycomb.
+        :type node: dict
         :return: True if all GETs fail to connect.
         :rtype bool
         """
-        cmd = "ps -ef | grep -v grep | grep honeycomb"
-        for node in nodes:
-            if node['type'] == NodeType.DUT:
-                try:
-                    status_code, _ = HTTPRequest.get(node, '/index.html',
-                                                     enable_logging=False)
-                    if status_code == HTTPCodes.OK:
-                        raise HoneycombError('Honeycomb on node {0} is still '
-                                             'running.'.format(node['host']),
-                                             enable_logging=False)
-                    elif status_code == HTTPCodes.NOT_FOUND:
-                        raise HoneycombError('Honeycomb on node {0} is shutting'
-                                             ' down.'.format(node['host']),
-                                             enable_logging=False)
-                    else:
-                        raise HoneycombError('Unexpected return code: {0}.'.
-                                             format(status_code))
-                except HTTPRequestError:
-                    logger.debug('Connection refused, checking the process '
-                                 'state ...')
-                    ssh = SSH()
-                    ssh.connect(node)
-                    (ret_code, _, _) = ssh.exec_command_sudo(cmd)
-                    if ret_code == 0:
-                        raise HoneycombError('Honeycomb on node {0} is still '
-                                             'running.'.format(node['host']),
-                                             enable_logging=False)
-                    else:
-                        logger.info("Honeycomb on node {0} has stopped".
-                                    format(node['host']))
+        cmd = "pgrep honeycomb"
+
+        ssh = SSH()
+        ssh.connect(node)
+        (ret_code, _, _) = ssh.exec_command_sudo(cmd)
+        if ret_code == 0:
+            raise HoneycombError('Honeycomb on node {0} is still '
+                                 'running.'.format(node['host']),
+                                 enable_logging=False)
+        else:
+            logger.info("Honeycomb on node {0} has stopped".
+                        format(node['host']))
         return True
 
     @staticmethod
diff --git a/resources/libraries/python/honeycomb/HoneycombUtil.py b/resources/libraries/python/honeycomb/HoneycombUtil.py
index 24f81af7b3..39c076d9c3 100644
--- a/resources/libraries/python/honeycomb/HoneycombUtil.py
+++ b/resources/libraries/python/honeycomb/HoneycombUtil.py
@@ -399,6 +399,41 @@ class HoneycombUtil(object):
         return HTTPRequest.delete(node, path)
 
     @staticmethod
+    def append_honeycomb_log(node, suite_name):
+        """Append Honeycomb log for the current test suite to the full log.
+
+        :param node: Honeycomb node.
+        :param suite_name: Name of the current test suite. ${SUITE_NAME}
+        variable in robotframework.
+        :type node: dict
+        :type suite_name: str
+        """
+
+        ssh = SSH()
+        ssh.connect(node)
+
+        ssh.exec_command(
+            "echo '{separator}' >> /tmp/honeycomb.log".format(separator="="*80))
+        ssh.exec_command(
+            "echo 'Log for suite: {suite}' >> /tmp/honeycomb.log".format(
+                suite=suite_name))
+        ssh.exec_command(
+            "cat {hc_log} >> /tmp/honeycomb.log".format(
+                hc_log=Const.REMOTE_HC_LOG))
+
+    @staticmethod
+    def clear_honeycomb_log(node):
+        """Delete the Honeycomb log file for the current test suite.
+
+        :param node: Honeycomb node.
+        :type node: dict"""
+
+        ssh = SSH()
+        ssh.connect(node)
+
+        ssh.exec_command("sudo rm {hc_log}".format(hc_log=Const.REMOTE_HC_LOG))
+
+    @staticmethod
     def archive_honeycomb_log(node, perf=False):
         """Copy honeycomb log file from DUT node to VIRL for archiving.
 
@@ -412,10 +447,11 @@ class HoneycombUtil(object):
         ssh.connect(node)
 
         if not perf:
-            cmd = "cp /var/log/honeycomb/honeycomb.log /scratch/"
+            cmd = "cp /tmp/honeycomb.log /scratch/"
             ssh.exec_command_sudo(cmd)
         else:
             ssh.scp(
                 ".",
-                "/var/log/honeycomb/honeycomb.log",
+                "/tmp/honeycomb.log",
                 get=True)
+            ssh.exec_command("rm /tmp/honeycomb.log")
diff --git a/resources/libraries/robot/honeycomb/honeycomb.robot b/resources/libraries/robot/honeycomb/honeycomb.robot
index 087bde8b6b..a2be0c7e8d 100644
--- a/resources/libraries/robot/honeycomb/honeycomb.robot
+++ b/resources/libraries/robot/honeycomb/honeycomb.robot
@@ -39,9 +39,9 @@
 | | ...
 | | [Arguments] | @{duts}
 | | Start honeycomb on DUTs | @{duts}
-| | Wait until keyword succeeds | 4min | 16sec
-| | ... | Check honeycomb startup state | @{duts}
-| | Sleep | 5s | Make sure all modules are loaded and ready.
+| | :FOR | ${dut} | IN | @{duts}
+| | | Check honeycomb startup state | @{duts}
+| | | Sleep | 5s | Make sure all modules are loaded and ready.
 
 | Stop Honeycomb service on DUTs
 | | [Documentation] | *Cleanup environment after honeycomb testing.*
@@ -62,8 +62,9 @@
 | | ...
 | | [Arguments] | @{duts}
 | | Stop honeycomb on DUTs | @{duts}
-| | Wait until keyword succeeds | 60sec | 16sec
-| | ... | Check honeycomb shutdown state | @{duts}
+| | :FOR | ${dut} | IN | @{duts}
+| | | Wait until keyword succeeds | 60sec | 15sec
+| | | ... | Check honeycomb shutdown state | @{duts}
 
 | Clear persisted Honeycomb configuration
 | | [Documentation] | *Delete saved configuration.*
@@ -130,8 +131,7 @@
 | | Setup DUT | ${node}
 | | Sleep | 10s | Wait 10sec so VPP is up for sure.
 | | Configure Honeycomb service on DUTs | ${node}
-| | Wait until keyword succeeds | 2min | 16sec
-| | ... | Check honeycomb startup state | ${node}
+| | Check honeycomb startup state | ${node} | timeout=120
 
 | Archive Honeycomb log file
 | | [Documentation] | Copy honeycomb.log file from Honeycomb node\
@@ -166,12 +166,11 @@
 | | Setup ODL Client | ${node} | /tmp
 | | Wait until keyword succeeds | 2min | 30sec
 | | ... | Install ODL Features | ${node} | /tmp
-| | Wait until keyword succeeds | 4min | 16sec
+| | Wait until keyword succeeds | 4min | 15sec
 | | ... | Mount Honeycomb on ODL | ${node}
-| | Wait until keyword succeeds | 2min | 16sec
+| | Wait until keyword succeeds | 2min | 15sec
 | | ... | Check ODL startup state | ${node}
-| | Wait until keyword succeeds | 2min | 16sec
-| | ... | Check honeycomb startup state | ${node}
+| | Check honeycomb startup state | ${node} | timeout=120
 
 | Configure Honeycomb for functional testing
 | | [Documentation] | Configure Honeycomb with parameters for functional
@@ -188,9 +187,8 @@
 | | Configure Restconf binding address | ${node}
 | | Configure Log Level | ${node} | TRACE
 | | Configure Persistence | ${node} | disable
-| | Configure jVPP timeout | ${node} | ${14}
+| | Configure jVPP timeout | ${node} | ${10}
 | | Clear Persisted Honeycomb Configuration | ${node}
-| | Generate Honeycomb startup configuration for ODL test | ${node}
 | | Configure Honeycomb service on DUTs | ${node}
 
 | Configure ODL Client for functional testing
@@ -245,6 +243,7 @@
 | | ... | \| Tear Down Honeycomb Functional Test Suite \| ${nodes['DUT1']} \|
 | | ...
 | | [Arguments] | ${node}
+| | Append suite to Honeycomb log file | ${node}
 | | ${use_odl_client}= | Get Variable Value | ${HC_ODL}
 | | Run Keyword If | '${use_odl_client}' != '${NONE}'
 | | ... | Run Keywords
@@ -253,6 +252,7 @@
 | | ... | Check ODL shutdown state | ${node} | AND
 | | ... | Set Global Variable | ${use_odl_client} | ${NONE}
 | | Stop Honeycomb service on DUTs | ${node}
+| | Clear Honeycomb Log | ${node}
 | | Stop VPP Service on DUT | ${node}
 
 | Enable Honeycomb Feature
@@ -324,9 +324,25 @@
 | | ...
 | | [Arguments] | ${node}
 | | Log Honeycomb and VPP process distribution on cores | ${node}
+| | Append suite to Honeycomb log file | ${node}
 | | Stop Honeycomb service on DUTs | ${node}
+| | Clear Honeycomb Log | ${node}
 | | Stop VPP Service on DUT | ${node}
 
+| Append suite to Honeycomb log file
+| | [Documentation] | Add the contents of honeycomb.log for the current suite\
+| | ... | to the full log which will be archived.
+| | ...
+| | ... | *Arguments:*
+| | ... | - node - information about a DUT node. Type: dictionary
+| | ...
+| | ... | *Example:*
+| | ...
+| | ... | \| Append suite to Honeycomb log file \| ${nodes['DUT1']} \|
+| | ...
+| | [Arguments] | ${node}
+| | Append Honeycomb log | ${node} | ${SUITE_NAME}
+
 | Generate Honeycomb startup configuration for ODL test
 | | [Documentation] | Create HC startup configuration and apply to config
 | | ... | file on DUT. Requires Honeycomb restart to take effect.
@@ -345,4 +361,4 @@
 | | Run Keyword | HC_config.Set SSH Security provider
 | | Run Keyword | HC_config.Set Memory Size | ${32}
 | | Run Keyword | HC_config.Set Metaspace Size | ${32}
-| | Run Keyword | HC_config.Apply config | ${node}
+| | Run Keyword | HC_config.Apply config | ${node}
\ No newline at end of file
diff --git a/resources/libraries/robot/honeycomb/nat.robot b/resources/libraries/robot/honeycomb/nat.robot
index 2b79c1b407..0ca9f8964a 100644
--- a/resources/libraries/robot/honeycomb/nat.robot
+++ b/resources/libraries/robot/honeycomb/nat.robot
@@ -14,7 +14,6 @@
 *** Settings ***
 | Library | resources.libraries.python.honeycomb.HcAPIKwInterfaces.InterfaceKeywords
 | Library | resources.libraries.python.honeycomb.NAT.NATKeywords
-| Library | resources.libraries.python.NAT.NATUtil
 | Documentation | Keywords used to test Honeycomb NAT node.
 
 *** Keywords ***