Re: [PATCH v2 04/15] KVM: selftests: Add option to save selftest runner output to a directory

[Sean Christopherson <seanjc@google.com>]

On Fri, Jun 06, 2025, Vipin Sharma wrote:
> -    def run(self):
> +    def _run(self, output=None, error=None):
>          run_args = {
>              "universal_newlines": True,
>              "shell": True,
> -            "capture_output": True,
>              "timeout": self.timeout,
>          }
>  
> +        if output is None and error is None:
> +            run_args.update({"capture_output": True})

The runner needs to check that its min version, whatever that ends up being, is
satisfied.

capture_output requires 3.7, but nothing in the runner actually checks that the
min version is met.  If you hadn't mentioned running into a problem with 3.6, I
don't know that I would have figured out what was going wrong all that quickly.

There's also no reason to use capture_output, which appears to be the only
3.7+ dependency.  Just pass subprocess.PIPE for stdout and stderr.

> +        else:
> +            run_args.update({"stdout": output, "stderr": error})
> +
>          proc = subprocess.run(self.command, **run_args)
>          return proc.returncode, proc.stdout, proc.stderr
> +
> +    def run(self):
> +        if self.output_dir is not None:
> +            pathlib.Path(self.output_dir).mkdir(parents=True, exist_ok=True)
> +
> +        output = None
> +        error = None
> +        with contextlib.ExitStack() as stack:
> +            if self.output_dir is not None:
> +                output_path = os.path.join(self.output_dir, "stdout")
> +                output = stack.enter_context(
> +                    open(output_path, encoding="utf-8", mode="w"))
> +
> +                error_path = os.path.join(self.output_dir, "stderr")
> +                error = stack.enter_context(
> +                    open(error_path, encoding="utf-8", mode="w"))
> +            return self._run(output, error)
> diff --git a/tools/testing/selftests/kvm/runner/selftest.py b/tools/testing/selftests/kvm/runner/selftest.py
> index 4c72108c47de..664958c693e5 100644
> --- a/tools/testing/selftests/kvm/runner/selftest.py
> +++ b/tools/testing/selftests/kvm/runner/selftest.py
> @@ -32,7 +32,7 @@ class Selftest:
>      Extract the test execution command from test file and executes it.
>      """
>  
> -    def __init__(self, test_path, executable_dir, timeout):
> +    def __init__(self, test_path, executable_dir, timeout, output_dir):
>          test_command = pathlib.Path(test_path).read_text().strip()
>          if not test_command:
>              raise ValueError("Empty test command in " + test_path)
> @@ -40,7 +40,11 @@ class Selftest:
>          test_command = os.path.join(executable_dir, test_command)
>          self.exists = os.path.isfile(test_command.split(maxsplit=1)[0])
>          self.test_path = test_path
> -        self.command = command.Command(test_command, timeout)
> +
> +        if output_dir is not None:
> +            output_dir = os.path.join(output_dir, test_path.lstrip("/"))
> +        self.command = command.Command(test_command, timeout, output_dir)
> +
>          self.status = SelftestStatus.NO_RUN
>          self.stdout = ""
>          self.stderr = ""
> diff --git a/tools/testing/selftests/kvm/runner/test_runner.py b/tools/testing/selftests/kvm/runner/test_runner.py
> index 1409e1cfe7d5..0501d77a9912 100644
> --- a/tools/testing/selftests/kvm/runner/test_runner.py
> +++ b/tools/testing/selftests/kvm/runner/test_runner.py
> @@ -13,19 +13,22 @@ logger = logging.getLogger("runner")
>  class TestRunner:
>      def __init__(self, test_files, args):
>          self.tests = []
> +        self.output_dir = args.output
>  
>          for test_file in test_files:
> -            self.tests.append(Selftest(test_file, args.executable, args.timeout))
> +            self.tests.append(Selftest(test_file, args.executable,
> +                                       args.timeout, args.output))
>  
>      def _log_result(self, test_result):
>          logger.log(test_result.status,
>                     f"[{test_result.status}] {test_result.test_path}")

Previous patch, but I missed it there.  Print the *name* of the result, not the
integer, which is arbitrary magic.  i.e

        logger.log(test_result.status,
                   f"[{test_result.status.name}] {test_result.test_path}")

> -        logger.info("************** STDOUT BEGIN **************")
> -        logger.info(test_result.stdout)
> -        logger.info("************** STDOUT END **************")
> -        logger.info("************** STDERR BEGIN **************")
> -        logger.info(test_result.stderr)
> -        logger.info("************** STDERR END **************")
> +        if (self.output_dir is None):

Ugh.  I want both.  Recording to disk shouldn't prevent the user from seeing
real-time data.

Rather than redirect to a file, always pipe to stdout/stderr, and then simply
write to the appropriate files after the subprocess completes.  That'll also force
the issue on fixing a bug with timeouts, where the runner doesn't capture stdout
or stderr.

> +            logger.info("************** STDOUT BEGIN **************")
> +            logger.info(test_result.stdout)
> +            logger.info("************** STDOUT END **************")
> +            logger.info("************** STDERR BEGIN **************")
> +            logger.info(test_result.stderr)
> +            logger.info("************** STDERR END **************")

This is unnecessarily verbose.  The logger spits out a timestamp, just use that
to demarcate, e.g.

	logger.info("*** stdout ***\n" + test_result.stdout)
	logger.info("*** stderr ***\n" + test_result.stderr)

yields

14:52:29 | *** stdout ***
Random seed: 0x6b8b4567

14:52:29 | *** stderr ***
==== Test Assertion Failure ====
  x86/state_test.c:316: memcmp(&regs1, &regs2, sizeof(regs2))
  pid=168652 tid=168652 errno=4 - Interrupted system call
     1	0x0000000000402300: main at state_test.c:316 (discriminator 1)
     2	0x000000000041e413: __libc_start_call_main at libc-start.o:?
     3	0x00000000004205bc: __libc_start_main_impl at ??:?
     4	0x00000000004027a0: _start at ??:?
  Unexpected register values after vcpu_load_state; rdi: 7ff68b1f3040 rsi: 0

>  
>      def start(self):
>          ret = 0
> -- 
> 2.50.0.rc0.604.gd4ff7b7c86-goog
>