Logging variable data with new format string

EDIT: take a look at the StyleAdapter approach in @Dunes' answer unlike this answer; it allows to use alternative formatting styles without the boilerplate while calling logger's methods (debug(), info(), error(), etc).


From the docs — Use of alternative formatting styles:

Logging calls (logger.debug(), logger.info() etc.) only take positional parameters for the actual logging message itself, with keyword parameters used only for determining options for how to handle the actual logging call (e.g. the exc_info keyword parameter to indicate that traceback information should be logged, or the extra keyword parameter to indicate additional contextual information to be added to the log). So you cannot directly make logging calls using str.format() or string.Template syntax, because internally the logging package uses %-formatting to merge the format string and the variable arguments. There would no changing this while preserving backward compatibility, since all logging calls which are out there in existing code will be using %-format strings.

And:

There is, however, a way that you can use {}- and $- formatting to construct your individual log messages. Recall that for a message you can use an arbitrary object as a message format string, and that the logging package will call str() on that object to get the actual format string.

Copy-paste this to wherever module:

class BraceMessage(object):
    def __init__(self, fmt, *args, **kwargs):
        self.fmt = fmt
        self.args = args
        self.kwargs = kwargs

    def __str__(self):
        return self.fmt.format(*self.args, **self.kwargs)

Then:

from wherever import BraceMessage as __

log.debug(__('Message with {0} {name}', 2, name='placeholders'))

Note: actual formatting is delayed until it is necessary e.g., if DEBUG messages are not logged then the formatting is not performed at all.


Here is another option that does not have the keyword problems mentioned in Dunes' answer. It can only handle positional ({0}) arguments and not keyword ({foo}) arguments. It also does not require two calls to format (using the underscore). It does have the ick-factor of subclassing str:

class BraceString(str):
    def __mod__(self, other):
        return self.format(*other)
    def __str__(self):
        return self


class StyleAdapter(logging.LoggerAdapter):

    def __init__(self, logger, extra=None):
        super(StyleAdapter, self).__init__(logger, extra)

    def process(self, msg, kwargs):
        if kwargs.pop('style', "%") == "{":  # optional
            msg = BraceString(msg)
        return msg, kwargs

You use it like this:

logger = StyleAdapter(logging.getLogger(__name__))
logger.info("knights:{0}", "ni", style="{")
logger.info("knights:{}", "shrubbery", style="{")

Of course, you can remove the check noted with # optional to force all messages through the adapter to use new-style formatting.


Note for anyone reading this answer years later: Starting with Python 3.2, you can use the style parameter with Formatter objects:

Logging (as of 3.2) provides improved support for these two additional formatting styles. The Formatter class been enhanced to take an additional, optional keyword parameter named style. This defaults to '%', but other possible values are '{' and '$', which correspond to the other two formatting styles. Backwards compatibility is maintained by default (as you would expect), but by explicitly specifying a style parameter, you get the ability to specify format strings which work with str.format() or string.Template.

The docs provide the example logging.Formatter('{asctime} {name} {levelname:8s} {message}', style='{')

Note that in this case you still can't call the logger with the new format. I.e., the following still won't work:

logger.info("knights:{say}", say="ni")  # Doesn't work!
logger.info("knights:{0}", "ni")  # Doesn't work either

This was my solution to the problem when I found logging only uses printf style formatting. It allows logging calls to remain the same -- no special syntax such as log.info(__("val is {}", "x")). The change required to code is to wrap the logger in a StyleAdapter.

from inspect import getargspec

class BraceMessage(object):
    def __init__(self, fmt, args, kwargs):
        self.fmt = fmt
        self.args = args
        self.kwargs = kwargs

    def __str__(self):
        return str(self.fmt).format(*self.args, **self.kwargs)

class StyleAdapter(logging.LoggerAdapter):
    def __init__(self, logger):
        self.logger = logger

    def log(self, level, msg, *args, **kwargs):
        if self.isEnabledFor(level):
            msg, log_kwargs = self.process(msg, kwargs)
            self.logger._log(level, BraceMessage(msg, args, kwargs), (), 
                    **log_kwargs)

    def process(self, msg, kwargs):
        return msg, {key: kwargs[key] 
                for key in getargspec(self.logger._log).args[1:] if key in kwargs}

Usage is:

log = StyleAdapter(logging.getLogger(__name__))
log.info("a log message using {type} substitution", type="brace")

It's worth noting that this implementation has problems if key words used for brace substitution include level, msg, args, exc_info, extra or stack_info. These are argument names used by the log method of Logger. If you need to one of these names then modify process to exclude these names or just remove log_kwargs from the _log call. On a further note, this implementation also silently ignores misspelled keywords meant for the Logger (eg. ectra).


The easier solution would be to use the excellent logbook module

import logbook
import sys

logbook.StreamHandler(sys.stdout).push_application()
logbook.debug('Format this message {k}', k=1)

Or the more complete:

>>> import logbook
>>> import sys
>>> logbook.StreamHandler(sys.stdout).push_application()
>>> log = logbook.Logger('MyLog')
>>> log.debug('Format this message {k}', k=1)
[2017-05-06 21:46:52.578329] DEBUG: MyLog: Format this message 1