13
\$\begingroup\$

Due to several limitations of the standard library's logging module, I wrote my own.
Below are the most important parts. You can find the whole library here.
Any feedback is welcome.

#  fancylog - A library for human readable logging.
#
#  Copyright (C) 2017  HOMEINFO - Digitale Informationssysteme GmbH
#
#  This program is free software: you can redistribute it and/or modify
#  it under the terms of the GNU General Public License as published by
#  the Free Software Foundation, either version 3 of the License, or
#  (at your option) any later version.
#
#  This program is distributed in the hope that it will be useful,
#  but WITHOUT ANY WARRANTY; without even the implied warranty of
#  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
#  GNU General Public License for more details.
#
#  You should have received a copy of the GNU General Public License
#  along with this program. If not, see <http://www.gnu.org/licenses/>.
"""A library for beautiful, readble logging."""

from datetime import datetime
from enum import Enum
from sys import stdout, stderr
from threading import Thread
from time import sleep
from traceback import format_exc

from blessings import Terminal

__all__ = [
    'logging',
    'LogLevel',
    'LogEntry',
    'Logger',
    'TTYAnimation',
    'LoggingClass']


TERMINAL = Terminal()


def logging(name=None, level=None, parent=None, file=None):
    """Decorator to attach a logger to the respective class."""

    def wrap(obj):
        """Attaches the logger to the respective class."""
        logger_name = obj.__name__ if name is None else name
        obj.logger = Logger(logger_name, level=level, parent=parent, file=file)
        return obj

    return wrap


class LogLevel(Enum):
    """Logging levels."""

    DEBUG = (10, '🔧', TERMINAL.bold)
    SUCCESS = (20, '✓', TERMINAL.green)
    INFO = (30, 'ℹ', TERMINAL.blue)
    WARNING = (70, '⚠', TERMINAL.yellow)
    ERROR = (80, '✗', TERMINAL.red)
    CRITICAL = (90, '☢', lambda string: TERMINAL.bold(TERMINAL.red(string)))
    FAILURE = (100, '☠', lambda string: TERMINAL.bold(TERMINAL.magenta(
        string)))

    def __init__(self, ident, symbol, format_):
        """Sets the identifier, symbol and color."""
        self.ident = ident
        self.symbol = symbol
        self.format = format_

    def __int__(self):
        """Returns the identifier."""
        return self.ident

    def __str__(self):
        """Returns the colored symbol."""
        return self.format(self.symbol)

    def __eq__(self, other):
        try:
            return int(self) == int(other)
        except TypeError:
            return NotImplemented

    def __gt__(self, other):
        try:
            return int(self) > int(other)
        except TypeError:
            return NotImplemented

    def __ge__(self, other):
        return self > other or self == other

    def __lt__(self, other):
        try:
            return int(self) < int(other)
        except TypeError:
            return NotImplemented

    def __le__(self, other):
        return self < other or self == other

    def __hash__(self):
        return hash((self.__class__, self.ident))

    @property
    def erroneous(self):
        """A log level is considered erroneous if it's identifier > 50."""
        return self.ident > 50


class LogEntry(Exception):
    """A log entry."""

    def __init__(self, *messages, level=LogLevel.ERROR, sep=None, color=None):
        """Sets the log level and the respective message(s)."""
        super().__init__()
        self.messages = messages
        self.level = level
        self.sep = ' ' if sep is None else sep
        self.color = color
        self.timestamp = datetime.now()

    def __hash__(self):
        """Returns a unique hash."""
        return hash(self._hash_tuple)

    @property
    def _hash_tuple(self):
        """Returns the tuple from which to create a unique hash."""
        return (self.__class__, self.level, self.messages, self.timestamp)

    @property
    def message(self):
        """Returns the message elements joint by the selected separator."""
        return self.sep.join(str(message) for message in self.messages)

    @property
    def text(self):
        """Returns the formatted message text."""
        if self.color is not None:
            return self.color(self.message)

        return self.message


class Logger:
    """A logger that can be nested."""

    CHILD_SEP = '→'

    def __init__(self, name, level=None, parent=None, file=None):
        """Sets the logger's name, log level, parent logger,
        log entry template and file.
        """
        self.name = name
        self.level = level or LogLevel.INFO
        self.parent = parent
        self.file = file
        self.template = '{1.level} {0}: {1.text}'

    def __str__(self):
        """Returns the logger's nested path as a string."""
        return self.CHILD_SEP.join(logger.name for logger in self.path)

    def __hash__(self):
        """Returns a unique hash."""
        return hash(self.__class__, self.name)

    def __enter__(self):
        """Returns itself."""
        return self

    def __exit__(self, _, value, __):
        """Logs risen log entries."""
        if isinstance(value, LogEntry):
            self.log_entry(value)
            return True

        return None

    @property
    def root(self):
        """Determines whether the logger is at the root level."""
        return self.parent is None

    @property
    def path(self):
        """Yields the logger's path."""
        if not self.root:
            yield from self.parent.path

        yield self

    @property
    def layer(self):
        """Returns the layer of the logger."""
        return 0 if self.root else self.parent.layer + 1

    def log_entry(self, log_entry):
        """Logs a log entry."""
        if log_entry.level >= self.level:
            if self.file is None:
                file = stderr if log_entry.level.erroneous else stdout
            else:
                file = self.file

            print(self.template.format(self, log_entry), file=file, flush=True)

        return log_entry

    def inherit(self, name, level=None, file=None):
        """Returns a new child of this logger."""
        level = self.level if level is None else level
        file = self.file if file is None else file
        return self.__class__(name, level=level, parent=self, file=file)

    def log(self, level, *messages, sep=None, color=None):
        """Logs messages of a certain log level."""
        log_entry = LogEntry(*messages, level=level, sep=sep, color=color)
        return self.log_entry(log_entry)

    def debug(self, *messages, sep=None, color=None):
        """Logs debug messages, defaulting to a stack trace."""
        if not messages:
            messages = ('Stacktrace:', format_exc())

            if sep is None:
                sep = '\n'

        return self.log(LogLevel.DEBUG, *messages, sep=sep, color=color)

    def success(self, *messages, sep=None, color=None):
        """Logs success messages."""
        return self.log(LogLevel.SUCCESS, *messages, sep=sep, color=color)

    def info(self, *messages, sep=None, color=None):
        """Logs info messages."""
        return self.log(LogLevel.INFO, *messages, sep=sep, color=color)

    def warning(self, *messages, sep=None, color=None):
        """Logs warning messages."""
        return self.log(LogLevel.WARNING, *messages, sep=sep, color=color)

    def error(self, *messages, sep=None, color=None):
        """Logs error messages."""
        return self.log(LogLevel.ERROR, *messages, sep=sep, color=color)

    def critical(self, *messages, sep=None, color=None):
        """Logs critical messages."""
        return self.log(LogLevel.CRITICAL, *messages, sep=sep, color=color)

    def failure(self, *messages, sep=None, color=None):
        """Logs failure messages."""
        return self.log(LogLevel.FAILURE, *messages, sep=sep, color=color)

Use example:

#! /usr/bin/env python3
"""divide.

Usage:
    divide <dividend> <divisor> [options]

Options:
    --help, -h  Show this page.
"""    
from docopt import docopt
from fancylog import LogLevel, LogEntry, Logger


def divide(dividend, divisor):

    try:
        return dividend / divisor
    except ZeroDivisionError:
        raise LogEntry('Cannot divide by zero.', level=LogLevel.ERROR)


def main(options):

    with Logger('Division logger', level=LogLevel.SUCCESS) as logger:
        try:
            dividend = float(options['<dividend>'])
        except ValueError:
            logger.error('Divident is not a float.')
            return

        try:
            divisor = float(options['<divisor>'])
        except ValueError:
            logger.error('Divisor is not a float.')
            return

        logger.success(divide(dividend, divisor))


if __name__ == '__main__':
    main(docopt(__doc__))
\$\endgroup\$
  • 1
    \$\begingroup\$ "Due to several limitations of the standard library's logging module" Which ones in particular are you trying to fix? \$\endgroup\$ – Mast Feb 16 '18 at 12:57
  • 2
    \$\begingroup\$ @Mast Comprehensive API, PEP8 compliant code, context management capability, easy formatting configuration, object-orientation... \$\endgroup\$ – Richard Neumann Feb 16 '18 at 13:10
  • \$\begingroup\$ Why self.level = level or LogLevel.INFO when every other check of the sort is of the form self.level = LogLevel.INFO if level is None else level? \$\endgroup\$ – Mathias Ettinger Feb 16 '18 at 14:04
  • 1
    \$\begingroup\$ Why not use total_ordering? \$\endgroup\$ – Dannnno Feb 16 '18 at 14:40
  • 1
    \$\begingroup\$ @Dannnno Good point. I also already refactored the several logging methods using functools.partialmethod in upstream. \$\endgroup\$ – Richard Neumann Feb 16 '18 at 14:59
4
\$\begingroup\$

The code reads good, I only have a few nitpicks:

  • Use default values where applicable instead of None: it will ease usage of the API as they can be introspected;

    class LogEntry(Exception):
        """A log entry."""
    
        def __init__(self, *messages, level=LogLevel.ERROR, sep=' ', color=None):
    
    class Logger:
        """A logger that can be nested."""
    
        CHILD_SEP = '→'
    
        def __init__(self, name, level=LogLevel.INFO, parent=None, file=None):
    
  • Change value of a parameter instead of reasigning it through a ternary: this make it more explicit about what you’re trying to do;

    def inherit(self, name, level=None, file=None):
        """Returns a new child of this logger."""
        if level is None:
            level = self.level
        if file is None:
            file = self.file
        return self.__class__(name, level=level, parent=self, file=file)
    
  • Avoid return None, especially as last intruction: it’s just noise.

Now, this is neat code and all, but it feels… rather limited. The two main concerns I have about this module is that:

  1. it only logs to files (or similar);
  2. it gives veeery few control over the formatting of the log message.

I sometimes need to send logs to the system syslog daemon and I can do it using a handler provided by the Python's logging module, but if I want to do that using yours, I would have to wrap syslog and your module myself… Same goes for sending logs over TCP (to a listening logstash for instance).

Same goes for the formatting of the message. As far as I hate % formatting imposed by the logging module, it is at least possible to writte a Formatter that is format aware and pass large objects to the logger which will use the format string to traverse it and retrieve values that I need to log only if it actually logs something. Using your approach, I can either write a non-flexible __str__ method on each object I want to log so I can have desired information (which is not always possible nor wanted, if I want to log several different things in several different places) or split the format string (bad for readability) and traverse the object to retrieve attributes myself which is a bit of overhead (some may be expensive properties, even) if the log ends up discarded.

Other missing things includes the ability to configure a logger hierarchy though a file and to retrieve/create any logger by name in any module.

I also don't really understand the use of the contextmanager, especially the LogEntry exception. As far as I find it interesting to create a specific logger for a specific portion of the code, why would I want to use the LogEntry "exception":

  1. it swallows the actual error, making the calling code unaware of any problem: if your example code were to use the value returned from divide, it would have a hard time doing so as None would be returned;
  2. it changes the type of the exception making any attempt to catch real errors moot. Why not keep it to the simple

    except XXX:
        logger.xxx(…)
        return
    

    that you use in your main? (or even better: except XXX: logger.xxx(…); raise)

    Can't you instead provide a utility function like current_logger that uses this context manager to return the appropriate one (or create a root logger if none is in use)? Or something akin to decimal.localcontext where you provide module-level logging functions (debug, success, info…) that applies to the current logger and other utilities to select which logger is the current one.

\$\endgroup\$

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

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