How do I add custom field to Python log format str

Question

My current format string is:

formatter = logging.Formatter('%(asctime)s : %(message)s')

and I want to add a new field called app_name and which will have a different value in each script that contains this formatter.

import logging
formatter = logging.Formatter('%(asctime)s %(app_name)s : %(message)s')
syslog.setFormatter(formatter)
logger.addHandler(syslog)

But I'm not sure how to pass that app_name value to the logger to interpolate into the format string. I can obviously get it to appear in the log message but passing it each time but this is messy.

I've tried:

logging.info('Log message', app_name='myapp')
logging.info('Log message', {'app_name', 'myapp'})
logging.info('Log message', 'myapp')

but none work.

Answer 1

You need to pass the dict as a parameter to extra to do it that way.

logging.info('Log message', extra={'app_name': 'myapp'})

Proof:

>>> import logging
>>> logging.basicConfig(format="%(foo)s - %(message)s")
>>> logging.warning('test', extra={'foo': 'bar'})
bar - test 

Also, as a note, if you try to log a message without passing the dict, then it will fail.

>>> logging.warning('test')
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 846, in emit
    msg = self.format(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 723, in format
    return fmt.format(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 467, in format
    s = self._fmt % record.__dict__
KeyError: 'foo'
Logged from file <stdin>, line 1

Answer 2

Another way is to create a custom LoggerAdapter. This is particularly useful when you can't change the format OR if your format is shared with code that does not send the unique key (in your case app_name):

class LoggerAdapter(logging.LoggerAdapter):
    def __init__(self, logger, prefix):
        super(LoggerAdapter, self).__init__(logger, {})
        self.prefix = prefix

    def process(self, msg, kwargs):
        return '[%s] %s' % (self.prefix, msg), kwargs

And in your code, you would create and initialize your logger as usual:

    logger = logging.getLogger(__name__)
    # Add any custom handlers, formatters for this logger
    myHandler = logging.StreamHandler()
    myFormatter = logging.Formatter('%(asctime)s %(message)s')
    myHandler.setFormatter(myFormatter)
    logger.addHandler(myHandler)
    logger.setLevel(logging.INFO)

Finally, you would create the wrapper adapter to add a prefix as needed:

    logger = LoggerAdapter(logger, 'myapp')
    logger.info('The world bores you when you are cool.')

The output will look something like this:

2013-07-09 17:39:33,596 [myapp] The world bores you when you are cool.

Answer 3

You could use a LoggerAdapter so you don't have to pass the extra info with every logging call:

import logging
extra = {'app_name':'Super App'}

logger = logging.getLogger(__name__)
syslog = logging.StreamHandler()
formatter = logging.Formatter('%(asctime)s %(app_name)s : %(message)s')
syslog.setFormatter(formatter)
logger.setLevel(logging.INFO)
logger.addHandler(syslog)

logger = logging.LoggerAdapter(logger, extra)
logger.info('The sky is so blue')

logs (something like)

2013-07-09 17:39:33,596 Super App : The sky is so blue

---

Filters can also be used to add contextual information.

import logging

class AppFilter(logging.Filter):
    def filter(self, record):
        record.app_name = 'Super App'
        return True

logger = logging.getLogger(__name__)
logger.addFilter(AppFilter())
syslog = logging.StreamHandler()
formatter = logging.Formatter('%(asctime)s %(app_name)s : %(message)s')
syslog.setFormatter(formatter)
logger.setLevel(logging.INFO)
logger.addHandler(syslog)

logger.info('The sky is so blue')

produces a similar log record.