make test: work around scapy truncated packets

Under stress, it's possible to hit a race condition, when the packet
header is fully written to pcap, but not all packet data - yet.
Scapy is stupid enough to:
1. not detect and report this error, truncating the packet instead
2. continue munching more data from wrong offset
The work around is to scan the file ahead, parse the packet header,
figure out how much data we need, wait for the file to be big
enough, then restore the file position back to where it was
and finally let scapy parse the packet.

Change-Id: I9fc71d3ebdc62ecab6c90b90f177d0eaeb09b8bb
Signed-off-by: Klement Sekera <ksekera@cisco.com>
diff --git a/test/framework.py b/test/framework.py
index 4185dbf..6a0ec96 100644
--- a/test/framework.py
+++ b/test/framework.py
@@ -8,6 +8,7 @@
 from collections import deque
 from threading import Thread
 from inspect import getdoc
+from traceback import format_exception
 from hook import StepHook, PollHook
 from vpp_pg_interface import VppPGInterface
 from vpp_sub_interface import VppSubInterface
@@ -287,6 +288,9 @@
 
     def tearDown(self):
         """ Show various debug prints after each test """
+        self.logger.debug("--- tearDown() for %s.%s(%s) called ---" %
+                          (self.__class__.__name__, self._testMethodName,
+                           self._testMethodDoc))
         if not self.vpp_dead:
             self.logger.debug(self.vapi.cli("show trace"))
             self.logger.info(self.vapi.ppcli("show int"))
@@ -297,6 +301,9 @@
 
     def setUp(self):
         """ Clear trace before running each test"""
+        self.logger.debug("--- setUp() for %s.%s(%s) called ---" %
+                          (self.__class__.__name__, self._testMethodName,
+                           self._testMethodDoc))
         if self.vpp_dead:
             raise Exception("VPP is dead when setting up the test")
         time.sleep(.1)
@@ -586,6 +593,11 @@
         :param test:
 
         """
+        if hasattr(test, 'logger'):
+            test.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)
 
@@ -597,6 +609,12 @@
         :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))
         unittest.TestResult.addSkip(self, test, reason)
         self.result_string = colorize("SKIP", YELLOW)
 
@@ -608,6 +626,13 @@
         :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) + \
@@ -623,6 +648,13 @@
         :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) + \