Python's text streams are not thread safe. If two threads write to sys.stdout at the same time the stream's internal buffer can be corrupted, resulting in lost output and runs of NUL bytes or heap garbage being written in its place. This isn't an issue currently, but will be when we implement support for parallel test execution.
Add a lock to kunit_printer which Printer.print() takes around each write, and route the other prints that can run concurrently with the test results through the printer: the kernel start banners and timeout message in kunit_kernel, and the raw, JSON and JUnit output to stdout. Prints that only happen before any kernel is started, such as during configuration and build, are left alone. No change in output when a single kernel is run at a time. Signed-off-by: Mark Brown <[email protected]> --- tools/testing/kunit/kunit.py | 4 ++-- tools/testing/kunit/kunit_junit.py | 3 ++- tools/testing/kunit/kunit_kernel.py | 7 ++++--- tools/testing/kunit/kunit_printer.py | 9 ++++++++- 4 files changed, 16 insertions(+), 7 deletions(-) diff --git a/tools/testing/kunit/kunit.py b/tools/testing/kunit/kunit.py index 971e70b0fb1a..0132687cdd43 100755 --- a/tools/testing/kunit/kunit.py +++ b/tools/testing/kunit/kunit.py @@ -272,7 +272,7 @@ def parse_tests(request: KunitParseRequest, metadata: kunit_json.Metadata, input elif request.raw_output == 'kunit': output = kunit_parser.extract_tap_lines(output) for line in output: - print(line.rstrip()) + stdout.print(line.rstrip()) parse_time = time.time() - parse_start return KunitResult(KunitStatus.SUCCESS, parse_time), fake_test @@ -302,7 +302,7 @@ def _write_test_results(request: KunitParseRequest, metadata: kunit_json.Metadat test=test, metadata=metadata) if request.json == 'stdout': - print(json_str) + stdout.print(json_str) else: with open(request.json, 'w') as f: f.write(json_str) diff --git a/tools/testing/kunit/kunit_junit.py b/tools/testing/kunit/kunit_junit.py index 3622070358e7..a15c6061003f 100644 --- a/tools/testing/kunit/kunit_junit.py +++ b/tools/testing/kunit/kunit_junit.py @@ -6,6 +6,7 @@ from xml.sax.saxutils import quoteattr, XMLGenerator import xml.etree.ElementTree as ET +import kunit_printer from kunit_parser import Test, TestStatus from typing import Optional @@ -51,7 +52,7 @@ def get_junit_result(test: Test) -> str: def print_junit_result(test: Test) -> None: root_element = get_test_suite(test, None) ET.indent(root_element) - ET.dump(root_element) + kunit_printer.stdout.print(ET.tostring(root_element, encoding='unicode')) # Write an entire XML file for the test structure starting at test def write_junit_result(test: Test, filename: str) -> None: diff --git a/tools/testing/kunit/kunit_kernel.py b/tools/testing/kunit/kunit_kernel.py index 1d3226f5a136..508bd62eaa40 100644 --- a/tools/testing/kunit/kunit_kernel.py +++ b/tools/testing/kunit/kunit_kernel.py @@ -21,6 +21,7 @@ from typing import Iterator, List, Optional, Tuple, Any from types import FrameType import kunit_config +import kunit_printer import qemu_config KCONFIG_PATH = '.config' @@ -132,7 +133,7 @@ class LinuxSourceTreeOperationsQemu(LinuxSourceTreeOperations): '-accel', 'tcg', '-serial', self._serial] + self._extra_qemu_params # Note: shlex.join() does what we want, but requires python 3.8+. - print('Running tests with:\n$', ' '.join(shlex.quote(arg) for arg in qemu_command)) + kunit_printer.stdout.print('Running tests with:\n$ ' + ' '.join(shlex.quote(arg) for arg in qemu_command)) return subprocess.Popen(qemu_command, stdin=subprocess.PIPE, stdout=subprocess.PIPE, @@ -154,7 +155,7 @@ class LinuxSourceTreeOperationsUml(LinuxSourceTreeOperations): """Runs the Linux UML binary. Must be named 'linux'.""" linux_bin = os.path.join(build_dir, 'linux') params.extend(['mem=1G', 'console=tty', 'kunit_shutdown=halt']) - print('Running tests with:\n$', linux_bin, ' '.join(shlex.quote(arg) for arg in params)) + kunit_printer.stdout.print('Running tests with:\n$ ' + linux_bin + ' ' + ' '.join(shlex.quote(arg) for arg in params)) return subprocess.Popen([linux_bin] + params, stdin=subprocess.PIPE, stdout=subprocess.PIPE, @@ -402,7 +403,7 @@ class LinuxSourceTree: try: process.wait(timeout=timeout) except Exception as e: - print(e) + kunit_printer.stdout.print(str(e)) process.terminate() process.wait() waiter = threading.Thread(target=_wait_proc) diff --git a/tools/testing/kunit/kunit_printer.py b/tools/testing/kunit/kunit_printer.py index ca119f61fe79..440aa7667ece 100644 --- a/tools/testing/kunit/kunit_printer.py +++ b/tools/testing/kunit/kunit_printer.py @@ -8,10 +8,16 @@ import datetime import sys +import threading import typing _RESET = '\033[0;0m' +# Python's text streams aren't thread safe: concurrent writes to +# sys.stdout from several threads can lose output or write garbage. All +# output from the tool should go through this lock. +print_lock = threading.Lock() + class Printer: """Wraps a file object, providing utilities for coloring output, etc.""" @@ -25,7 +31,8 @@ class Printer: def print(self, message: str) -> None: if self._print: - print(message, file=self._output) + with print_lock: + print(message, file=self._output) def print_with_timestamp(self, message: str) -> None: ts = datetime.datetime.now().strftime('%H:%M:%S') -- 2.47.3

