From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mails.dpdk.org (mails.dpdk.org [217.70.189.124]) by inbox.dpdk.org (Postfix) with ESMTP id 6CF3A43B29; Wed, 14 Feb 2024 08:49:35 +0100 (CET) Received: from mails.dpdk.org (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id 5A87440A7A; Wed, 14 Feb 2024 08:49:35 +0100 (CET) Received: from mail-ed1-f48.google.com (mail-ed1-f48.google.com [209.85.208.48]) by mails.dpdk.org (Postfix) with ESMTP id 5C47640263 for ; Wed, 14 Feb 2024 08:49:33 +0100 (CET) Received: by mail-ed1-f48.google.com with SMTP id 4fb4d7f45d1cf-55ee686b5d5so6911483a12.0 for ; Tue, 13 Feb 2024 23:49:33 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=pantheon.tech; s=google; t=1707896973; x=1708501773; darn=dpdk.org; h=content-transfer-encoding:cc:to:subject:message-id:date:from :in-reply-to:references:mime-version:from:to:cc:subject:date :message-id:reply-to; bh=xE+EaUQZyrKLyvXfuXTJt2bN9GnD0IHsxLg6nX7rAa8=; b=HWhppFeXUiT2E2gBWSEeIrJk5dzclGiSufIz6HBsbK/5ukew5YYRZ0zs7eCmGfyH+9 5mfZ+dkpoUGF/B65Dv+EH6d+b9bz1J5N2cpugiPWiAwGgpEbiXerFbiouPFA3mEyQyDb B6LBCM+1P2vGw9ZPBP7g3TbRpoDTyPZB9yHy3c1hvfSJDIx6LC0boF41Y6RVPrsNjWLY SEbjXAKtTxRI2fgb+/XPjo2kE4TY6AdZ76f4VYQ+Xmch4CTFKUaRp2tHQY84zyoK/yTE CeJjEkG855k9Tnil9uzX2g89XSsiFAO0P+ztjem4jfVUJT3sHeWAj7ftGzhvRRjxZ1DR pLOw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1707896973; x=1708501773; h=content-transfer-encoding:cc:to:subject:message-id:date:from :in-reply-to:references:mime-version:x-gm-message-state:from:to:cc :subject:date:message-id:reply-to; bh=xE+EaUQZyrKLyvXfuXTJt2bN9GnD0IHsxLg6nX7rAa8=; b=QxxC62yPquHihDBZ8BgWA6INn7Kx+SJ4hw/HyFEOMJxYdOkW+58mfV998fgWLhAXRR xKnlFzERwWrTJ0IBTWRsfB6+qfdzLKO753EnoQd+NxfR4awh4jqusZvUfhthOnNHa040 F8uWJv8Di03cN4D/8jBjevKauo0/GBTeMerjXn8clm6i67ZwFdJKIH7sOWWyVpWjJVoW ujAf8J9XEAvZWp39NoNru6l7FY3XQr25AgElgwJE/k6H/uE2tA5rhma0cN+jqT2EaY+O TG//RYCJ0EcA8WbpTwVbVvGX7mLQWhYChh4lQZvo02RXtIBlykg0F88C0F88iDWhUZxK BmkA== X-Forwarded-Encrypted: i=1; AJvYcCVHVQGLNlCydwMZcftAe9ymkPUA4qUm1rD2VGg8fXms9mSR6guAA6X3Yn/DqqYgtG4WQ7+TyzRPcjLn2wY= X-Gm-Message-State: AOJu0YxFwF0GcHsvedXQgVkleSkczd5Mv4EXSuFJ3kKpOf9yPIamphyY WTk+cJZ6SZrSYM1qFADdPb2Q1sfIUmuPlPNzhdoe1u5Wmg229RX4H8uPQu35dwwxinXr4i9KmEM pxmloUoimJh3YKsVtwkYMnVKmwYHaFCueAsj3Vw== X-Google-Smtp-Source: AGHT+IHT2XdUcbXpz/2ikQQYDuBVEurOfljCJdZ2e6DFhMQbvPz45Zf0pieUTxUq4jw1KAiHu1ryUGif1rNv5wh0Fak= X-Received: by 2002:a17:906:378a:b0:a3c:91aa:7562 with SMTP id n10-20020a170906378a00b00a3c91aa7562mr1146984ejc.2.1707896972632; Tue, 13 Feb 2024 23:49:32 -0800 (PST) MIME-Version: 1.0 References: <20231220103331.60888-1-juraj.linkes@pantheon.tech> <20240206145716.71435-1-juraj.linkes@pantheon.tech> <20240206145716.71435-7-juraj.linkes@pantheon.tech> In-Reply-To: From: =?UTF-8?Q?Juraj_Linke=C5=A1?= Date: Wed, 14 Feb 2024 08:49:21 +0100 Message-ID: Subject: Re: [PATCH v2 6/7] dts: refactor logging configuration To: Jeremy Spewock Cc: thomas@monjalon.net, Honnappa.Nagarahalli@arm.com, probb@iol.unh.edu, paul.szczepanek@arm.com, Luca.Vizzarro@arm.com, dev@dpdk.org Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable X-BeenThere: dev@dpdk.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: DPDK patches and discussions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: dev-bounces@dpdk.org Hi Jeremy, Just a reminder, please strip the parts you're not commenting on. On Mon, Feb 12, 2024 at 5:45=E2=80=AFPM Jeremy Spewock wrote: > > On Tue, Feb 6, 2024 at 9:57=E2=80=AFAM Juraj Linke=C5=A1 wrote: > > > > Remove unused parts of the code and add useful features: > > 1. Add DTS execution stages such as execution and test suite to better > > identify where in the DTS lifecycle we are when investigating logs, > > 2. Logging to separate files in specific stages, which is mainly useful > > for having test suite logs in additional separate files. > > 3. Remove the dependence on the settings module which enhances the > > usefulness of the logger module, as it can now be imported in more > > modules. > > > > The execution stages and the files to log to are the same for all DTS > > loggers. To achieve this, we have one DTS root logger which should be > > used for handling stage switching and all other loggers are children of > > this DTS root logger. The DTS root logger is the one where we change th= e > > behavior of all loggers (the stage and which files to log to) and the > > child loggers just log messages under a different name. > > > > Signed-off-by: Juraj Linke=C5=A1 > > --- > > dts/framework/logger.py | 235 +++++++++++------- > > dts/framework/remote_session/__init__.py | 6 +- > > .../interactive_remote_session.py | 6 +- > > .../remote_session/interactive_shell.py | 6 +- > > .../remote_session/remote_session.py | 8 +- > > dts/framework/runner.py | 19 +- > > dts/framework/test_result.py | 6 +- > > dts/framework/test_suite.py | 6 +- > > dts/framework/testbed_model/node.py | 11 +- > > dts/framework/testbed_model/os_session.py | 7 +- > > .../traffic_generator/traffic_generator.py | 6 +- > > dts/main.py | 1 - > > 12 files changed, 183 insertions(+), 134 deletions(-) > > > > diff --git a/dts/framework/logger.py b/dts/framework/logger.py > > index cfa6e8cd72..568edad82d 100644 > > --- a/dts/framework/logger.py > > +++ b/dts/framework/logger.py > > @@ -5,141 +5,186 @@ > > > > """DTS logger module. > > > > -DTS framework and TestSuite logs are saved in different log files. > > +The module provides several additional features: > > + > > + * The storage of DTS execution stages, > > + * Logging to console, a human-readable log file and a machine-read= able log file, > > + * Optional log files for specific stages. > > """ > > > > import logging > > -import os.path > > -from typing import TypedDict > > +from enum import auto > > +from logging import FileHandler, StreamHandler > > +from pathlib import Path > > +from typing import ClassVar > > > > -from .settings import SETTINGS > > +from .utils import StrEnum > > > > date_fmt =3D "%Y/%m/%d %H:%M:%S" > > -stream_fmt =3D "%(asctime)s - %(name)s - %(levelname)s - %(message)s" > > +stream_fmt =3D "%(asctime)s - %(stage)s - %(name)s - %(levelname)s - %= (message)s" > > +dts_root_logger_name =3D "dts" > > + > > + > > +class DtsStage(StrEnum): > > + """The DTS execution stage.""" > > > > + #: > > + pre_execution =3D auto() > > + #: > > + execution =3D auto() > > + #: > > + build_target =3D auto() > > + #: > > + suite =3D auto() > > + #: > > + post_execution =3D auto() > > > > -class DTSLOG(logging.LoggerAdapter): > > - """DTS logger adapter class for framework and testsuites. > > > > - The :option:`--verbose` command line argument and the :envvar:`DTS= _VERBOSE` environment > > - variable control the verbosity of output. If enabled, all messages= will be emitted to the > > - console. > > +class DTSLogger(logging.Logger): > > + """The DTS logger class. > > > > - The :option:`--output` command line argument and the :envvar:`DTS_= OUTPUT_DIR` environment > > - variable modify the directory where the logs will be stored. > > + The class extends the :class:`~logging.Logger` class to add the DT= S execution stage information > > + to log records. The stage is common to all loggers, so it's stored= in a class variable. > > > > - Attributes: > > - node: The additional identifier. Currently unused. > > - sh: The handler which emits logs to console. > > - fh: The handler which emits logs to a file. > > - verbose_fh: Just as fh, but logs with a different, more verbos= e, format. > > + Any time we switch to a new stage, we have the ability to log to a= n additional log file along > > + with a supplementary log file with machine-readable format. These = two log files are used until > > + a new stage switch occurs. This is useful mainly for logging per t= est suite. > > """ > > > > - _logger: logging.Logger > > - node: str > > - sh: logging.StreamHandler > > - fh: logging.FileHandler > > - verbose_fh: logging.FileHandler > > + _stage: ClassVar[DtsStage] =3D DtsStage.pre_execution > > + _extra_file_handlers: list[FileHandler] =3D [] > > > > - def __init__(self, logger: logging.Logger, node: str =3D "suite"): > > - """Extend the constructor with additional handlers. > > + def __init__(self, *args, **kwargs): > > + """Extend the constructor with extra file handlers.""" > > + self._extra_file_handlers =3D [] > > + super().__init__(*args, **kwargs) > > > > - One handler logs to the console, the other one to a file, with= either a regular or verbose > > - format. > > + def makeRecord(self, *args, **kwargs): > > Is the return type annotation here skipped because of the `:meta private:= `? > Basically. We're modifying a method defined elsewhere, but there's no harm in adding the return type. > > + """Generates a record with additional stage information. > > > > - Args: > > - logger: The logger from which to create the logger adapter= . > > - node: An additional identifier. Currently unused. > > + This is the default method for the :class:`~logging.Logger` cl= ass. We extend it > > + to add stage information to the record. > > + > > + :meta private: > > + > > + Returns: > > + record: The generated record with the stage information. > > """ > > - self._logger =3D logger > > - # 1 means log everything, this will be used by file handlers i= f their level > > - # is not set > > - self._logger.setLevel(1) > > + record =3D super().makeRecord(*args, **kwargs) > > + record.stage =3D DTSLogger._stage > > + return record > > + > > + def add_dts_root_logger_handlers(self, verbose: bool, output_dir: = str) -> None: > > + """Add logger handlers to the DTS root logger. > > + > > + This method should be called only on the DTS root logger. > > + The log records from child loggers will propagate to these han= dlers. > > + > > + Three handlers are added: > > > > - self.node =3D node > > + * A console handler, > > + * A file handler, > > + * A supplementary file handler with machine-readable logs > > + containing more debug information. > > > > - # add handler to emit to stdout > > - sh =3D logging.StreamHandler() > > + All log messages will be logged to files. The log level of the= console handler > > + is configurable with `verbose`. > > + > > + Args: > > + verbose: If :data:`True`, log all messages to the console. > > + If :data:`False`, log to console with the :data:`loggi= ng.INFO` level. > > + output_dir: The directory where the log files will be loca= ted. > > + The names of the log files correspond to the name of t= he logger instance. > > + """ > > + self.setLevel(1) > > + > > + sh =3D StreamHandler() > > sh.setFormatter(logging.Formatter(stream_fmt, date_fmt)) > > - sh.setLevel(logging.INFO) # console handler default level > > + if not verbose: > > + sh.setLevel(logging.INFO) > > + self.addHandler(sh) > > > > - if SETTINGS.verbose is True: > > - sh.setLevel(logging.DEBUG) > > + self._add_file_handlers(Path(output_dir, self.name)) > > > > - self._logger.addHandler(sh) > > - self.sh =3D sh > > + def set_stage(self, stage: DtsStage, log_file_path: Path | None = =3D None) -> None: > > + """Set the DTS execution stage and optionally log to files. > > > > - # prepare the output folder > > - if not os.path.exists(SETTINGS.output_dir): > > - os.mkdir(SETTINGS.output_dir) > > + Set the DTS execution stage of the DTSLog class and optionally= add > > + file handlers to the instance if the log file name is provided= . > > > > - logging_path_prefix =3D os.path.join(SETTINGS.output_dir, node= ) > > + The file handlers log all messages. One is a regular human-rea= dable log file and > > + the other one is a machine-readable log file with extra debug = information. > > > > - fh =3D logging.FileHandler(f"{logging_path_prefix}.log") > > - fh.setFormatter( > > - logging.Formatter( > > - fmt=3D"%(asctime)s - %(name)s - %(levelname)s - %(mess= age)s", > > - datefmt=3Ddate_fmt, > > - ) > > - ) > > + Args: > > + stage: The DTS stage to set. > > + log_file_path: An optional path of the log file to use. Th= is should be a full path > > + (either relative or absolute) without suffix (which wi= ll be appended). > > + """ > > + self._remove_extra_file_handlers() > > + > > + if DTSLogger._stage !=3D stage: > > + self.info(f"Moving from stage '{DTSLogger._stage}' to stag= e '{stage}'.") > > + DTSLogger._stage =3D stage > > + > > + if log_file_path: > > + self._extra_file_handlers.extend(self._add_file_handlers(l= og_file_path)) > > + > > + def _add_file_handlers(self, log_file_path: Path) -> list[FileHand= ler]: > > + """Add file handlers to the DTS root logger. > > + > > + Add two type of file handlers: > > + > > + * A regular file handler with suffix ".log", > > + * A machine-readable file handler with suffix ".verbose.lo= g". > > + This format provides extensive information for debugging= and detailed analysis. > > + > > + Args: > > + log_file_path: The full path to the log file without suffi= x. > > + > > + Returns: > > + The newly created file handlers. > > > > - self._logger.addHandler(fh) > > - self.fh =3D fh > > + """ > > + fh =3D FileHandler(f"{log_file_path}.log") > > + fh.setFormatter(logging.Formatter(stream_fmt, date_fmt)) > > + self.addHandler(fh) > > > > - # This outputs EVERYTHING, intended for post-mortem debugging > > - # Also optimized for processing via AWK (awk -F '|' ...) > > - verbose_fh =3D logging.FileHandler(f"{logging_path_prefix}.ver= bose.log") > > + verbose_fh =3D FileHandler(f"{log_file_path}.verbose.log") > > verbose_fh.setFormatter( > > logging.Formatter( > > - fmt=3D"%(asctime)s|%(name)s|%(levelname)s|%(pathname)s= |%(lineno)d|" > > + "%(asctime)s|%(stage)s|%(name)s|%(levelname)s|%(pathna= me)s|%(lineno)d|" > > "%(funcName)s|%(process)d|%(thread)d|%(threadName)s|%(= message)s", > > datefmt=3Ddate_fmt, > > ) > > ) > > + self.addHandler(verbose_fh) > > > > - self._logger.addHandler(verbose_fh) > > - self.verbose_fh =3D verbose_fh > > - > > - super(DTSLOG, self).__init__(self._logger, dict(node=3Dself.no= de)) > > - > > - def logger_exit(self) -> None: > > - """Remove the stream handler and the logfile handler.""" > > - for handler in (self.sh, self.fh, self.verbose_fh): > > - handler.flush() > > - self._logger.removeHandler(handler) > > - > > - > > -class _LoggerDictType(TypedDict): > > - logger: DTSLOG > > - name: str > > - node: str > > - > > + return [fh, verbose_fh] > > > > -# List for saving all loggers in use > > -_Loggers: list[_LoggerDictType] =3D [] > > + def _remove_extra_file_handlers(self) -> None: > > + """Remove any extra file handlers that have been added to the = logger.""" > > + if self._extra_file_handlers: > > + for extra_file_handler in self._extra_file_handlers: > > + self.removeHandler(extra_file_handler) > > > > + self._extra_file_handlers =3D [] > > > > -def getLogger(name: str, node: str =3D "suite") -> DTSLOG: > > - """Get DTS logger adapter identified by name and node. > > > > - An existing logger will be returned if one with the exact name and= node already exists. > > - A new one will be created and stored otherwise. > > +def get_dts_logger(name: str =3D None) -> DTSLogger: > > + """Return a DTS logger instance identified by `name`. > > > > Args: > > - name: The name of the logger. > > - node: An additional identifier for the logger. > > + name: If :data:`None`, return the DTS root logger. > > + If specified, return a child of the DTS root logger. > > > > Returns: > > - A logger uniquely identified by both name and node. > > + The DTS root logger or a child logger identified by `name`. > > """ > > - global _Loggers > > - # return saved logger > > - logger: _LoggerDictType > > - for logger in _Loggers: > > - if logger["name"] =3D=3D name and logger["node"] =3D=3D node: > > - return logger["logger"] > > - > > - # return new logger > > - dts_logger: DTSLOG =3D DTSLOG(logging.getLogger(name), node) > > - _Loggers.append({"logger": dts_logger, "name": name, "node": node}= ) > > - return dts_logger > > + logging.setLoggerClass(DTSLogger) > > + if name: > > + name =3D f"{dts_root_logger_name}.{name}" > > + else: > > + name =3D dts_root_logger_name > > + logger =3D logging.getLogger(name) > > + logging.setLoggerClass(logging.Logger) > > What's the benefit of setting the logger class back to logging.Logger > here? Is the idea basically that if someone wanted to use the logging > module we shouldn't implicitly make them use our DTSLogger? > Yes. We should actually set it to whatever was there before (it may not be logging.Logger), so I'll change that.+ > > + return logger # type: ignore[return-value] > > diff --git a/dts/framework/remote_session/__init__.py b/dts/framework/r= emote_session/__init__.py > > index 51a01d6b5e..1910c81c3c 100644 > > --- a/dts/framework/remote_session/__init__.py > > +++ b/dts/framework/remote_session/__init__.py > > @@ -15,7 +15,7 @@ > > # pylama:ignore=3DW0611 > > > > from framework.config import NodeConfiguration > > -from framework.logger import DTSLOG > > +from framework.logger import DTSLogger > > > > from .interactive_remote_session import InteractiveRemoteSession > > from .interactive_shell import InteractiveShell > > @@ -26,7 +26,7 @@ > > > > > > def create_remote_session( > > - node_config: NodeConfiguration, name: str, logger: DTSLOG > > + node_config: NodeConfiguration, name: str, logger: DTSLogger > > ) -> RemoteSession: > > """Factory for non-interactive remote sessions. > > > > @@ -45,7 +45,7 @@ def create_remote_session( > > > > > > def create_interactive_session( > > - node_config: NodeConfiguration, logger: DTSLOG > > + node_config: NodeConfiguration, logger: DTSLogger > > ) -> InteractiveRemoteSession: > > """Factory for interactive remote sessions. > > > > diff --git a/dts/framework/remote_session/interactive_remote_session.py= b/dts/framework/remote_session/interactive_remote_session.py > > index 1cc82e3377..c50790db79 100644 > > --- a/dts/framework/remote_session/interactive_remote_session.py > > +++ b/dts/framework/remote_session/interactive_remote_session.py > > @@ -16,7 +16,7 @@ > > > > from framework.config import NodeConfiguration > > from framework.exception import SSHConnectionError > > -from framework.logger import DTSLOG > > +from framework.logger import DTSLogger > > > > > > class InteractiveRemoteSession: > > @@ -50,11 +50,11 @@ class InteractiveRemoteSession: > > username: str > > password: str > > session: SSHClient > > - _logger: DTSLOG > > + _logger: DTSLogger > > _node_config: NodeConfiguration > > _transport: Transport | None > > > > - def __init__(self, node_config: NodeConfiguration, logger: DTSLOG)= -> None: > > + def __init__(self, node_config: NodeConfiguration, logger: DTSLogg= er) -> None: > > """Connect to the node during initialization. > > > > Args: > > diff --git a/dts/framework/remote_session/interactive_shell.py b/dts/fr= amework/remote_session/interactive_shell.py > > index b158f963b6..5cfe202e15 100644 > > --- a/dts/framework/remote_session/interactive_shell.py > > +++ b/dts/framework/remote_session/interactive_shell.py > > @@ -20,7 +20,7 @@ > > > > from paramiko import Channel, SSHClient, channel # type: ignore[impor= t] > > > > -from framework.logger import DTSLOG > > +from framework.logger import DTSLogger > > from framework.settings import SETTINGS > > > > > > @@ -38,7 +38,7 @@ class InteractiveShell(ABC): > > _stdin: channel.ChannelStdinFile > > _stdout: channel.ChannelFile > > _ssh_channel: Channel > > - _logger: DTSLOG > > + _logger: DTSLogger > > _timeout: float > > _app_args: str > > > > @@ -61,7 +61,7 @@ class InteractiveShell(ABC): > > def __init__( > > self, > > interactive_session: SSHClient, > > - logger: DTSLOG, > > + logger: DTSLogger, > > get_privileged_command: Callable[[str], str] | None, > > app_args: str =3D "", > > timeout: float =3D SETTINGS.timeout, > > diff --git a/dts/framework/remote_session/remote_session.py b/dts/frame= work/remote_session/remote_session.py > > index 2059f9a981..a69dc99400 100644 > > --- a/dts/framework/remote_session/remote_session.py > > +++ b/dts/framework/remote_session/remote_session.py > > @@ -9,14 +9,13 @@ > > the structure of the result of a command execution. > > """ > > > > - > > import dataclasses > > from abc import ABC, abstractmethod > > from pathlib import PurePath > > > > from framework.config import NodeConfiguration > > from framework.exception import RemoteCommandExecutionError > > -from framework.logger import DTSLOG > > +from framework.logger import DTSLogger > > from framework.settings import SETTINGS > > > > > > @@ -75,14 +74,14 @@ class RemoteSession(ABC): > > username: str > > password: str > > history: list[CommandResult] > > - _logger: DTSLOG > > + _logger: DTSLogger > > _node_config: NodeConfiguration > > > > def __init__( > > self, > > node_config: NodeConfiguration, > > session_name: str, > > - logger: DTSLOG, > > + logger: DTSLogger, > > ): > > """Connect to the node during initialization. > > > > @@ -181,7 +180,6 @@ def close(self, force: bool =3D False) -> None: > > Args: > > force: Force the closure of the connection. This may not c= lean up all resources. > > """ > > - self._logger.logger_exit() > > self._close(force) > > > > @abstractmethod > > diff --git a/dts/framework/runner.py b/dts/framework/runner.py > > index f58b0adc13..035e3368ef 100644 > > --- a/dts/framework/runner.py > > +++ b/dts/framework/runner.py > > @@ -19,9 +19,10 @@ > > > > import importlib > > import inspect > > -import logging > > +import os > > import re > > import sys > > +from pathlib import Path > > from types import MethodType > > from typing import Iterable > > > > @@ -38,7 +39,7 @@ > > SSHTimeoutError, > > TestCaseVerifyError, > > ) > > -from .logger import DTSLOG, getLogger > > +from .logger import DTSLogger, DtsStage, get_dts_logger > > from .settings import SETTINGS > > from .test_result import ( > > BuildTargetResult, > > @@ -73,7 +74,7 @@ class DTSRunner: > > """ > > > > _configuration: Configuration > > - _logger: DTSLOG > > + _logger: DTSLogger > > _result: DTSResult > > _test_suite_class_prefix: str > > _test_suite_module_prefix: str > > @@ -83,7 +84,10 @@ class DTSRunner: > > def __init__(self): > > """Initialize the instance with configuration, logger, result = and string constants.""" > > self._configuration =3D load_config() > > - self._logger =3D getLogger("DTSRunner") > > + self._logger =3D get_dts_logger() > > + if not os.path.exists(SETTINGS.output_dir): > > + os.makedirs(SETTINGS.output_dir) > > + self._logger.add_dts_root_logger_handlers(SETTINGS.verbose, SE= TTINGS.output_dir) > > self._result =3D DTSResult(self._logger) > > self._test_suite_class_prefix =3D "Test" > > self._test_suite_module_prefix =3D "tests.TestSuite_" > > @@ -137,6 +141,7 @@ def run(self): > > > > # for all Execution sections > > for execution in self._configuration.executions: > > + self._logger.set_stage(DtsStage.execution) > > This ends up getting set twice in short succession which of course > doesn't functionally cause a problem, but I don't exactly see the > point of setting it twice. I'm not sure what you're referring to. The stage is only set once at the start of each execution (and more generally, at the start of each stage). It's also set in each finally block to properly mark the cleanup of that stage. There are two finally blocks in the execution stage where that could happen, but otherwise it should be set exactly once. > We could either set it here or set it in > the _run_execution, but i think it makes more sense to set it in the > _run_execution method as that is the method where we are doing the > setup, here we are only initializing the nodes which is still in a > sense "pre execution." Init nodes was pre-execution before the patch. I've moved it to execution because of two reasons: 1. The nodes are actually defined per-execution. It just made more sense to move them to execution. Also, if an error happens while connecting to a node, we don't want to abort the whole DTS run, just the execution, as the next execution could be connecting to a different node. 2. We're not just doing node init here, we're also discovering which test cases to run. This is essential to do as soon as possible (before anything else happens in the execution, such as connecting the nodes) so that we can mark blocked test cases in case of an error. Test case discovery is definitely part of each execution and putting node init after that was a natural consequence. There's an argument for discovering test cases of all executions before actually running any of the executions. It's certainly doable, but the code doesn't look that good (when not modifying the original execution config (which we shouldn't do) - I've tried) and there's actually not much of a point to do it this way, the result is almost the same. Where it makes a difference is when there's an error in test suite configuration and later executions - the user would have to wait for the previous execution to fully run to discover the error). > > > > self._logger.info( > > f"Running execution with SUT '{execution.system_un= der_test_node.name}'." > > ) > > @@ -164,6 +169,7 @@ def run(self): > > > > finally: > > try: > > + self._logger.set_stage(DtsStage.post_execution) > > for node in (sut_nodes | tg_nodes).values(): > > node.close() > > self._result.update_teardown(Result.PASS) > > @@ -419,6 +425,7 @@ def _run_execution( > > > > finally: > > try: > > + self._logger.set_stage(DtsStage.execution) > > sut_node.tear_down_execution() > > execution_result.update_teardown(Result.PASS) > > except Exception as e: > > @@ -447,6 +454,7 @@ def _run_build_target( > > with the current build target. > > test_suites_with_cases: The test suites with test cases to= run. > > """ > > + self._logger.set_stage(DtsStage.build_target) > > self._logger.info(f"Running build target '{build_target.name}'= .") > > > > try: > > @@ -463,6 +471,7 @@ def _run_build_target( > > > > finally: > > try: > > + self._logger.set_stage(DtsStage.build_target) > > sut_node.tear_down_build_target() > > build_target_result.update_teardown(Result.PASS) > > except Exception as e: > > @@ -535,6 +544,7 @@ def _run_test_suite( > > BlockingTestSuiteError: If a blocking test suite fails. > > """ > > test_suite_name =3D test_suite_with_cases.test_suite_class.__n= ame__ > > + self._logger.set_stage(DtsStage.suite, Path(SETTINGS.output_di= r, test_suite_name)) > > test_suite =3D test_suite_with_cases.test_suite_class(sut_node= , tg_node) > > try: > > self._logger.info(f"Starting test suite setup: {test_suite= _name}") > > @@ -683,5 +693,4 @@ def _exit_dts(self) -> None: > > if self._logger: > > self._logger.info("DTS execution has ended.") > > > > - logging.shutdown() > > sys.exit(self._result.get_return_code()) > > diff --git a/dts/framework/test_result.py b/dts/framework/test_result.p= y > > index eedb2d20ee..28f84fd793 100644 > > --- a/dts/framework/test_result.py > > +++ b/dts/framework/test_result.py > > @@ -42,7 +42,7 @@ > > TestSuiteConfig, > > ) > > from .exception import DTSError, ErrorSeverity > > -from .logger import DTSLOG > > +from .logger import DTSLogger > > from .settings import SETTINGS > > from .test_suite import TestSuite > > > > @@ -237,13 +237,13 @@ class DTSResult(BaseResult): > > """ > > > > dpdk_version: str | None > > - _logger: DTSLOG > > + _logger: DTSLogger > > _errors: list[Exception] > > _return_code: ErrorSeverity > > _stats_result: Union["Statistics", None] > > _stats_filename: str > > > > - def __init__(self, logger: DTSLOG): > > + def __init__(self, logger: DTSLogger): > > """Extend the constructor with top-level specifics. > > > > Args: > > diff --git a/dts/framework/test_suite.py b/dts/framework/test_suite.py > > index f9fe88093e..365f80e21a 100644 > > --- a/dts/framework/test_suite.py > > +++ b/dts/framework/test_suite.py > > @@ -21,7 +21,7 @@ > > from scapy.packet import Packet, Padding # type: ignore[import] > > > > from .exception import TestCaseVerifyError > > -from .logger import DTSLOG, getLogger > > +from .logger import DTSLogger, get_dts_logger > > from .testbed_model import Port, PortLink, SutNode, TGNode > > from .utils import get_packet_summaries > > > > @@ -61,7 +61,7 @@ class TestSuite(object): > > #: Whether the test suite is blocking. A failure of a blocking tes= t suite > > #: will block the execution of all subsequent test suites in the c= urrent build target. > > is_blocking: ClassVar[bool] =3D False > > - _logger: DTSLOG > > + _logger: DTSLogger > > _port_links: list[PortLink] > > _sut_port_ingress: Port > > _sut_port_egress: Port > > @@ -88,7 +88,7 @@ def __init__( > > """ > > self.sut_node =3D sut_node > > self.tg_node =3D tg_node > > - self._logger =3D getLogger(self.__class__.__name__) > > + self._logger =3D get_dts_logger(self.__class__.__name__) > > self._port_links =3D [] > > self._process_links() > > self._sut_port_ingress, self._tg_port_egress =3D ( > > diff --git a/dts/framework/testbed_model/node.py b/dts/framework/testbe= d_model/node.py > > index 1a55fadf78..74061f6262 100644 > > --- a/dts/framework/testbed_model/node.py > > +++ b/dts/framework/testbed_model/node.py > > @@ -23,7 +23,7 @@ > > NodeConfiguration, > > ) > > from framework.exception import ConfigurationError > > -from framework.logger import DTSLOG, getLogger > > +from framework.logger import DTSLogger, get_dts_logger > > from framework.settings import SETTINGS > > > > from .cpu import ( > > @@ -63,7 +63,7 @@ class Node(ABC): > > name: str > > lcores: list[LogicalCore] > > ports: list[Port] > > - _logger: DTSLOG > > + _logger: DTSLogger > > _other_sessions: list[OSSession] > > _execution_config: ExecutionConfiguration > > virtual_devices: list[VirtualDevice] > > @@ -82,7 +82,7 @@ def __init__(self, node_config: NodeConfiguration): > > """ > > self.config =3D node_config > > self.name =3D node_config.name > > - self._logger =3D getLogger(self.name) > > + self._logger =3D get_dts_logger(self.name) > > self.main_session =3D create_session(self.config, self.name, s= elf._logger) > > > > self._logger.info(f"Connected to node: {self.name}") > > @@ -189,7 +189,7 @@ def create_session(self, name: str) -> OSSession: > > connection =3D create_session( > > self.config, > > session_name, > > - getLogger(session_name, node=3Dself.name), > > + get_dts_logger(session_name), > > ) > > self._other_sessions.append(connection) > > return connection > > @@ -299,7 +299,6 @@ def close(self) -> None: > > self.main_session.close() > > for session in self._other_sessions: > > session.close() > > - self._logger.logger_exit() > > > > @staticmethod > > def skip_setup(func: Callable[..., Any]) -> Callable[..., Any]: > > @@ -314,7 +313,7 @@ def skip_setup(func: Callable[..., Any]) -> Callabl= e[..., Any]: > > return func > > > > > > -def create_session(node_config: NodeConfiguration, name: str, logger: = DTSLOG) -> OSSession: > > +def create_session(node_config: NodeConfiguration, name: str, logger: = DTSLogger) -> OSSession: > > """Factory for OS-aware sessions. > > > > Args: > > diff --git a/dts/framework/testbed_model/os_session.py b/dts/framework/= testbed_model/os_session.py > > index ac6bb5e112..6983aa4a77 100644 > > --- a/dts/framework/testbed_model/os_session.py > > +++ b/dts/framework/testbed_model/os_session.py > > @@ -21,7 +21,6 @@ > > the :attr:`~.node.Node.main_session` translates that to ``rm -rf``= if the node's OS is Linux > > and other commands for other OSs. It also translates the path to m= atch the underlying OS. > > """ > > - > > from abc import ABC, abstractmethod > > from collections.abc import Iterable > > from ipaddress import IPv4Interface, IPv6Interface > > @@ -29,7 +28,7 @@ > > from typing import Type, TypeVar, Union > > > > from framework.config import Architecture, NodeConfiguration, NodeInfo > > -from framework.logger import DTSLOG > > +from framework.logger import DTSLogger > > from framework.remote_session import ( > > CommandResult, > > InteractiveRemoteSession, > > @@ -62,7 +61,7 @@ class OSSession(ABC): > > > > _config: NodeConfiguration > > name: str > > - _logger: DTSLOG > > + _logger: DTSLogger > > remote_session: RemoteSession > > interactive_session: InteractiveRemoteSession > > > > @@ -70,7 +69,7 @@ def __init__( > > self, > > node_config: NodeConfiguration, > > name: str, > > - logger: DTSLOG, > > + logger: DTSLogger, > > ): > > """Initialize the OS-aware session. > > > > diff --git a/dts/framework/testbed_model/traffic_generator/traffic_gene= rator.py b/dts/framework/testbed_model/traffic_generator/traffic_generator.= py > > index c49fbff488..d86d7fb532 100644 > > --- a/dts/framework/testbed_model/traffic_generator/traffic_generator.p= y > > +++ b/dts/framework/testbed_model/traffic_generator/traffic_generator.p= y > > @@ -13,7 +13,7 @@ > > from scapy.packet import Packet # type: ignore[import] > > > > from framework.config import TrafficGeneratorConfig > > -from framework.logger import DTSLOG, getLogger > > +from framework.logger import DTSLogger, get_dts_logger > > from framework.testbed_model.node import Node > > from framework.testbed_model.port import Port > > from framework.utils import get_packet_summaries > > @@ -28,7 +28,7 @@ class TrafficGenerator(ABC): > > > > _config: TrafficGeneratorConfig > > _tg_node: Node > > - _logger: DTSLOG > > + _logger: DTSLogger > > > > def __init__(self, tg_node: Node, config: TrafficGeneratorConfig): > > """Initialize the traffic generator. > > @@ -39,7 +39,7 @@ def __init__(self, tg_node: Node, config: TrafficGene= ratorConfig): > > """ > > self._config =3D config > > self._tg_node =3D tg_node > > - self._logger =3D getLogger(f"{self._tg_node.name} {self._confi= g.traffic_generator_type}") > > + self._logger =3D get_dts_logger(f"{self._tg_node.name} {self._= config.traffic_generator_type}") > > > > def send_packet(self, packet: Packet, port: Port) -> None: > > """Send `packet` and block until it is fully sent. > > diff --git a/dts/main.py b/dts/main.py > > index 1ffe8ff81f..d30c164b95 100755 > > --- a/dts/main.py > > +++ b/dts/main.py > > @@ -30,5 +30,4 @@ def main() -> None: > > > > # Main program begins here > > if __name__ =3D=3D "__main__": > > - logging.raiseExceptions =3D True > > main() > > -- > > 2.34.1 > >