From 2ca028d8e204e83b938d7dd2c577651e6a9f5df0 Mon Sep 17 00:00:00 2001
From: Dennis Kempin <denniskempin@google.com>
Date: Wed, 9 Nov 2022 15:03:18 -0800
Subject: [PATCH] run_tests: Allow real-time output of integration tests in
 verbose mode

There are test flakes in our post-submit builders that will
just crash the run_tests process.
To better figure out what's going on, switch verbose mode output
to print output directly instead of caching it to possible hide
the results on success.

This should help us find out where exactly the test is failing.

BUG=b:254923676
TEST=run_tests && run_tests -v

Change-Id: I3a9884db5da9c0973e8b05dea5541a8050c00548
Reviewed-on: https://chromium-review.googlesource.com/c/crosvm/crosvm/+/4018117
Reviewed-by: Zihan Chen <zihanchen@google.com>
Commit-Queue: Zihan Chen <zihanchen@google.com>
---
 tools/impl/test_runner.py | 76 ++++++++++++++++++++++++++++++++++-----
 1 file changed, 68 insertions(+), 8 deletions(-)

diff --git a/tools/impl/test_runner.py b/tools/impl/test_runner.py
index 7a5773ed80..fcf3fd3be2 100644
--- a/tools/impl/test_runner.py
+++ b/tools/impl/test_runner.py
@@ -283,7 +283,6 @@ def execute_test(
     target: TestTarget,
     attempts: int,
     collect_coverage: bool,
-    integration_test: bool,
     executable: Executable,
 ):
     """
@@ -295,7 +294,7 @@ def execute_test(
     """
     options = CRATE_OPTIONS.get(executable.crate_name, [])
     args: List[str] = []
-    if TestOption.SINGLE_THREADED in options or integration_test:
+    if TestOption.SINGLE_THREADED in options:
         args += ["--test-threads=1"]
 
     binary_path = executable.binary_path
@@ -354,6 +353,68 @@ def execute_test(
     return result  # type: ignore
 
 
+def execute_integration_test(
+    target: TestTarget,
+    attempts: int,
+    collect_coverage: bool,
+    executable: Executable,
+):
+    """
+    Executes a single integration test on the given test targed
+
+    Test output is hidden unless the test fails or VERBOSE mode is enabled.
+    """
+    args: List[str] = ["--test-threads=1"]
+    binary_path = executable.binary_path
+
+    previous_attempts: List[ExecutableResults] = []
+    for i in range(1, attempts + 1):
+        print(f"Running integration test {executable.name} on {target}... (attempt {i}/{attempts})")
+
+        try:
+            test_process = test_target.exec_file_on_target(
+                target,
+                binary_path,
+                args=args,
+                timeout=get_test_timeout(target, executable),
+                generate_profile=True,
+                stdout=None if VERBOSE else subprocess.PIPE,
+                stderr=subprocess.STDOUT,
+            )
+            profile_files: List[Path] = []
+            if collect_coverage:
+                profile_files = [*test_target.list_profile_files(binary_path)]
+                if not profile_files:
+                    print()
+                    print(f"Warning: Running {binary_path} did not produce a profile file.")
+
+            result = ExecutableResults(
+                executable.name,
+                binary_path,
+                test_process.returncode == 0,
+                test_process.stdout,
+                previous_attempts,
+                profile_files,
+            )
+        except subprocess.TimeoutExpired as e:
+            # Append a note about the timeout to the stdout of the process.
+            msg = f"\n\nProcess timed out after {e.timeout}s\n"
+            result = ExecutableResults(
+                executable.name,
+                binary_path,
+                False,
+                e.stdout.decode("utf-8") + msg if e.stdout else msg,
+                previous_attempts,
+                [],
+            )
+        if result.success:
+            break
+        else:
+            previous_attempts.append(result)
+
+    return result  # type: ignore
+
+
 def print_test_progress(result: ExecutableResults):
     if not result.success or result.previous_attempts or VERBOSE:
         if result.success:
@@ -394,9 +455,7 @@ def execute_all(
         sys.stdout.flush()
         with Pool(PARALLELISM) as pool:
             for result in pool.imap(
-                functools.partial(
-                    execute_test, unit_test_target, attempts, collect_coverage, False
-                ),
+                functools.partial(execute_test, unit_test_target, attempts, collect_coverage),
                 unit_tests,
             ):
                 print_test_progress(result)
@@ -412,10 +471,11 @@ def execute_all(
         )
         sys.stdout.flush()
         for executable in integration_tests:
-            result = execute_test(
-                integration_test_target, attempts, collect_coverage, True, executable
+            result = execute_integration_test(
+                integration_test_target, attempts, collect_coverage, executable
             )
-            print_test_progress(result)
+            if not result.success:
+                print(result.test_log)
             yield result
         print()