4
\$\begingroup\$

I am working on a project, neurodecode, which uses a logger based on the logging library. As I am not very familiar with logging, I don't know how to further improve this aspect of the project.

The project is constructed as:

neurodecode
|_ __init__.py
|_ logger.py
|_ folder1
    |_ script1.py
    |_ script2.py
...

The logger.py contains: (I removed the docstring to compact the code).

import sys
import logging

LOG_LEVELS = {
    'DEBUG': logging.DEBUG,
    'INFO': logging.INFO,
    'WARNING': logging.WARNING,
    'ERROR': logging.ERROR
}


def init_logger(logger, verbosity='INFO'):
    if not logger.hasHandlers():
        logger.setLevel(verbosity)
        add_logger_handler(logger, sys.stdout, verbosity=verbosity)


def add_logger_handler(logger, stream, verbosity='INFO'):
    c_handler = logging.StreamHandler(stream)
    c_handler.setFormatter(neurodecodeFormatter())
    logger.addHandler(c_handler)

    set_log_level(logger, verbosity, -1)

    return logger


def set_log_level(logger, verbosity, handler_id=0):
    logger.handlers[handler_id].level = LOG_LEVELS[verbosity]


class neurodecodeFormatter(logging.Formatter):
    # Format string syntax for the different Log levels
    fmt_debug = "[%(module)s:%(funcName)s:%(lineno)d] DEBUG: %(message)s (%(asctime)s)"
    fmt_info = "[%(module)s.%(funcName)s] %(message)s"
    fmt_warning = "[%(module)s.%(funcName)s] WARNING: %(message)s"
    fmt_error = "[%(module)s:%(funcName)s:%(lineno)d] ERROR: %(message)s"

    def __init__(self, fmt='%(levelno)s: %(message)s'):
        super().__init__(fmt)

    def format(self, record):
        if record.levelno == LOG_LEVELS['DEBUG']:
            self._fmt = self.fmt_debug
        elif record.levelno == LOG_LEVELS['INFO']:
            self._fmt = self.fmt_info
        elif record.levelno == LOG_LEVELS['WARNING']:
            self._fmt = self.fmt_warning
        elif record.levelno >= LOG_LEVELS['ERROR']:
            self._fmt = self.fmt_error

        self._style = logging.PercentStyle(self._fmt)

        return logging.Formatter.format(self, record)

And the __init__.py contains:

import logging

from .logger import init_logger

# set loggers
logging.getLogger('matplotlib').setLevel(logging.ERROR)
logger = logging.getLogger('neurodecode')
logger.propagate = False
init_logger(logger, verbosity='INFO')

First, do you see any improvements which could be made to those 2 parts? Maybe I could add from .logger import set_log_level to the __init__.py to be able to set the log level as neurodecode.set_log_level().

Second, in the different subfolders and scripts, I am using the logger as:

from pathlib import Path
from .. import logger # relative import vary depending on the script

class Foo:
    def __init__(self, param1, param2):
        self.param1 = str(param1)
        logger.info(f'Param1 set as {self.param1}')
        param2 = Foo._check_param2(param2)

    def method_to_do_stuff(self, n):
        try:
            # do stuff
            x = 2/n
        except Exception as error:
            logger.error('Something didn't work..')
            raise error

    @staticmethod
    def _check_param2(param2):
        # let's imagine it's a path -> pathlib
        param2 = Path(param2)
        if not param2.exists():
            logger.error('The path to param2 was not found')
            raise IOError

In this dummy example above, which sums up well most of my use case of the logger, I feel like I am not using it correctly. Shouldn't the logger catch the exception and the message attached directly, e.g. with raise IOError('The path to param2 was not found')?

\$\endgroup\$
1

1 Answer 1

4
+50
\$\begingroup\$

Part of your interface accepts strings as levels, and you have a string-level mapping. Why? There are standard symbols available from the logging library for anyone to use. There is no advantage to passing around stringly-typed levels, and in fact the standard levels being integral is a feature. It's entirely possible for a user to want to pass in a level integer that does not have an entry in your map and it should still behave well. So I would suggest dropping your LOG_LEVELS entirely, accepting verbosity: int (for which you should have a type hint), and replacing this:

    if record.levelno == LOG_LEVELS['DEBUG']:
        self._fmt = self.fmt_debug
    elif record.levelno == LOG_LEVELS['INFO']:
        self._fmt = self.fmt_info
    elif record.levelno == LOG_LEVELS['WARNING']:
        self._fmt = self.fmt_warning
    elif record.levelno >= LOG_LEVELS['ERROR']:
        self._fmt = self.fmt_error

with something that respects ranges instead, i.e.

if record.levelno <= logging.DEBUG:
    self._fmt = self.fmt_debug
elif record.levelno <= logging.INFO:
    self._fmt = self.fmt_info
elif record.levelno <= logging.WARNING:
    self._fmt = self.fmt_warning
else:
    self._fmt = self.fmt_error

That said, there are other problems with the above:

  • neurodecodeFormatter should be NeurodecodeFormatter by PEP8
  • Rather than baking in DEBUG: etc. in your format string, just use %(levelname)
  • logging.Formatter.format(self, record) should use super()
  • I question setting self._fmt and relying on it not to change while the super's implementation of format() uses it. I realize that's how the accepted answer on SO does it, but don't trust everything you read on SO. This introduces a concurrency vulnerability where two threaded calls to the same formatter will have unpredictable results - which _fmt assignment will win? You could either add a lock and keep doing what you're doing, which is not awesome; or you could keep surrogate formatter instances - one for every level - and call into them while avoiding mutating your own instance or theirs. I would recommend the latter.

I recommend changing

    try:
        # do stuff
        x = 2/n
    except Exception as error:
        logger.error('Something didn't work..')
        raise error

to

    try:
        # do stuff
        x = 2/n
    except Exception:
        logger.error("Something didn't work..", exc_info=True)
        raise

There's no need to keep a reference to the exception at all; and you should be including the stack trace. Also your quote syntax was wrong.

Shouldn't the logger catch the exception

Absolutely not. Loggers are not for exception catching; they're for exception logging.

\$\endgroup\$

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.