make test: add CACHE_OUTPUT option

This option allows one to toggle whether captured VPP stdout/stderr
output is printed inline (each line logged immediately after being
collected). Default setting is 0/no (behaviour same as before).

This allows one to see the output in case of vpp crashing during test
run even if test framework gets stuck waiting for shared memory mutex
(which crashed vpp can no longer unlock).

Complete stdout/stderr output is always printed as a block to the
logger after test finishes.

Change-Id: If3645a9b85562dba26ed9c87daa27ea5ef34f2e5
Signed-off-by: Klement Sekera <ksekera@cisco.com>

Makefile

@@ -355,6 +355,7 @@ define test
 	  EXTENDED_TESTS=$(EXTENDED_TESTS) \
 	  PYTHON=$(PYTHON) \
 	  OS_ID=$(OS_ID) \
+	  CACHE_OUTPUT=$(CACHE_OUTPUT) \
 	  $(3)
 endef
 

test/Makefile

@@ -210,6 +210,7 @@ help:
 	@echo ""
 	@echo "Arguments controlling test runs:"
 	@echo " V=[0|1|2]            - set test verbosity level"
+	@echo " CACHE_OUTPUT=[0|1]   - cache VPP stdout/stderr and log as one block after test finishes (default: 1)"
 	@echo " FAILFAST=[0|1]       - fail fast if 1, complete all tests if 0"
 	@echo " TIMEOUT=<timeout>    - fail test suite if any single test takes longer than <timeout> to finish"
 	@echo " RETRIES=<n>          - retry failed tests <n> times"

test/framework.py

@@ -76,9 +76,15 @@ def pump_output(testclass):
         if testclass.vpp.stdout.fileno() in readable:
             read = os.read(testclass.vpp.stdout.fileno(), 1024)
             testclass.vpp_stdout_deque.append(read)
+            if not testclass.cache_vpp_output:
+                for line in read.splitlines():
+                    testclass.logger.debug("VPP STDOUT: %s" % line)
         if testclass.vpp.stderr.fileno() in readable:
             read = os.read(testclass.vpp.stderr.fileno(), 1024)
             testclass.vpp_stderr_deque.append(read)
+            if not testclass.cache_vpp_output:
+                for line in read.splitlines():
+                    testclass.logger.debug("VPP STDERR: %s" % line)
         # ignoring the dummy pipe here intentionally - the flag will take care
         # of properly terminating the loop
 
@@ -190,6 +196,12 @@ class VppTestCase(unittest.TestCase):
             d = os.getenv("DEBUG")
         except:
             d = None
+        try:
+            c = os.getenv("CACHE_OUTPUT", "1")
+            cls.cache_vpp_output = \
+                True if c.lower() in ("y", "yes", "1") else False
+        except:
+            cls.cache_vpp_output = True
         cls.set_debug_flags(d)
         cls.vpp_bin = os.getenv('VPP_TEST_BIN', "vpp")
         cls.plugin_path = os.getenv('VPP_TEST_PLUGIN_PATH')