Setup, teardown, DEBUG=core, FAILFAST fixes

- Fixed a bug when an error occuring in tearDownClass would not result in
test being marked as failed
- Improved test results reporting in cases when an error occurs in setUpClass
and tearDownClass
- Fixed DEBUG=core when the core is produced in setUpClass or
tearDownClass
- Reworked DEBUG=core to always be handled after all tests have been
executed
- Fixed FAILFAST=1 for parallel test runs

Change-Id: I3e9cd3b97ba6fa802fa0aa2dd7678ff82eee09ec
Signed-off-by: juraj.linkes <juraj.linkes@pantheon.tech>

5 files changed, 380 insertions, 249 deletions

diff --git a/test/debug.py b/test/debug.py
index 4516b8c150b..d1c89c66f3c 100644
--- a/test/debug.py
+++ b/test/debug.py
@@ -2,11 +2,12 @@
 
 import os
 import pexpect
+import sys
 
 gdb_path = '/usr/bin/gdb'
 
 
-def spawn_gdb(binary_path, core_path, logger):
+def spawn_gdb(binary_path, core_path):
     if os.path.isfile(gdb_path) and os.access(gdb_path, os.X_OK):
         # automatically attach gdb
         gdb_cmdline = "%s %s %s" % (gdb_path, binary_path, core_path)
@@ -19,5 +20,5 @@ def spawn_gdb(binary_path, core_path, logger):
         if gdb.isalive():
             raise Exception("GDB refused to die...")
     else:
-        logger.error("Debugger '%s' does not exist or is not an "
-                     "executable.." % gdb_path)
+        sys.stderr.write("Debugger '%s' does not exist or is not "
+                         "an executable..\n" % gdb_path)
diff --git a/test/framework.py b/test/framework.py
index a7f4fc774b4..fbe6c370a3f 100644
--- a/test/framework.py
+++ b/test/framework.py
@@ -27,7 +27,7 @@ from vpp_papi.vpp_stats import VPPStats
 from log import RED, GREEN, YELLOW, double_line_delim, single_line_delim, \
     getLogger, colorize
 from vpp_object import VppObjectRegistry
-from util import ppp
+from util import ppp, is_core_present
 from scapy.layers.inet import IPerror, TCPerror, UDPerror, ICMPerror
 from scapy.layers.inet6 import ICMPv6DestUnreach, ICMPv6EchoRequest
 from scapy.layers.inet6 import ICMPv6EchoReply
@@ -162,7 +162,7 @@ class KeepAliveReporter(object):
             raise Exception("Internal error - pipe should only be set once.")
         self._pipe = pipe
 
-    def send_keep_alive(self, test):
+    def send_keep_alive(self, test, desc=None):
         """
         Write current test tmpdir & desc to keep-alive pipe to signal liveness
         """
@@ -171,11 +171,9 @@ class KeepAliveReporter(object):
             return
 
         if isclass(test):
-            desc = test.__name__
+            desc = '%s (%s)' % (desc, unittest.util.strclass(test))
         else:
-            desc = test.shortDescription()
-            if not desc:
-                desc = str(test)
+            desc = test.id()
 
         self.pipe.send((desc, test.vpp_bin, test.tempdir, test.vpp.pid))
 
@@ -249,6 +247,14 @@ class VppTestCase(unittest.TestCase):
 
         return random.choice(tuple(min_usage_set))
 
+    @staticmethod
+    def print_header(cls):
+        if not hasattr(cls, '_header_printed'):
+            print(double_line_delim)
+            print(colorize(getdoc(cls).splitlines()[0], GREEN))
+            print(double_line_delim)
+            cls._header_printed = True
+
     @classmethod
     def setUpConstants(cls):
         """ Set-up the test case class based on environment variables """
@@ -361,6 +367,7 @@ class VppTestCase(unittest.TestCase):
         """
         gc.collect()  # run garbage collection first
         random.seed()
+        cls.print_header(cls)
         if not hasattr(cls, 'logger'):
             cls.logger = getLogger(cls.__name__)
         else:
@@ -391,7 +398,9 @@ class VppTestCase(unittest.TestCase):
         # doesn't get called and we might end with a zombie vpp
         try:
             cls.run_vpp()
-            cls.reporter.send_keep_alive(cls)
+            cls.reporter.send_keep_alive(cls, 'setUpClass')
+            VppTestResult.current_test_case_info = TestCaseInfo(
+                cls.logger, cls.tempdir, cls.vpp.pid, cls.vpp_bin)
             cls.vpp_stdout_deque = deque()
             cls.vpp_stderr_deque = deque()
             cls.pump_thread_stop_flag = Event()
@@ -507,6 +516,7 @@ class VppTestCase(unittest.TestCase):
     @classmethod
     def tearDownClass(cls):
         """ Perform final cleanup after running all tests in this test-case """
+        cls.reporter.send_keep_alive(cls, 'tearDownClass')
         cls.quit()
         cls.file_handler.close()
         cls.reset_packet_infos()
@@ -928,7 +938,6 @@ def get_testcase_doc_name(test):
 
 
 def get_test_description(descriptions, test):
-    # TODO: if none print warning not raise exception
     short_description = test.shortDescription()
     if descriptions and short_description:
         return short_description
@@ -936,20 +945,13 @@ def get_test_description(descriptions, test):
         return str(test)
 
 
-class TestCasePrinter(object):
-    _shared_state = {}
-
-    def __init__(self):
-        self.__dict__ = self._shared_state
-        if not hasattr(self, "_test_case_set"):
-            self._test_case_set = set()
-
-    def print_test_case_heading_if_first_time(self, case):
-        if case.__class__ not in self._test_case_set:
-            print(double_line_delim)
-            print(colorize(get_testcase_doc_name(case), GREEN))
-            print(double_line_delim)
-            self._test_case_set.add(case.__class__)
+class TestCaseInfo(object):
+    def __init__(self, logger, tempdir, vpp_pid, vpp_bin_path):
+        self.logger = logger
+        self.tempdir = tempdir
+        self.vpp_pid = vpp_pid
+        self.vpp_bin_path = vpp_bin_path
+        self.core_crash_test = None
 
 
 class VppTestResult(unittest.TestResult):
@@ -967,6 +969,10 @@ class VppTestResult(unittest.TestResult):
      methods.
     """
 
+    failed_test_cases_info = set()
+    core_crash_test_cases_info = set()
+    current_test_case_info = None
+
     def __init__(self, stream, descriptions, verbosity):
         """
         :param stream File descriptor to store where to report test results.
@@ -980,7 +986,6 @@ class VppTestResult(unittest.TestResult):
         self.descriptions = descriptions
         self.verbosity = verbosity
         self.result_string = None
-        self.printer = TestCasePrinter()
 
     def addSuccess(self, test):
         """
@@ -989,11 +994,11 @@ class VppTestResult(unittest.TestResult):
         :param test:
 
         """
-        if hasattr(test, 'logger'):
-            test.logger.debug("--- addSuccess() %s.%s(%s) called"
-                              % (test.__class__.__name__,
-                                 test._testMethodName,
-                                 test._testMethodDoc))
+        if self.current_test_case_info:
+            self.current_test_case_info.logger.debug(
+                "--- addSuccess() %s.%s(%s) called" % (test.__class__.__name__,
+                                                       test._testMethodName,
+                                                       test._testMethodDoc))
         unittest.TestResult.addSuccess(self, test)
         self.result_string = colorize("OK", GREEN)
 
@@ -1007,39 +1012,40 @@ class VppTestResult(unittest.TestResult):
         :param reason:
 
         """
-        if hasattr(test, 'logger'):
-            test.logger.debug("--- addSkip() %s.%s(%s) called, reason is %s"
-                              % (test.__class__.__name__,
-                                 test._testMethodName,
-                                 test._testMethodDoc,
-                                 reason))
+        if self.current_test_case_info:
+            self.current_test_case_info.logger.debug(
+                "--- addSkip() %s.%s(%s) called, reason is %s" %
+                (test.__class__.__name__, test._testMethodName,
+                 test._testMethodDoc, reason))
         unittest.TestResult.addSkip(self, test, reason)
         self.result_string = colorize("SKIP", YELLOW)
 
         self.send_result_through_pipe(test, SKIP)
 
-    def symlink_failed(self, test):
-        logger = None
-        if hasattr(test, 'logger'):
-            logger = test.logger
-        if hasattr(test, 'tempdir'):
+    def symlink_failed(self):
+        if self.current_test_case_info:
             try:
                 failed_dir = os.getenv('VPP_TEST_FAILED_DIR')
-                link_path = os.path.join(failed_dir, '%s-FAILED' %
-                                         os.path.basename(test.tempdir))
-                if logger:
-                    logger.debug("creating a link to the failed test")
-                    logger.debug("os.symlink(%s, %s)" %
-                                 (test.tempdir, link_path))
+                link_path = os.path.join(
+                    failed_dir,
+                    '%s-FAILED' %
+                    os.path.basename(self.current_test_case_info.tempdir))
+                if self.current_test_case_info.logger:
+                    self.current_test_case_info.logger.debug(
+                        "creating a link to the failed test")
+                    self.current_test_case_info.logger.debug(
+                        "os.symlink(%s, %s)" %
+                        (self.current_test_case_info.tempdir, link_path))
                 if os.path.exists(link_path):
-                    if logger:
-                        logger.debug('symlink already exists')
+                    if self.current_test_case_info.logger:
+                        self.current_test_case_info.logger.debug(
+                            'symlink already exists')
                 else:
-                    os.symlink(test.tempdir, link_path)
+                    os.symlink(self.current_test_case_info.tempdir, link_path)
 
             except Exception as e:
-                if logger:
-                    logger.error(e)
+                if self.current_test_case_info.logger:
+                    self.current_test_case_info.logger.error(e)
 
     def send_result_through_pipe(self, test, result):
         if hasattr(self, 'test_framework_result_pipe'):
@@ -1047,6 +1053,54 @@ class VppTestResult(unittest.TestResult):
             if pipe:
                 pipe.send((test.id(), result))
 
+    def log_error(self, test, err, fn_name):
+        if self.current_test_case_info:
+            if isinstance(test, unittest.suite._ErrorHolder):
+                test_name = test.description
+            else:
+                test_name = '%s.%s(%s)' % (test.__class__.__name__,
+                                           test._testMethodName,
+                                           test._testMethodDoc)
+            self.current_test_case_info.logger.debug(
+                "--- %s() %s called, err is %s" %
+                (fn_name, test_name, err))
+            self.current_test_case_info.logger.debug(
+                "formatted exception is:\n%s" %
+                "".join(format_exception(*err)))
+
+    def add_error(self, test, err, unittest_fn, error_type):
+        if error_type == FAIL:
+            self.log_error(test, err, 'addFailure')
+            error_type_str = colorize("FAIL", RED)
+        elif error_type == ERROR:
+            self.log_error(test, err, 'addError')
+            error_type_str = colorize("ERROR", RED)
+        else:
+            raise Exception('Error type %s cannot be used to record an '
+                            'error or a failure' % error_type)
+
+        unittest_fn(self, test, err)
+        if self.current_test_case_info:
+            self.result_string = "%s [ temp dir used by test case: %s ]" % \
+                                 (error_type_str,
+                                  self.current_test_case_info.tempdir)
+            self.symlink_failed()
+            self.failed_test_cases_info.add(self.current_test_case_info)
+            if is_core_present(self.current_test_case_info.tempdir):
+                if not self.current_test_case_info.core_crash_test:
+                    if isinstance(test, unittest.suite._ErrorHolder):
+                        test_name = str(test)
+                    else:
+                        test_name = "'{}' ({})".format(
+                            get_testcase_doc_name(test), test.id())
+                    self.current_test_case_info.core_crash_test = test_name
+                self.core_crash_test_cases_info.add(
+                    self.current_test_case_info)
+        else:
+            self.result_string = '%s [no temp dir]' % error_type_str
+
+        self.send_result_through_pipe(test, error_type)
+
     def addFailure(self, test, err):
         """
         Record a test failed result
@@ -1055,22 +1109,7 @@ class VppTestResult(unittest.TestResult):
         :param err: error message
 
         """
-        if hasattr(test, 'logger'):
-            test.logger.debug("--- addFailure() %s.%s(%s) called, err is %s"
-                              % (test.__class__.__name__,
-                                 test._testMethodName,
-                                 test._testMethodDoc, err))
-            test.logger.debug("formatted exception is:\n%s" %
-                              "".join(format_exception(*err)))
-        unittest.TestResult.addFailure(self, test, err)
-        if hasattr(test, 'tempdir'):
-            self.result_string = colorize("FAIL", RED) + \
-                ' [ temp dir used by test case: ' + test.tempdir + ' ]'
-            self.symlink_failed(test)
-        else:
-            self.result_string = colorize("FAIL", RED) + ' [no temp dir]'
-
-        self.send_result_through_pipe(test, FAIL)
+        self.add_error(test, err, unittest.TestResult.addFailure, FAIL)
 
     def addError(self, test, err):
         """
@@ -1080,22 +1119,7 @@ class VppTestResult(unittest.TestResult):
         :param err: error message
 
         """
-        if hasattr(test, 'logger'):
-            test.logger.debug("--- addError() %s.%s(%s) called, err is %s"
-                              % (test.__class__.__name__,
-                                 test._testMethodName,
-                                 test._testMethodDoc, err))
-            test.logger.debug("formatted exception is:\n%s" %
-                              "".join(format_exception(*err)))
-        unittest.TestResult.addError(self, test, err)
-        if hasattr(test, 'tempdir'):
-            self.result_string = colorize("ERROR", RED) + \
-                ' [ temp dir used by test case: ' + test.tempdir + ' ]'
-            self.symlink_failed(test)
-        else:
-            self.result_string = colorize("ERROR", RED) + ' [no temp dir]'
-
-        self.send_result_through_pipe(test, ERROR)
+        self.add_error(test, err, unittest.TestResult.addError, ERROR)
 
     def getDescription(self, test):
         """
@@ -1114,7 +1138,8 @@ class VppTestResult(unittest.TestResult):
         :param test:
 
         """
-        self.printer.print_test_case_heading_if_first_time(test)
+        test.print_header(test.__class__)
+
         unittest.TestResult.startTest(self, test)
         if self.verbosity > 0:
             self.stream.writeln(
@@ -1177,6 +1202,7 @@ class VppTestRunner(unittest.TextTestRunner):
     def __init__(self, keep_alive_pipe=None, descriptions=True, verbosity=1,
                  result_pipe=None, failfast=False, buffer=False,
                  resultclass=None):
+
         # ignore stream setting here, use hard-coded stdout to be in sync
         # with prints from VppTestCase methods ...
         super(VppTestRunner, self).__init__(sys.stdout, descriptions,
diff --git a/test/hook.py b/test/hook.py
index 7287aaa1920..29c4cd9435c 100644
--- a/test/hook.py
+++ b/test/hook.py
@@ -3,9 +3,8 @@ import os
 import sys
 import traceback
 from log import RED, single_line_delim, double_line_delim
-from debug import spawn_gdb
 from subprocess import check_output, CalledProcessError
-from util import check_core_path
+from util import check_core_path, get_core_path
 
 
 class Hook(object):
@@ -60,27 +59,21 @@ class PollHook(Hook):
     """ Hook which checks if the vpp subprocess is alive """
 
     def __init__(self, testcase):
+        super(PollHook, self).__init__(testcase.logger)
         self.testcase = testcase
-        self.logger = testcase.logger
 
     def on_crash(self, core_path):
-        if self.testcase.debug_core:
-            # notify parent process that we're handling a core file
-            open('%s/_core_handled' % self.testcase.tempdir, 'a').close()
-            spawn_gdb(self.testcase.vpp_bin, core_path, self.logger)
-        else:
-            self.logger.error("Core file present, debug with: gdb %s %s" %
-                              (self.testcase.vpp_bin, core_path))
-            check_core_path(self.logger, core_path)
-            self.logger.error("Running `file %s':" % core_path)
-            try:
-                info = check_output(["file", core_path])
-                self.logger.error(info)
-            except CalledProcessError as e:
-                self.logger.error(
-                    "Could not run `file' utility on core-file, "
-                    "rc=%s" % e.returncode)
-                pass
+        self.logger.error("Core file present, debug with: gdb %s %s" %
+                          (self.testcase.vpp_bin, core_path))
+        check_core_path(self.logger, core_path)
+        self.logger.error("Running `file %s':" % core_path)
+        try:
+            info = check_output(["file", core_path])
+            self.logger.error(info)
+        except CalledProcessError as e:
+            self.logger.error(
+                "Could not run `file' utility on core-file, "
+                "rc=%s" % e.returncode)
 
     def poll_vpp(self):
         """
@@ -104,7 +97,7 @@ class PollHook(Hook):
             msg = "VPP subprocess died unexpectedly with returncode %d [%s]" %\
                 (self.testcase.vpp.returncode, s)
             self.logger.critical(msg)
-            core_path = self.testcase.tempdir + '/core'
+            core_path = get_core_path(self.testcase.tempdir)
             if os.path.isfile(core_path):
                 self.on_crash(core_path)
             self.testcase.vpp_dead = True
diff --git a/test/run_tests.py b/test/run_tests.py
index 6836466373e..c42c6a820dc 100644
--- a/test/run_tests.py
+++ b/test/run_tests.py
@@ -4,13 +4,13 @@ import sys
 import shutil
 import os
 import fnmatch
-import select
 import unittest
 import argparse
 import time
 import threading
 import signal
 import psutil
+import re
 from multiprocessing import Process, Pipe, cpu_count
 from multiprocessing.queues import Queue
 from multiprocessing.managers import BaseManager
@@ -19,10 +19,10 @@ from framework import VppTestRunner, running_extended_tests, VppTestCase, \
     TEST_RUN
 from debug import spawn_gdb
 from log import get_parallel_logger, double_line_delim, RED, YELLOW, GREEN, \
-    colorize
+    colorize, single_line_delim
 from discover_tests import discover_tests
 from subprocess import check_output, CalledProcessError
-from util import check_core_path
+from util import check_core_path, get_core_path, is_core_present
 
 # timeout which controls how long the child has to finish after seeing
 # a core dump in test temporary directory. If this is exceeded, parent assumes
@@ -54,31 +54,28 @@ StreamQueueManager.register('StreamQueue', StreamQueue)
 
 
 class TestResult(dict):
-    def __init__(self, testcase_suite):
+    def __init__(self, testcase_suite, testcases_by_id=None):
         super(TestResult, self).__init__()
         self[PASS] = []
         self[FAIL] = []
         self[ERROR] = []
         self[SKIP] = []
         self[TEST_RUN] = []
+        self.crashed = False
         self.testcase_suite = testcase_suite
         self.testcases = [testcase for testcase in testcase_suite]
-        self.testcases_by_id = {}
+        self.testcases_by_id = testcases_by_id
 
     def was_successful(self):
-        return len(self[PASS] + self[SKIP]) \
-               == self.testcase_suite.countTestCases()
+        return 0 == len(self[FAIL]) == len(self[ERROR]) \
+               and len(self[PASS] + self[SKIP]) \
+               == self.testcase_suite.countTestCases() == len(self[TEST_RUN])
 
     def no_tests_run(self):
         return 0 == len(self[TEST_RUN])
 
     def process_result(self, test_id, result):
         self[result].append(test_id)
-        for testcase in self.testcases:
-            if testcase.id() == test_id:
-                self.testcases_by_id[test_id] = testcase
-                self.testcases.remove(testcase)
-                break
 
     def suite_from_failed(self):
         rerun_ids = set([])
@@ -90,21 +87,33 @@ class TestResult(dict):
             return suite_from_failed(self.testcase_suite, rerun_ids)
 
     def get_testcase_names(self, test_id):
-        return self._get_testcase_class(test_id), \
-               self._get_test_description(test_id)
+        if re.match(r'.+\..+\..+', test_id):
+            test_name = self._get_test_description(test_id)
+            testcase_name = self._get_testcase_doc_name(test_id)
+        else:
+            # could be tearDownClass (test_ipsec_esp.TestIpsecEsp1)
+            setup_teardown_match = re.match(
+                r'((tearDownClass)|(setUpClass)) \((.+\..+)\)', test_id)
+            if setup_teardown_match:
+                test_name, _, _, testcase_name = setup_teardown_match.groups()
+                if len(testcase_name.split('.')) == 2:
+                    for key in self.testcases_by_id.keys():
+                        if key.startswith(testcase_name):
+                            testcase_name = key
+                            break
+                testcase_name = self._get_testcase_doc_name(testcase_name)
+            else:
+                test_name = test_id
+                testcase_name = test_id
+
+        return testcase_name, test_name
 
     def _get_test_description(self, test_id):
-        if test_id in self.testcases_by_id:
-            return get_test_description(descriptions,
-                                        self.testcases_by_id[test_id])
-        else:
-            return test_id
+        return get_test_description(descriptions,
+                                    self.testcases_by_id[test_id])
 
-    def _get_testcase_class(self, test_id):
-        if test_id in self.testcases_by_id:
-            return get_testcase_doc_name(self.testcases_by_id[test_id])
-        else:
-            return test_id
+    def _get_testcase_doc_name(self, test_id):
+        return get_testcase_doc_name(self.testcases_by_id[test_id])
 
 
 def test_runner_wrapper(suite, keep_alive_pipe, stdouterr_queue,
@@ -142,12 +151,48 @@ class TestCaseWrapper(object):
         self.child.start()
         self.last_test_temp_dir = None
         self.last_test_vpp_binary = None
-        self.last_test = None
-        self.result = None
+        self._last_test = None
+        self.last_test_id = None
         self.vpp_pid = None
         self.last_heard = time.time()
         self.core_detected_at = None
-        self.result = TestResult(testcase_suite)
+        self.testcases_by_id = {}
+        self.testclasess_with_core = {}
+        for testcase in self.testcase_suite:
+            self.testcases_by_id[testcase.id()] = testcase
+        self.result = TestResult(testcase_suite, self.testcases_by_id)
+
+    @property
+    def last_test(self):
+        return self._last_test
+
+    @last_test.setter
+    def last_test(self, test_id):
+        self.last_test_id = test_id
+        if test_id in self.testcases_by_id:
+            testcase = self.testcases_by_id[test_id]
+            self._last_test = testcase.shortDescription()
+            if not self._last_test:
+                self._last_test = str(testcase)
+        else:
+            self._last_test = test_id
+
+    def add_testclass_with_core(self):
+        if self.last_test_id in self.testcases_by_id:
+            test = self.testcases_by_id[self.last_test_id]
+            class_name = unittest.util.strclass(test.__class__)
+            test_name = "'{}' ({})".format(get_test_description(descriptions,
+                                                                test),
+                                           self.last_test_id)
+        else:
+            test_name = self.last_test_id
+            class_name = re.match(r'((tearDownClass)|(setUpClass)) '
+                                  r'\((.+\..+)\)', test_name).groups()[3]
+        if class_name not in self.testclasess_with_core:
+            self.testclasess_with_core[class_name] = (
+                test_name,
+                self.last_test_vpp_binary,
+                self.last_test_temp_dir)
 
     def close_pipes(self):
         self.keep_alive_child_end.close()
@@ -157,6 +202,9 @@ class TestCaseWrapper(object):
         self.finished_parent_end.close()
         self.result_parent_end.close()
 
+    def was_successful(self):
+        return self.result.was_successful()
+
 
 def stdouterr_reader_wrapper(unread_testcases, finished_unread_testcases,
                              read_testcases):
@@ -179,12 +227,86 @@ def stdouterr_reader_wrapper(unread_testcases, finished_unread_testcases,
             read_testcase = None
 
 
+def handle_failed_suite(logger, last_test_temp_dir, vpp_pid):
+    if last_test_temp_dir:
+        # Need to create link in case of a timeout or core dump without failure
+        lttd = os.path.basename(last_test_temp_dir)
+        failed_dir = os.getenv('VPP_TEST_FAILED_DIR')
+        link_path = '%s%s-FAILED' % (failed_dir, lttd)
+        if not os.path.exists(link_path):
+            logger.error("Creating a link to the failed test: %s -> %s" %
+                         (link_path, lttd))
+            os.symlink(last_test_temp_dir, link_path)
+        else:
+            logger.error("Link to the failed test already exists: %s -> %s" %
+                         (link_path, lttd))
+
+        # Report core existence
+        core_path = get_core_path(last_test_temp_dir)
+        if os.path.exists(core_path):
+            logger.error(
+                "Core-file exists in test temporary directory: %s!" %
+                core_path)
+            check_core_path(logger, core_path)
+            logger.debug("Running `file %s':" % core_path)
+            try:
+                info = check_output(["file", core_path])
+                logger.debug(info)
+            except CalledProcessError as e:
+                logger.error("Could not run `file' utility on core-file, "
+                             "rc=%s" % e.returncode)
+
+    if vpp_pid:
+        # Copy api post mortem
+        api_post_mortem_path = "/tmp/api_post_mortem.%d" % vpp_pid
+        if os.path.isfile(api_post_mortem_path):
+            logger.error("Copying api_post_mortem.%d to %s" %
+                         (vpp_pid, last_test_temp_dir))
+            shutil.copy2(api_post_mortem_path, last_test_temp_dir)
+
+
+def check_and_handle_core(vpp_binary, tempdir, core_crash_test):
+    if is_core_present(tempdir):
+        print('VPP core detected in %s. Last test running was %s' %
+              (tempdir, core_crash_test))
+        print(single_line_delim)
+        spawn_gdb(vpp_binary, get_core_path(tempdir))
+        print(single_line_delim)
+
+
+def handle_cores(failed_testcases):
+    if debug_core:
+        for failed_testcase in failed_testcases:
+            tcs_with_core = failed_testcase.testclasess_with_core
+            if len(tcs_with_core) > 0:
+                for test, vpp_binary, tempdir in tcs_with_core.values():
+                    check_and_handle_core(vpp_binary, tempdir, test)
+
+
+def process_finished_testsuite(wrapped_testcase_suite,
+                               finished_testcase_suites,
+                               failed_wrapped_testcases,
+                               results):
+    results.append(wrapped_testcase_suite.result)
+    finished_testcase_suites.add(wrapped_testcase_suite)
+    stop_run = False
+    if failfast and not wrapped_testcase_suite.was_successful():
+        stop_run = True
+
+    if not wrapped_testcase_suite.was_successful():
+        failed_wrapped_testcases.add(wrapped_testcase_suite)
+        handle_failed_suite(wrapped_testcase_suite.logger,
+                            wrapped_testcase_suite.last_test_temp_dir,
+                            wrapped_testcase_suite.vpp_pid)
+
+    return stop_run
+
+
 def run_forked(testcase_suites):
     wrapped_testcase_suites = set()
 
     # suites are unhashable, need to use list
     results = []
-    debug_core = os.getenv("DEBUG", "").lower() == "core"
     unread_testcases = set()
     finished_unread_testcases = set()
     manager = StreamQueueManager()
@@ -195,7 +317,6 @@ def run_forked(testcase_suites):
                                                      manager)
             wrapped_testcase_suites.add(wrapped_testcase_suite)
             unread_testcases.add(wrapped_testcase_suite)
-            # time.sleep(1)
         else:
             break
 
@@ -207,6 +328,8 @@ def run_forked(testcase_suites):
                                               read_from_testcases))
     stdouterr_thread.start()
 
+    failed_wrapped_testcases = set()
+    stop_run = False
     while len(wrapped_testcase_suites) > 0:
         finished_testcase_suites = set()
         for wrapped_testcase_suite in wrapped_testcase_suites:
@@ -215,12 +338,6 @@ def run_forked(testcase_suites):
                     *wrapped_testcase_suite.result_parent_end.recv())
                 wrapped_testcase_suite.last_heard = time.time()
 
-            if wrapped_testcase_suite.finished_parent_end.poll():
-                wrapped_testcase_suite.finished_parent_end.recv()
-                results.append(wrapped_testcase_suite.result)
-                finished_testcase_suites.add(wrapped_testcase_suite)
-                continue
-
             while wrapped_testcase_suite.keep_alive_parent_end.poll():
                 wrapped_testcase_suite.last_test, \
                     wrapped_testcase_suite.last_test_vpp_binary, \
@@ -229,101 +346,65 @@ def run_forked(testcase_suites):
                     wrapped_testcase_suite.keep_alive_parent_end.recv()
                 wrapped_testcase_suite.last_heard = time.time()
 
+            if wrapped_testcase_suite.finished_parent_end.poll():
+                wrapped_testcase_suite.finished_parent_end.recv()
+                wrapped_testcase_suite.last_heard = time.time()
+                stop_run = process_finished_testsuite(
+                    wrapped_testcase_suite,
+                    finished_testcase_suites,
+                    failed_wrapped_testcases,
+                    results) or stop_run
+                continue
+
             fail = False
-            if wrapped_testcase_suite.last_heard + test_timeout < time.time() \
-                    and not os.path.isfile(
-                                "%s/_core_handled" %
-                                wrapped_testcase_suite.last_test_temp_dir):
+            if wrapped_testcase_suite.last_heard + test_timeout < time.time():
                 fail = True
                 wrapped_testcase_suite.logger.critical(
-                    "Timeout while waiting for child test "
-                    "runner process (last test running was "
-                    "`%s' in `%s')!" %
+                    "Child test runner process timed out "
+                    "(last test running was `%s' in `%s')!" %
                     (wrapped_testcase_suite.last_test,
                      wrapped_testcase_suite.last_test_temp_dir))
             elif not wrapped_testcase_suite.child.is_alive():
                 fail = True
                 wrapped_testcase_suite.logger.critical(
-                    "Child python process unexpectedly died "
+                    "Child test runner process unexpectedly died "
                     "(last test running was `%s' in `%s')!" %
                     (wrapped_testcase_suite.last_test,
                      wrapped_testcase_suite.last_test_temp_dir))
             elif wrapped_testcase_suite.last_test_temp_dir and \
                     wrapped_testcase_suite.last_test_vpp_binary:
-                core_path = "%s/core" % \
-                            wrapped_testcase_suite.last_test_temp_dir
-                if os.path.isfile(core_path):
+                if is_core_present(wrapped_testcase_suite.last_test_temp_dir):
+                    wrapped_testcase_suite.add_testclass_with_core()
                     if wrapped_testcase_suite.core_detected_at is None:
                         wrapped_testcase_suite.core_detected_at = time.time()
                     elif wrapped_testcase_suite.core_detected_at + \
                             core_timeout < time.time():
-                        if not os.path.isfile(
-                                        "%s/_core_handled" %
-                                        wrapped_testcase_suite.
-                                        last_test_temp_dir):
-                            wrapped_testcase_suite.logger.critical(
-                                "Child python process unresponsive and core-"
-                                "file exists in test temporary directory!")
-                            fail = True
+                        wrapped_testcase_suite.logger.critical(
+                            "Child test runner process unresponsive and core-"
+                            "file exists in test temporary directory "
+                            "(last test running was `%s' in `%s')!" %
+                            (wrapped_testcase_suite.last_test,
+                             wrapped_testcase_suite.last_test_temp_dir))
+                        fail = True
 
             if fail:
-                failed_dir = os.getenv('VPP_TEST_FAILED_DIR')
-                if wrapped_testcase_suite.last_test_temp_dir:
-                    lttd = os.path.basename(
-                        wrapped_testcase_suite.last_test_temp_dir)
-                else:
-                    lttd = None
-                link_path = '%s%s-FAILED' % (failed_dir, lttd)
-                wrapped_testcase_suite.logger.error(
-                    "Creating a link to the failed test: %s -> %s" %
-                    (link_path, lttd))
-                if not os.path.exists(link_path) \
-                        and wrapped_testcase_suite.last_test_temp_dir:
-                    os.symlink(wrapped_testcase_suite.last_test_temp_dir,
-                               link_path)
-                api_post_mortem_path = "/tmp/api_post_mortem.%d" % \
-                                       wrapped_testcase_suite.vpp_pid
-                if os.path.isfile(api_post_mortem_path):
-                    wrapped_testcase_suite.logger.error(
-                        "Copying api_post_mortem.%d to %s" %
-                        (wrapped_testcase_suite.vpp_pid,
-                         wrapped_testcase_suite.last_test_temp_dir))
-                    shutil.copy2(api_post_mortem_path,
-                                 wrapped_testcase_suite.last_test_temp_dir)
-                if wrapped_testcase_suite.last_test_temp_dir and \
-                        wrapped_testcase_suite.last_test_vpp_binary:
-                    core_path = "%s/core" % \
-                                wrapped_testcase_suite.last_test_temp_dir
-                    if os.path.isfile(core_path):
-                        wrapped_testcase_suite.logger.error(
-                            "Core-file exists in test temporary directory: %s!"
-                            % core_path)
-                        check_core_path(wrapped_testcase_suite.logger,
-                                        core_path)
-                        wrapped_testcase_suite.logger.debug(
-                            "Running `file %s':" % core_path)
-                        try:
-                            info = check_output(["file", core_path])
-                            wrapped_testcase_suite.logger.debug(info)
-                        except CalledProcessError as e:
-                            wrapped_testcase_suite.logger.error(
-                                "Could not run `file' utility on core-file, "
-                                "rc=%s" % e.returncode)
-                            pass
-                        if debug_core:
-                            spawn_gdb(
-                                wrapped_testcase_suite.last_test_vpp_binary,
-                                core_path, wrapped_testcase_suite.logger)
                 wrapped_testcase_suite.child.terminate()
                 try:
                     # terminating the child process tends to leave orphan
                     # VPP process around
-                    os.kill(wrapped_testcase_suite.vpp_pid, signal.SIGTERM)
+                    if wrapped_testcase_suite.vpp_pid:
+                        os.kill(wrapped_testcase_suite.vpp_pid, signal.SIGTERM)
                 except OSError:
                     # already dead
                     pass
-                results.append(wrapped_testcase_suite.result)
-                finished_testcase_suites.add(wrapped_testcase_suite)
+                wrapped_testcase_suite.result.crashed = True
+                wrapped_testcase_suite.result.process_result(
+                    wrapped_testcase_suite.last_test_id, ERROR)
+                stop_run = process_finished_testsuite(
+                    wrapped_testcase_suite,
+                    finished_testcase_suites,
+                    failed_wrapped_testcases,
+                    results) or stop_run
 
         for finished_testcase in finished_testcase_suites:
             finished_testcase.child.join()
@@ -331,14 +412,22 @@ def run_forked(testcase_suites):
             wrapped_testcase_suites.remove(finished_testcase)
             finished_unread_testcases.add(finished_testcase)
             finished_testcase.stdouterr_queue.put(None)
-            if len(testcase_suites) > 0:
+            if stop_run:
+                while len(testcase_suites) > 0:
+                    results.append(TestResult(testcase_suites.pop(0)))
+            elif len(testcase_suites) > 0:
                 new_testcase = TestCaseWrapper(testcase_suites.pop(0), manager)
                 wrapped_testcase_suites.add(new_testcase)
                 unread_testcases.add(new_testcase)
 
+    while len(unread_testcases) > 0:
+        # wait for reader thread to read everything in all loggers
+        pass
+
     read_from_testcases.clear()
     stdouterr_thread.join(test_timeout)
     manager.shutdown()
+    handle_cores(failed_wrapped_testcases)
     return results
 
 
@@ -474,21 +563,20 @@ class AllResults(dict):
     def add_result(self, result):
         retval = 0
         self.all_testcases += result.testcase_suite.countTestCases()
-        if not result.no_tests_run():
-            if not result.was_successful():
-                retval = 1
+        self.add_results(result)
 
-            self.add_results(result)
-        else:
+        if result.no_tests_run():
             self.testsuites_no_tests_run.append(result.testcase_suite)
-            retval = -1
+            if result.crashed:
+                retval = -1
+            else:
+                retval = 1
+        elif not result.was_successful():
+            retval = 1
 
         if retval != 0:
             if concurrent_tests == 1:
-                if not result.no_tests_run():
-                    self.rerun.append(result.suite_from_failed())
-                else:
-                    self.rerun.append(result.testcase_suite)
+                self.rerun.append(result.suite_from_failed())
             else:
                 self.rerun.append(result.testcase_suite)
 
@@ -516,7 +604,7 @@ class AllResults(dict):
                 colorize(str(self[ERROR]), RED)))
 
         if self.all_failed > 0:
-            print('FAILED TESTS:')
+            print('FAILURES AND ERRORS IN TESTS:')
             for result in self.results_per_suite:
                 failed_testcase_ids = result[FAIL]
                 errored_testcase_ids = result[ERROR]
@@ -529,7 +617,7 @@ class AllResults(dict):
                             print('  Testcase name: {}'.format(
                                 colorize(new_testcase_name, RED)))
                             old_testcase_name = new_testcase_name
-                        print('     FAILED: {}'.format(
+                        print('    FAILURE: {}'.format(
                             colorize(test_name, RED)))
                     for failed_test_id in errored_testcase_ids:
                         new_testcase_name, test_name = \
@@ -538,11 +626,11 @@ class AllResults(dict):
                             print('  Testcase name: {}'.format(
                                 colorize(new_testcase_name, RED)))
                             old_testcase_name = new_testcase_name
-                        print('    ERRORED: {}'.format(
+                        print('      ERROR: {}'.format(
                             colorize(test_name, RED)))
         if len(self.testsuites_no_tests_run) > 0:
             print('TESTCASES WHERE NO TESTS WERE SUCCESSFULLY EXECUTED:')
-            tc_classes = set([])
+            tc_classes = set()
             for testsuite in self.testsuites_no_tests_run:
                 for testcase in testsuite:
                     tc_classes.add(get_testcase_doc_name(testcase))
@@ -615,12 +703,11 @@ if __name__ == '__main__':
 
     debug = os.getenv("DEBUG", "n").lower() in ["gdb", "gdbserver"]
 
-    step = os.getenv("STEP", "n").lower() in ("y", "yes", "1")
+    debug_core = os.getenv("DEBUG", "").lower() == "core"
 
-    force_foreground = \
-        os.getenv("FORCE_FOREGROUND", "n").lower() in ("y", "yes", "1")
+    step = os.getenv("STEP", "n").lower() in ("y", "yes", "1")
 
-    run_interactive = debug or step or force_foreground
+    run_interactive = debug or step
 
     test_jobs = os.getenv("TEST_JOBS", "1").lower()  # default = 1 process
     if test_jobs == 'auto':
@@ -647,9 +734,8 @@ if __name__ == '__main__':
 
     if run_interactive and concurrent_tests > 1:
         raise NotImplementedError(
-            'Running tests interactively (DEBUG, STEP or FORCE_FOREGROUND is '
-            'set) in parallel (TEST_JOBS is more than 1) is not '
-            'supported')
+            'Running tests interactively (DEBUG is gdb or gdbserver or STEP '
+            'is set) in parallel (TEST_JOBS is more than 1) is not supported')
 
     parser = argparse.ArgumentParser(description="VPP unit tests")
     parser.add_argument("-f", "--failfast", action='store_true',
@@ -700,13 +786,24 @@ if __name__ == '__main__':
 
     if run_interactive:
         # don't fork if requiring interactive terminal
-        sys.exit(not VppTestRunner(
-            verbosity=verbose, failfast=failfast)
-                 .run(suites[0]).wasSuccessful())
+        result = VppTestRunner(verbosity=verbose, failfast=failfast)\
+            .run(suites[0])
+        was_successful = result.wasSuccessful()
+        if not was_successful:
+            for test_case_info in result.failed_test_cases_info:
+                handle_failed_suite(test_case_info.logger,
+                                    test_case_info.tempdir,
+                                    test_case_info.vpp_pid)
+                if debug_core and \
+                        test_case_info in result.core_crash_test_cases_info:
+                    check_and_handle_core(test_case_info.vpp_bin_path,
+                                          test_case_info.tempdir,
+                                          test_case_info.core_crash_test)
+
+        sys.exit(not was_successful)
     else:
         exit_code = 0
         while len(suites) > 0 and attempts > 0:
-            tests_amount = sum([x.countTestCases() for x in suites])
             results = run_forked(suites)
             exit_code, suites = parse_results(results)
             attempts -= 1
diff --git a/test/util.py b/test/util.py
index d8ecf270f67..1ab5c1f2350 100644
--- a/test/util.py
+++ b/test/util.py
@@ -2,6 +2,7 @@
 
 import socket
 import sys
+import os.path
 from abc import abstractmethod, ABCMeta
 from cStringIO import StringIO
 from scapy.utils6 import in6_mactoifaceid
@@ -73,19 +74,32 @@ def ip6_normalize(ip6):
                             socket.inet_pton(socket.AF_INET6, ip6))
 
 
-def check_core_path(logger, core_path):
+def get_core_path(tempdir):
+    return "%s/%s" % (tempdir, get_core_pattern())
+
+
+def is_core_present(tempdir):
+    return os.path.isfile(get_core_path(tempdir))
+
+
+def get_core_pattern():
     with open("/proc/sys/kernel/core_pattern", "r") as f:
-        corefmt = f.read()
-        if corefmt.startswith("|"):
-            logger.error(
-                "WARNING: redirecting the core dump through a"
-                " filter may result in truncated dumps.")
-            logger.error(
-                "   You may want to check the filter settings"
-                " or uninstall it and edit the"
-                " /proc/sys/kernel/core_pattern accordingly.")
-            logger.error(
-                "   current core pattern is: %s" % corefmt)
+        corefmt = f.read().strip()
+    return corefmt
+
+
+def check_core_path(logger, core_path):
+    corefmt = get_core_pattern()
+    if corefmt.startswith("|"):
+        logger.error(
+            "WARNING: redirecting the core dump through a"
+            " filter may result in truncated dumps.")
+        logger.error(
+            "   You may want to check the filter settings"
+            " or uninstall it and edit the"
+            " /proc/sys/kernel/core_pattern accordingly.")
+        logger.error(
+            "   current core pattern is: %s" % corefmt)
 
 
 class NumericConstant(object):