[PATCH v4 3/9] dts: add basic logging facility

[Juraj Linkeš]

> -----Original Message-----
> From: Bruce Richardson <bruce.richardson at intel.com>
> Sent: Thursday, September 8, 2022 10:31 AM
> To: Juraj Linkeš <juraj.linkes at pantheon.tech>
> Cc: thomas at monjalon.net; david.marchand at redhat.com;
> ronan.randles at intel.com; Honnappa.Nagarahalli at arm.com;
> ohilyard at iol.unh.edu; lijuan.tu at intel.com; dev at dpdk.org
> Subject: Re: [PATCH v4 3/9] dts: add basic logging facility
> 
> On Fri, Jul 29, 2022 at 10:55:44AM +0000, Juraj Linkeš wrote:
> > The logging module provides loggers distinguished by two attributes, a
> > custom format and a verbosity switch. The loggers log to both console
> > and more verbosely to files.
> >
> > Signed-off-by: Owen Hilyard <ohilyard at iol.unh.edu>
> > Signed-off-by: Juraj Linkeš <juraj.linkes at pantheon.tech>
> 
> Few small comments inline below.
> 
> Thanks,
> /Bruce
> 
> > ---
> >  dts/framework/__init__.py |   3 +
> >  dts/framework/logger.py   | 124
> ++++++++++++++++++++++++++++++++++++++
> >  2 files changed, 127 insertions(+)
> >  create mode 100644 dts/framework/__init__.py  create mode 100644
> > dts/framework/logger.py
> >
> > diff --git a/dts/framework/__init__.py b/dts/framework/__init__.py new
> > file mode 100644 index 0000000000..3c30bccf43
> > --- /dev/null
> > +++ b/dts/framework/__init__.py
> > @@ -0,0 +1,3 @@
> > +# SPDX-License-Identifier: BSD-3-Clause # Copyright(c) 2022
> > +PANTHEON.tech s.r.o.
> > +#
> > diff --git a/dts/framework/logger.py b/dts/framework/logger.py new
> > file mode 100644 index 0000000000..920ce0fb15
> > --- /dev/null
> > +++ b/dts/framework/logger.py
> > @@ -0,0 +1,124 @@
> > +# SPDX-License-Identifier: BSD-3-Clause # Copyright(c) 2010-2014
> > +Intel Corporation # Copyright(c) 2022 PANTHEON.tech s.r.o.
> > +# Copyright(c) 2022 University of New Hampshire #
> > +
> > +import logging
> > +import os.path
> > +from typing import TypedDict
> > +
> > +"""
> > +DTS logger module with several log level. DTS framework and TestSuite
> > +log will saved into different log files.
> > +"""
> > +verbose = False
> > +date_fmt = "%d/%m/%Y %H:%M:%S"
> 
> Please use Year-month-day ordering for dates, since it's unambiguous - as well
> as being an ISO standard date format. (ISO 8601)
> 

Ack.

> > +stream_fmt = "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
> > +
> > +
> > +class LoggerDictType(TypedDict):
> > +    logger: "DTSLOG"
> > +    name: str
> > +    node: str
> > +
> > +
> > +# List for saving all using loggers
> > +global Loggers
> > +Loggers: list[LoggerDictType] = []
> > +
> > +
> > +def set_verbose() -> None:
> > +    global verbose
> > +    verbose = True
> > +
> 
> Is there a need for a clear_verbose() or "set_not_verbose()" API?
> 

No, this is used with a comman-line option or env variable which just sets it once and that's it.

> > +
> > +class DTSLOG(logging.LoggerAdapter):
> > +    """
> > +    DTS log class for framework and testsuite.
> > +    """
> > +
> > +    node: str
> > +    logger: logging.Logger
> > +    sh: logging.StreamHandler
> > +    fh: logging.FileHandler
> > +    verbose_handler: logging.FileHandler
> > +
> > +    def __init__(self, logger: logging.Logger, node: str = "suite"):
> > +        global log_dir
> > +
> > +        self.logger = logger
> > +        self.logger.setLevel(1)  # 1 means log everything
> > +
> > +        self.node = node
> > +
> > +        # add handler to emit to stdout
> > +        sh = logging.StreamHandler()
> > +        sh.setFormatter(logging.Formatter(stream_fmt, date_fmt))
> > +
> > +        sh.setLevel(logging.DEBUG)  # file handler default level
> > +        global verbose
> > +        if verbose is True:
> > +            sh.setLevel(logging.DEBUG)
> > +        else:
> > +            sh.setLevel(logging.INFO)  # console handler defaultlevel
> 
> The global should be defined at the top of the function.
> Looks like some of the setlevel calls are unnecessary; two should be enough
> rather than three. For example:
> 
> 	sh.setLevel(logging.INFO)
> 	if verbose:
> 		sh.setLevel(logging.DEGUG)
> 

Ack.

> > +
> > +        self.logger.addHandler(sh)
> > +        self.sh = sh
> > +
> > +        if not os.path.exists("output"):
> > +            os.mkdir("output")
> > +
> > +        fh = logging.FileHandler(f"output/{node}.log")
> > +        fh.setFormatter(
> > +            logging.Formatter(
> > +                fmt="%(asctime)s - %(name)s - %(levelname)s - %(message)s",
> > +                datefmt=date_fmt,
> > +            )
> > +        )
> > +
> > +        fh.setLevel(1)  # We want all the logs we can get in the file
> > +        self.logger.addHandler(fh)
> > +        self.fh = fh
> > +
> > +        # This outputs EVERYTHING, intended for post-mortem debugging
> > +        # Also optimized for processing via AWK (awk -F '|' ...)
> > +        verbose_handler = logging.FileHandler(f"output/{node}.verbose.log")
> > +        verbose_handler.setFormatter(
> > +            logging.Formatter(
> > +
> fmt="%(asctime)s|%(name)s|%(levelname)s|%(pathname)s|%(lineno)d|%(funcN
> ame)s|"
> > +                "%(process)d|%(thread)d|%(threadName)s|%(message)s",
> > +                datefmt=date_fmt,
> > +            )
> > +        )
> > +
> > +        verbose_handler.setLevel(1)  # We want all the logs we can get in the file
> > +        self.logger.addHandler(verbose_handler)
> > +        self.verbose_handler = verbose_handler
> > +
> > +        super(DTSLOG, self).__init__(self.logger,
> > + dict(node=self.node))
> > +
> > +    def logger_exit(self) -> None:
> > +        """
> > +        Remove stream handler and logfile handler.
> > +        """
> > +        for handler in (self.sh, self.fh, self.verbose_handler):
> > +            handler.flush()
> > +            self.logger.removeHandler(handler)
> > +
> > +
> > +def getLogger(name: str, node: str = "suite") -> DTSLOG:
> > +    """
> > +    Get logger handler and if there's no handler for specified Node will create
> one.
> > +    """
> > +    global Loggers
> > +    # return saved logger
> > +    logger: LoggerDictType
> > +    for logger in Loggers:
> > +        if logger["name"] == name and logger["node"] == node:
> > +            return logger["logger"]
> > +
> > +    # return new logger
> > +    dts_logger: DTSLOG = DTSLOG(logging.getLogger(name), node)
> > +    Loggers.append({"logger": dts_logger, "name": name, "node": node})
> > +    return dts_logger
> 
> Looking through this patch alone, I see the "verbose" global only seems to be
> used to set the log-level in the logger init function. If this is the only use of it
> across all the patches in the set, it may be more readable to change the variable
> from a "verbose" flag, to instead being a log-level one. That way your global
> define is:
> 
> 	log_level = logging.INFO
> 
> and set_verbose() becomes:
> 
> 	global log_level
> 	log_level = logging.DEBUG
> 
> thereby removing the branch from you logging init fn.
> 
> NOTE: I have not yet had the chance to review the rest of the series, so if
> verbose is used elsewhere, please ignore this comment.
> 

It isn't. It's used solely to enable more logging, so I'll move the code around to achieve what you outlined.

> > --
> > 2.30.2
> >