On Tue, Oct 5, 2021 at 9:13 AM Daniel Latypov <dlatypov@xxxxxxxxxx> wrote: > > Currently, `run_kernel()` dumps all the kernel output to a file > (.kunit/test.log) and then opens the file and yields it to callers. > This made it easier to respect the requested timeout, if any. > > But it means that we can't yield the results in real time, either to the > parser or to stdout (if --raw_output is set). > > This change spins up a background thread to enforce the timeout, which > allows us to yield the kernel output in real time, while also copying it > to the .kunit/test.log file. > It's also careful to ensure that the .kunit/test.log file is complete, > even in the kunit_parser throws an exception/otherwise doesn't consume > every line, see the new `finally` block and unit test. > > For example: > > $ ./tools/testing/kunit/kunit.py run --arch=x86_64 --raw_output > <configure + build steps> > ... > <can now see output from QEMU in real time> > > This does not currently have a visible effect when --raw_output is not > passed, as kunit_parser.py currently only outputs everything at the end. > But that could change, and this patch is a necessary step towards > showing parsed test results in real time. > > Signed-off-by: Daniel Latypov <dlatypov@xxxxxxxxxx> > --- > v1 -> v2: restore stdin=subprocess.PIPE to avoid a UML (?) bug. > https://lore.kernel.org/linux-kselftest/CABVgOSnXBtCHEMDYYqrbXWvKcrSbY9BXP4MJjsT+vzZS6W4J=w@xxxxxxxxxxxxxx/ > --- This looks good and works well here, thanks. This is particularly nice with the slow time_test_cases:time64_to_tm_test_date_range test. Reviewed-by: David Gow <davidgow@xxxxxxxxxx> Thanks, -- David > tools/testing/kunit/kunit_kernel.py | 75 +++++++++++++++----------- > tools/testing/kunit/kunit_tool_test.py | 17 ++++++ > 2 files changed, 62 insertions(+), 30 deletions(-) > > diff --git a/tools/testing/kunit/kunit_kernel.py b/tools/testing/kunit/kunit_kernel.py > index 2c6f916ccbaf..450f1c386e01 100644 > --- a/tools/testing/kunit/kunit_kernel.py > +++ b/tools/testing/kunit/kunit_kernel.py > @@ -12,7 +12,8 @@ import subprocess > import os > import shutil > import signal > -from typing import Iterator, Optional, Tuple > +import threading > +from typing import Iterator, List, Optional, Tuple > > from contextlib import ExitStack > > @@ -103,8 +104,8 @@ class LinuxSourceTreeOperations(object): > if stderr: # likely only due to build warnings > print(stderr.decode()) > > - def run(self, params, timeout, build_dir, outfile) -> None: > - pass > + def start(self, params: List[str], build_dir: str) -> subprocess.Popen: > + raise RuntimeError('not implemented!') > > > class LinuxSourceTreeOperationsQemu(LinuxSourceTreeOperations): > @@ -123,7 +124,7 @@ class LinuxSourceTreeOperationsQemu(LinuxSourceTreeOperations): > kconfig.parse_from_string(self._kconfig) > base_kunitconfig.merge_in_entries(kconfig) > > - def run(self, params, timeout, build_dir, outfile): > + def start(self, params: List[str], build_dir: str) -> subprocess.Popen: > kernel_path = os.path.join(build_dir, self._kernel_path) > qemu_command = ['qemu-system-' + self._qemu_arch, > '-nodefaults', > @@ -134,18 +135,11 @@ class LinuxSourceTreeOperationsQemu(LinuxSourceTreeOperations): > '-nographic', > '-serial stdio'] + self._extra_qemu_params > print('Running tests with:\n$', ' '.join(qemu_command)) > - with open(outfile, 'w') as output: > - process = subprocess.Popen(' '.join(qemu_command), > - stdin=subprocess.PIPE, > - stdout=output, > - stderr=subprocess.STDOUT, > - text=True, shell=True) > - try: > - process.wait(timeout=timeout) > - except Exception as e: > - print(e) > - process.terminate() > - return process > + return subprocess.Popen(' '.join(qemu_command), > + stdin=subprocess.PIPE, > + stdout=subprocess.PIPE, > + stderr=subprocess.STDOUT, > + text=True, shell=True) > > class LinuxSourceTreeOperationsUml(LinuxSourceTreeOperations): > """An abstraction over command line operations performed on a source tree.""" > @@ -175,17 +169,14 @@ class LinuxSourceTreeOperationsUml(LinuxSourceTreeOperations): > kunit_parser.print_with_timestamp( > 'Starting Kernel with all configs takes a few minutes...') > > - def run(self, params, timeout, build_dir, outfile): > + def start(self, params: List[str], build_dir: str) -> subprocess.Popen: > """Runs the Linux UML binary. Must be named 'linux'.""" > linux_bin = get_file_path(build_dir, 'linux') > - outfile = get_outfile_path(build_dir) > - with open(outfile, 'w') as output: > - process = subprocess.Popen([linux_bin] + params, > - stdin=subprocess.PIPE, > - stdout=output, > - stderr=subprocess.STDOUT, > - text=True) > - process.wait(timeout) > + return subprocess.Popen([linux_bin] + params, > + stdin=subprocess.PIPE, > + stdout=subprocess.PIPE, > + stderr=subprocess.STDOUT, > + text=True) > > def get_kconfig_path(build_dir) -> str: > return get_file_path(build_dir, KCONFIG_PATH) > @@ -330,12 +321,36 @@ class LinuxSourceTree(object): > args.extend(['mem=1G', 'console=tty', 'kunit_shutdown=halt']) > if filter_glob: > args.append('kunit.filter_glob='+filter_glob) > - outfile = get_outfile_path(build_dir) > - self._ops.run(args, timeout, build_dir, outfile) > - subprocess.call(['stty', 'sane']) > - with open(outfile, 'r') as file: > - for line in file: > + > + process = self._ops.start(args, build_dir) > + assert process.stdout is not None # tell mypy it's set > + > + # Enforce the timeout in a background thread. > + def _wait_proc(): > + try: > + process.wait(timeout=timeout) > + except Exception as e: > + print(e) > + process.terminate() > + process.wait() > + waiter = threading.Thread(target=_wait_proc) > + waiter.start() > + > + output = open(get_outfile_path(build_dir), 'w') > + try: > + # Tee the output to the file and to our caller in real time. > + for line in process.stdout: > + output.write(line) > yield line > + # This runs even if our caller doesn't consume every line. > + finally: > + # Flush any leftover output to the file > + output.write(process.stdout.read()) > + output.close() > + process.stdout.close() > + > + waiter.join() > + subprocess.call(['stty', 'sane']) > > def signal_handler(self, sig, frame) -> None: > logging.error('Build interruption occurred. Cleaning console.') > diff --git a/tools/testing/kunit/kunit_tool_test.py b/tools/testing/kunit/kunit_tool_test.py > index 619c4554cbff..f9a7398a9584 100755 > --- a/tools/testing/kunit/kunit_tool_test.py > +++ b/tools/testing/kunit/kunit_tool_test.py > @@ -14,6 +14,7 @@ import tempfile, shutil # Handling test_tmpdir > import itertools > import json > import signal > +import subprocess > import os > > import kunit_config > @@ -291,6 +292,22 @@ class LinuxSourceTreeTest(unittest.TestCase): > pass > tree = kunit_kernel.LinuxSourceTree('', kunitconfig_path=dir) > > + def test_run_kernel_hits_exception(self): > + def fake_start(unused_args, unused_build_dir): > + return subprocess.Popen(['echo "hi\nbye"'], shell=True, text=True, stdout=subprocess.PIPE) > + > + with tempfile.TemporaryDirectory('') as build_dir: > + tree = kunit_kernel.LinuxSourceTree(build_dir, load_config=False) > + mock.patch.object(tree._ops, 'start', side_effect=fake_start).start() > + > + with self.assertRaises(ValueError): > + for line in tree.run_kernel(build_dir=build_dir): > + self.assertEqual(line, 'hi\n') > + raise ValueError('uh oh, did not read all output') > + > + with open(kunit_kernel.get_outfile_path(build_dir), 'rt') as outfile: > + self.assertEqual(outfile.read(), 'hi\nbye\n', msg='Missing some output') > + > # TODO: add more test cases. > > > > base-commit: 3b29021ddd10cfb6b2565c623595bd3b02036f33 > -- > 2.33.0.800.g4c38ced690-goog >
