0

Python has multiple string formatting styles for arguments:

  • Old-style/percent/%: "The first number is %s" % (1,)

  • New-style/bracket/{: "The first number is {}".format(1)

  • F-string: one = 1; f"the first number is {one}"

I can format log messages manually at the message creation time: log.error("the first number is {}".format(1)). However this can lead to performance problems and cause bugs when formatting complex objects.

How do I configure logging to use the style I want in individual logs (e.g. logging.error)?

jonrsharpe
  • 115,751
  • 26
  • 228
  • 437
loopbackbee
  • 21,962
  • 10
  • 62
  • 97
  • The reason for delaying formatting until the log record emits is not really a concern of performance. It's so that log aggregation clients have an opportunity to group together "same" log events logged with different parameters. For example, sentry might group together "The first number is 1" and "The first number is 456" as different occurrences of the same underlying thing. That can help a lot when you have an app logging millions of events. – wim Mar 12 '23 at 19:47
  • @wim Thanks, I hadn't heard of this issue before. Do you happen to have any reference / example? It seems there's actually many reasons to do things lazily, I'll include links in the answer (or feel free to edit directly) – loopbackbee Mar 12 '23 at 20:05

1 Answers1

1

This is not supported out-of-the-box, but can be done with a minimal amount of code.

Python 3.2 introduced a new API to make it possible to support your preferred style throughout your whole application without customizing individual Logger:

  • Format/bracket style

    import logging
    
    class BracketStyleRecord(logging.LogRecord):
        def getMessage(self):
            msg = str(self.msg) # see logging cookbook
            if self.args:
                try:
                    msg = msg % self.args # retro-compability for 3rd party code
                except TypeError as e:
                    if e.args and "not all arguments converted" in e.args[0]:
                        # "format" style
                        msg = msg.format(*self.args)
                    else:
                        raise # other Errors, like type mismatch
            return msg
    
    logging.setLogRecordFactory(BracketStyleRecord)
    logging.basicConfig()
    logging.error("The first number is %s", 1) # old-style
    logging.error("The first number is {}", 1) # new-style
    

    Caveats:

    • Keyword arguments are not supported. That is only possibly in a single Logger (see "Using a specific style in a single Logger" section below)
  • F-string style

    import logging
    import inspect
    
    class FStringStyleRecord(logging.LogRecord):
        def getMessage(self):
            msg = str(self.msg) # see logging cookbook
            if self.args:
                msg = msg % self.args # retro-compability for 3rd party code
            elif "{" in msg:
                # it might be a f-string
                try:
                    frame = inspect.currentframe().f_back
                    while "/logging/" in frame.f_code.co_filename:
                        frame = frame.f_back
                    variables = {}
                    variables.update(frame.f_locals)
                    variables.update(frame.f_globals)
                    msg = msg.format(**variables)
                except Exception:
                    pass # Give up, treat the string as a literal message
            return msg
    
    
    
    logging.setLogRecordFactory(FStringStyleRecord)
    logging.basicConfig()
    
    one = 1
    logging.error("The first number is %s", 1) # old-style
    logging.error("The first number is {one}") # f-string-style (note the lack of f"")
    

    Caveats:

    • Do NOT use this in production code. It can have many security, performance and memory implications (including remote code execution if you're not extremely careful)
    • This will not work as-is if your package contains a directory named logging

Sometimes it might be easier or better to only support a different style in individual Loggers. For that, you can use a LoggerAdapter, as recommended in the cookbook:

import logging

class Message:
    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)

class StyleAdapter(logging.LoggerAdapter):
    def __init__(self, logger, extra=None):
        super().__init__(logger, extra or {})

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

logger = StyleAdapter(logging.getLogger(__name__))
logging.basicConfig()
logger.error("The first number is {one}", one=1) 

This supports keyword arguments, unlike the version in the cookbook

For Pylint support can use logging-format-style=new in your pylintrc to support the new format.

Note: don't be misled by the style argument of the Formatter or of basicConfig. These arguments are only used to set the style of the logging format string, and are not applied to individual messages:

formatter = logging.Formatter(style='{', fmt="{levelname}:{name}:{message}")

Useful references:

jonrsharpe
  • 115,751
  • 26
  • 228
  • 437
loopbackbee
  • 21,962
  • 10
  • 62
  • 97
  • 1
    _"F-strings in logging are still not supported"_ - how could they be? The point is to pass a _template_ to be formatted if and when that text actually gets written out somewhere, whereas f-strings are evaluated on creation. – jonrsharpe Mar 12 '23 at 18:36
  • @wim I've edited my answer to support retro-compatibility / calls from other libraries. The cookbook actually mentions this, but I neglected to implement it at first – loopbackbee Mar 12 '23 at 20:06
  • Yep, looks better now (_you should be careful to support all formatting styles and allow %-formatting as the default, to ensure interoperability with other code_ <-- old answer was not doing that). I close my [earlier question](https://stackoverflow.com/q/42427337/674039) as dupe of this one. – wim Mar 12 '23 at 20:11
  • One problem with this approach, it may catch and mis-handle a `TypeError` for the wrong reasons (e.g. `logging.error("The first number is %d", "1")` will just happily log `ERROR:root:The first number is %d` and the context of the number is now lost. Without a custom `LogRecord` factory, the logging framework would have handled this error condition and provided the useful context about the logging error. – wim Mar 12 '23 at 22:55
  • @wim Thanks for catching the bug! I fixed the implementation to handle that case – loopbackbee Mar 13 '23 at 10:15
  • @jonrsharpe you're right, I meant something like f-strink-syntax that is evaluated at logging output time. I think technically you could support that by either passing `locals()` or using `inspect`, but that would likely lead to performance, memory and security problems – loopbackbee Mar 13 '23 at 10:23
  • @jonrsharpe I now added f-string-style support to the answer, along with a warning. There's probably more problems I didn't anticipate, feel free to expand the caveats section – loopbackbee Mar 13 '23 at 12:05