From b787cf0ca38527e6174a3a59cc1c1d6b15125193 Mon Sep 17 00:00:00 2001 From: Michael Schneider Date: Tue, 14 Apr 2026 14:43:43 +0100 Subject: [PATCH] nixos/test-driver: Hide vde switch log messages --- .../lib/test-driver/src/test_driver/logger.py | 29 ++++++++++++++-- nixos/lib/test-driver/src/test_driver/vlan.py | 34 ++++++++++++++++--- nixos/lib/testing/driver.nix | 1 + 3 files changed, 56 insertions(+), 8 deletions(-) diff --git a/nixos/lib/test-driver/src/test_driver/logger.py b/nixos/lib/test-driver/src/test_driver/logger.py index bce73a402234..a5bf7c61c1a4 100644 --- a/nixos/lib/test-driver/src/test_driver/logger.py +++ b/nixos/lib/test-driver/src/test_driver/logger.py @@ -18,9 +18,10 @@ from junit_xml import TestCase, TestSuite class LogLevel(IntEnum): - INFO = 1 - WARNING = 2 - ERROR = 3 + DEBUG = 1 + INFO = 2 + WARNING = 3 + ERROR = 4 class AbstractLogger(ABC): @@ -38,6 +39,10 @@ class AbstractLogger(ABC): def nested(self, message: str, attributes: dict[str, str] = {}) -> Iterator[None]: pass + @abstractmethod + def debug(self, *args, **kwargs) -> None: + pass + @abstractmethod def info(self, *args, **kwargs) -> None: pass @@ -102,6 +107,10 @@ class JunitXMLLogger(AbstractLogger): self.log(message) yield + def debug(self, *args, **kwargs) -> None: + if self._log_level <= LogLevel.DEBUG: + self.tests[self.currentSubtest].stdout += args[0] + os.linesep + def info(self, *args, **kwargs) -> None: if self._log_level <= LogLevel.INFO: self.tests[self.currentSubtest].stdout += args[0] + os.linesep @@ -171,6 +180,10 @@ class CompositeLogger(AbstractLogger): stack.enter_context(logger.nested(message, attributes)) yield + def debug(self, *args, **kwargs) -> None: + for logger in self.logger_list: + logger.debug(*args, **kwargs) + def info(self, *args, **kwargs) -> None: for logger in self.logger_list: logger.info(*args, **kwargs) @@ -237,6 +250,12 @@ class TerminalLogger(AbstractLogger): toc = time.time() self.log(f"(finished: {message}, in {toc - tic:.2f} seconds)", attributes) + def debug(self, *args, **kwargs) -> None: + if self._log_level <= LogLevel.DEBUG: + self._eprint( + Style.DIM + self.maybe_prefix(args[0], kwargs) + Style.RESET_ALL # ty: ignore[unsupported-operator] + ) + def info(self, *args, **kwargs) -> None: if self._log_level <= LogLevel.INFO: self.log(*args, **kwargs) @@ -296,6 +315,10 @@ class XMLLogger(AbstractLogger): self.xml.characters(message) self.xml.endElement("line") + def debug(self, *args, **kwargs) -> None: + if self._log_level <= LogLevel.DEBUG: + self.log(*args, **kwargs) + def info(self, *args, **kwargs) -> None: if self._log_level <= LogLevel.INFO: self.log(*args, **kwargs) diff --git a/nixos/lib/test-driver/src/test_driver/vlan.py b/nixos/lib/test-driver/src/test_driver/vlan.py index eed66dcd13cb..232749da7544 100644 --- a/nixos/lib/test-driver/src/test_driver/vlan.py +++ b/nixos/lib/test-driver/src/test_driver/vlan.py @@ -4,6 +4,7 @@ import io import os import select import subprocess +import threading import typing from pathlib import Path @@ -57,6 +58,11 @@ class VLan: def __repr__(self) -> str: return f"" + def _log_stream(self, stream: typing.IO[str], prefix: str) -> None: + """Read lines from a stream and log via debug().""" + for line in stream: + self.logger.debug(f"{prefix}: {line.rstrip()}") + def __init__(self, nr: int, tmp_dir: Path, logger: AbstractLogger): self.nr = nr self.socket_dir = tmp_dir / f"vde{self.nr}.ctl" @@ -66,7 +72,7 @@ class VLan: # TODO: don't side-effect environment here os.environ[f"QEMU_VDE_SOCKET_{self.nr}"] = str(self.socket_dir) - self.logger.info("start vlan") + self.logger.debug("start vlan") self.process = subprocess.Popen( [ @@ -84,7 +90,7 @@ class VLan: bufsize=1, # Line buffered. stdin=subprocess.PIPE, stdout=subprocess.PIPE, - stderr=None, # Do not swallow stderr. + stderr=subprocess.STDOUT, text=True, ) self.pid = self.process.pid @@ -117,19 +123,37 @@ class VLan: if "1000 Success" in line: break + self._stdout_thread = threading.Thread( + target=self._log_stream, + args=(self.process.stdout, f"vde_switch[{self.nr}]"), + daemon=True, + ) + self._stdout_thread.start() + # This is needed to allow systemd-nspawn containers to communicate # with VMs connected to the VLAN. - self.logger.info(f"creating tap interface {self.tap_name}") + self.logger.debug(f"creating tap interface {self.tap_name}") self.plug_process = subprocess.Popen( ["vde_plug2tap", "-s", self.socket_dir, self.tap_name], + stdout=subprocess.PIPE, + stderr=subprocess.STDOUT, + text=True, ) + assert self.plug_process.stdout is not None + self._plug_stdout_thread = threading.Thread( + target=self._log_stream, + args=(self.plug_process.stdout, f"vde_plug2tap[{self.nr}]"), + daemon=True, + ) + self._plug_stdout_thread.start() + assert (self.socket_dir / "ctl").exists(), "cannot start vde_switch" - self.logger.info(f"running vlan (pid {self.pid}; ctl {self.socket_dir})") + self.logger.debug(f"running vlan (pid {self.pid}; ctl {self.socket_dir})") def stop(self) -> None: - self.logger.info(f"kill vlan (pid {self.pid})") + self.logger.debug(f"kill vlan (pid {self.pid})") assert self.process.stdin is not None self.process.stdin.close() if self.plug_process: diff --git a/nixos/lib/testing/driver.nix b/nixos/lib/testing/driver.nix index e9808907b2c5..606a7e225b68 100644 --- a/nixos/lib/testing/driver.nix +++ b/nixos/lib/testing/driver.nix @@ -234,6 +234,7 @@ in logLevel = mkOption { description = "Log level for the test driver."; type = types.enum [ + "debug" "info" "warning" "error"