From: Stephen Warren <swarren@nvidia.com>
Date: Fri, 22 Jan 2016 19:30:09 +0000 (-0700)
Subject: test/py: drain console log at the end of any failed test
X-Git-Url: http://git.dujemihanovic.xyz/img/sics.gif?a=commitdiff_plain;h=c10eb9d39fb54f435dbd632f71c760e4a887a015;p=u-boot.git

test/py: drain console log at the end of any failed test

Tests may fail for a number of reasons, and in particular for reasons
other than a timeout waiting for U-Boot to print expected data. If the
last operation that a failed test performs is not waiting for U-Boot to
print something, then any trailing output from U-Boot during that test's
operation will not be logged as part of that test, but rather either
along with the next test, or even thrown away, potentiall hiding clues
re: the test failure reason.

Solve this by explicitly draining (and hence logging) the U-Boot output
in the case of failed tests.

Signed-off-by: Stephen Warren <swarren@nvidia.com>
Acked-by: Simon Glass <sjg@chromium.org>
---

diff --git a/test/py/conftest.py b/test/py/conftest.py
index 38aa3f922a..c1f19cee65 100644
--- a/test/py/conftest.py
+++ b/test/py/conftest.py
@@ -386,6 +386,7 @@ def pytest_runtest_protocol(item, nextitem):
                 skipped = report
 
     if failed:
+        console.drain_console()
         tests_failed.add(item.name)
     elif skipped:
         tests_skipped.add(item.name)
diff --git a/test/py/u_boot_console_base.py b/test/py/u_boot_console_base.py
index 10fe3dbdd3..418a26bb8e 100644
--- a/test/py/u_boot_console_base.py
+++ b/test/py/u_boot_console_base.py
@@ -14,6 +14,7 @@ import os
 import pytest
 import re
 import sys
+import u_boot_spawn
 
 # Regexes for text we expect U-Boot to send to the console.
 pattern_u_boot_spl_signon = re.compile('(U-Boot SPL \\d{4}\\.\\d{2}-[^\r\n]*)')
@@ -213,6 +214,43 @@ class ConsoleBase(object):
 
         self.run_command(chr(3), wait_for_echo=False, send_nl=False)
 
+    def drain_console(self):
+        '''Read from and log the U-Boot console for a short time.
+
+        U-Boot's console output is only logged when the test code actively
+        waits for U-Boot to emit specific data. There are cases where tests
+        can fail without doing this. For example, if a test asks U-Boot to
+        enable USB device mode, then polls until a host-side device node
+        exists. In such a case, it is useful to log U-Boot's console output
+        in case U-Boot printed clues as to why the host-side even did not
+        occur. This function will do that.
+
+        Args:
+            None.
+
+        Returns:
+            Nothing.
+        '''
+
+        # If we are already not connected to U-Boot, there's nothing to drain.
+        # This should only happen when a previous call to run_command() or
+        # wait_for() failed (and hence the output has already been logged), or
+        # the system is shutting down.
+        if not self.p:
+            return
+
+        orig_timeout = self.p.timeout
+        try:
+            # Drain the log for a relatively short time.
+            self.p.timeout = 1000
+            # Wait for something U-Boot will likely never send. This will
+            # cause the console output to be read and logged.
+            self.p.expect(['This should never match U-Boot output'])
+        except u_boot_spawn.Timeout:
+            pass
+        finally:
+            self.p.timeout = orig_timeout
+
     def ensure_spawned(self):
         '''Ensure a connection to a correctly running U-Boot instance.