2
0
mirror of https://gitlab.isc.org/isc-projects/bind9 synced 2025-08-22 18:19:42 +00:00

Indent multiline output in pytest logging

When multiline message is logged, indent all but the first line (which
will be preceeded by the LOG_FORMAT). This improves the clarity of logs,
as it's immediately clear which lines are regular log output, and which
ones are multiline debug output.

Adjust the isctest.run.cmd() stdout/stderr logging to this new format.
This commit is contained in:
Nicki Křížek 2025-06-17 17:33:22 +02:00
parent 0a6b0cf68c
commit 23e6b49cc5
2 changed files with 15 additions and 4 deletions

View File

@ -11,10 +11,12 @@
import logging import logging
from pathlib import Path from pathlib import Path
import textwrap
from typing import Dict, Optional from typing import Dict, Optional
LOG_FORMAT = "%(asctime)s %(levelname)7s:%(name)s %(message)s" LOG_FORMAT = "%(asctime)s %(levelname)7s:%(name)s %(message)s"
LOG_INDENT = 4
LOGGERS = { LOGGERS = {
"conftest": None, "conftest": None,
@ -77,6 +79,13 @@ def deinit_test_logger():
LOGGERS["test"] = None LOGGERS["test"] = None
def indent_message(msg):
lines = msg.splitlines()
first = lines[0] + "\n"
to_indent = "\n".join(lines[1:])
return first + textwrap.indent(to_indent, " " * LOG_INDENT)
def log(lvl: int, msg: str, *args, **kwargs): def log(lvl: int, msg: str, *args, **kwargs):
"""Log message with the most-specific logger currently available.""" """Log message with the most-specific logger currently available."""
logger = LOGGERS["test"] logger = LOGGERS["test"]
@ -85,6 +94,8 @@ def log(lvl: int, msg: str, *args, **kwargs):
if logger is None: if logger is None:
logger = LOGGERS["conftest"] logger = LOGGERS["conftest"]
assert logger is not None assert logger is not None
if "\n" in msg:
msg = indent_message(msg)
logger.log(lvl, msg, *args, **kwargs) logger.log(lvl, msg, *args, **kwargs)

View File

@ -31,17 +31,17 @@ def cmd(
env: Optional[dict] = None, env: Optional[dict] = None,
): ):
"""Execute a command with given args as subprocess.""" """Execute a command with given args as subprocess."""
isctest.log.debug(f"command: {' '.join(args)}") isctest.log.debug(f"isctest.run.cmd(): {' '.join(args)}")
def print_debug_logs(procdata): def print_debug_logs(procdata):
if procdata: if procdata:
if log_stdout and procdata.stdout: if log_stdout and procdata.stdout:
isctest.log.debug( isctest.log.debug(
f"~~~ cmd stdout ~~~\n{procdata.stdout.decode('utf-8')}\n~~~~~~~~~~~~~~~~~~" f"isctest.run.cmd(): (stdout)\n{procdata.stdout.decode('utf-8')}"
) )
if log_stderr and procdata.stderr: if log_stderr and procdata.stderr:
isctest.log.debug( isctest.log.debug(
f"~~~ cmd stderr ~~~\n{procdata.stderr.decode('utf-8')}\n~~~~~~~~~~~~~~~~~~" f"isctest.run.cmd(): (stderr)\n{procdata.stderr.decode('utf-8')}"
) )
if env is None: if env is None:
@ -62,7 +62,7 @@ def cmd(
return proc return proc
except subprocess.CalledProcessError as exc: except subprocess.CalledProcessError as exc:
print_debug_logs(exc) print_debug_logs(exc)
isctest.log.debug(f" return code: {exc.returncode}") isctest.log.debug(f"isctest.run.cmd(): (return code) {exc.returncode}")
if raise_on_exception: if raise_on_exception:
raise exc raise exc
return exc return exc