make test: automatic "vpp finishes startup" check

Add code which checks if vpp doesn't crash/exit immediately after
startup to aid debugging stuff like mistyped graph node name or so.
Refuse to run tests if the vpp is unable to start, complain loudly
and print vpp's stderr at critical log level if this happens to make
spotting these problems in jenkins easy.

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

3 files changed, 59 insertions, 13 deletions

diff --git a/test/Makefile b/test/Makefile
index 6647d67b20b..787dd9d12c7 100644
--- a/test/Makefile
+++ b/test/Makefile
@@ -78,6 +78,11 @@ sanity: verify-no-running-vpp
 		 echo \"* 2. execute debugger:   gdb python -ex 'run sanity_import_vpp_papi.py'\" &&\
 	         echo \"*******************************************************************\" &&\
 		 false)"
+	@bash -c "source $(PYTHON_VENV_PATH)/bin/activate && python sanity_run_vpp.py ||\
+		(echo \"*******************************************************************\" &&\
+		 echo \"* Sanity check failed, cannot run vpp\" &&\
+	         echo \"*******************************************************************\" &&\
+		 false)"
 
 test: verify-python-path $(PAPI_INSTALL_DONE) sanity reset 
 	$(call retest-func)
diff --git a/test/framework.py b/test/framework.py
index ce70af2e267..fc263e703eb 100644
--- a/test/framework.py
+++ b/test/framework.py
@@ -255,6 +255,7 @@ class VppTestCase(unittest.TestCase):
         cls.verbose = 0
         cls.vpp_dead = False
         cls.registry = VppObjectRegistry()
+        cls.vpp_startup_failed = False
         # need to catch exceptions here because if we raise, then the cleanup
         # doesn't get called and we might end with a zombie vpp
         try:
@@ -273,7 +274,14 @@ class VppTestCase(unittest.TestCase):
                 hook = PollHook(cls)
             cls.vapi.register_hook(hook)
             cls.sleep(0.1, "after vpp startup, before initial poll")
-            hook.poll_vpp()
+            try:
+                hook.poll_vpp()
+            except:
+                cls.vpp_startup_failed = True
+                cls.logger.critical(
+                    "VPP died shortly after startup, check the"
+                    " output to standard error for possible cause")
+                raise
             try:
                 cls.vapi.connect()
             except:
@@ -325,27 +333,32 @@ class VppTestCase(unittest.TestCase):
                 cls.vpp.communicate()
             del cls.vpp
 
+        if cls.vpp_startup_failed:
+            stdout_log = cls.logger.info
+            stderr_log = cls.logger.critical
+        else:
+            stdout_log = cls.logger.info
+            stderr_log = cls.logger.info
+
         if hasattr(cls, 'vpp_stdout_deque'):
-            cls.logger.info(single_line_delim)
-            cls.logger.info('VPP output to stdout while running %s:',
-                            cls.__name__)
-            cls.logger.info(single_line_delim)
+            stdout_log(single_line_delim)
+            stdout_log('VPP output to stdout while running %s:', cls.__name__)
+            stdout_log(single_line_delim)
             f = open(cls.tempdir + '/vpp_stdout.txt', 'w')
             vpp_output = "".join(cls.vpp_stdout_deque)
             f.write(vpp_output)
-            cls.logger.info('\n%s', vpp_output)
-            cls.logger.info(single_line_delim)
+            stdout_log('\n%s', vpp_output)
+            stdout_log(single_line_delim)
 
         if hasattr(cls, 'vpp_stderr_deque'):
-            cls.logger.info(single_line_delim)
-            cls.logger.info('VPP output to stderr while running %s:',
-                            cls.__name__)
-            cls.logger.info(single_line_delim)
+            stderr_log(single_line_delim)
+            stderr_log('VPP output to stderr while running %s:', cls.__name__)
+            stderr_log(single_line_delim)
             f = open(cls.tempdir + '/vpp_stderr.txt', 'w')
             vpp_output = "".join(cls.vpp_stderr_deque)
             f.write(vpp_output)
-            cls.logger.info('\n%s', vpp_output)
-            cls.logger.info(single_line_delim)
+            stderr_log('\n%s', vpp_output)
+            stderr_log(single_line_delim)
 
     @classmethod
     def tearDownClass(cls):
@@ -925,4 +938,6 @@ class VppTestRunner(unittest.TextTestRunner):
                                      filter_func)
         print("%s out of %s tests match specified filters" % (
             filtered.countTestCases(), test.countTestCases()))
+        if not running_extended_tests():
+            print("Not running extended tests (some tests will be skipped)")
         return super(VppTestRunner, self).run(filtered)
diff --git a/test/sanity_run_vpp.py b/test/sanity_run_vpp.py
new file mode 100644
index 00000000000..527b618fbd9
--- /dev/null
+++ b/test/sanity_run_vpp.py
@@ -0,0 +1,26 @@
+#!/usr/bin/env python
+
+from __future__ import print_function
+from framework import VppTestCase
+from hook import VppDiedError
+from sys import exit
+
+
+class SanityTestCase(VppTestCase):
+    """ Dummy test case used to check if VPP is able to start """
+    pass
+
+if __name__ == '__main__':
+    rc = 0
+    tc = SanityTestCase
+    try:
+        tc.setUpClass()
+    except VppDiedError:
+        rc = -1
+    else:
+        try:
+            tc.tearDownClass()
+        except:
+            pass
+
+    exit(rc)