Python logging with context

Python official documentation (logging cookbook) suggests two approaches to add contextual information to logs:

1. Using LoggerAdapters - for more details you can refer to pete lin`s answer.
2. Using Filters (and threadlocal variables) - A filter processes the record before it is being emitted. It's main purpose is to allow advanced and customized rules to reject log records (the filter method returns bool, which indices whether to emit the record). However, it also allows you to process the record - and add attributes based on whatever is required. For example, you can set the attributes based on a global threading.local variable.

Below is a Filter example that appends attributes from a global threading.local variable:

log_utils.py

import logging
import threading

log_context_data = threading.local()


class ThreadingLocalContextFilter(logging.Filter):
    """
    This is a filter which injects contextual information from `threading.local` (log_context_data) into the log.
    """
    def __init__(self, attributes: List[str]):
        super().__init__()
        self.attributes = attributes

    def filter(self, record):
        for a in self.attributes:
            setattr(record, a, getattr(log_context_data, a, 'default_value'))
        return True

log_context_data can be set when you start processing an account, and reset when you you're done. However, I recommend setting it using a context manager:

Also in log_utils.py:

class SessionContext(object):
    def __init__(self, logger, context: dict = None):
        self.logger = logger
        self.context: dict = context

    def __enter__(self):
        for key, val in self.context.items():
            setattr(log_context_data, key, val)
        return self

    def __exit__(self, et, ev, tb):
        for key in self.context.keys():
            delattr(log_context_data, key)

And a usage example, my_script.py:

root_logger = logging.getLogger()
handler = ...
handler.setFormatter(
    logging.Formatter('{name}: {levelname} {account} - {message}', style='{'))
handler.addFilter(ThreadingLocalContextFilter(['account']))
root_logger.addHandler(handler)
...
...
using SessionContext(logger=root_logger, context={'account': account}):
    ...
    ...
     

Notes:

1. Filter is only applied to the logger it is attached to. So if we attach it to a logging.getLogger('foo'), it won't affect logging.getLogger('foo.bar'). The solution is to attach the Filter to a Handler, rather than a logger.
2. ThreadingLocalContextFilter could've rejected records, if log_context_data doesn't contain the required attribute. This depends on what you need.

When to use what?

1. I'd recommend LoggerAdapters if you need to edit records for specific looger instances - in which case, it makes sense to instantiate an Adapter instead.
2. I'd recommend Filter if you want to edit all records that are handled by a specific Handler - including other modules and 3rd party packages. It is generally a cleaner approach in my opinion, since we only configure our logger in our entry code - and the rest of the code remains the same (no need to replace logger instances with adapter instances).

You can define a function inside the account processing code, after you get the account name, like this:

# account_name should already be defined
log = lambda msg: logger.info(msg, extra={'account': account_name})

###

log('Processing account...')

Note the extra keyword argument. It is used to add additional context to log records—in this case, the account name.

You can use context passed via extra in the formatter:

format = '%(asctime)s - %(name)s - %(levelname)s - %(message)s - %(account)s'

Note that if you set up formatter like this and forget to pass account, you'll get a string formatting exception.

• More information on extra keyword argument

Tony's answer just provide a function, but use LoggerAdapter we can get a context logger.

class ILoggerAdapter(LoggerAdapter):
    def __init__(self, logger, extra):
        super(ILoggerAdapter, self).__init__(logger, extra)
        self.env = extra

    def process(self, msg, kwargs):
        msg, kwargs = super(ILoggerAdapter, self).process(msg, kwargs)

        result = copy.deepcopy(kwargs)

        default_kwargs_key = ['exc_info', 'stack_info', 'extra']
        custome_key = [k for k in result.keys() if k not in default_kwargs_key]
        result['extra'].update({k: result.pop(k) for k in custome_key})

        return msg, result

then just wrap your logger as

new_logger = ILoggerAdapter(old_logger, extra={'name': 'name'})

# new_logger is just same as old_logger    
# but can be pass to record
new_logger.info(msg='haha', id=100)

def emit(self, record):
    print(record.name)
    print(record.id)