Can't get this custom logging adapter example to work

Question

I have been looking at examples related to context logging here: Logging Cookbook

However, I cannot get the following example to work. The example should be demonstrating the use of custom adapters and goes on as the following:

# Here is a simple example:

class CustomAdapter(logging.LoggerAdapter):
"""
This example adapter expects the passed in dict-like object to have a
'connid' key, whose value in brackets is prepended to the log message.
"""
def process(self, msg, kwargs):
    return '[%s] %s' % (self.extra['connid'], msg), kwargs

# which you can use like this:

logger = logging.getLogger(__name__)
adapter = CustomAdapter(logger, {'connid': some_conn_id})

# Then any events that you log to the adapter will have the value of some_conn_id prepended to the log messages.

However, no matter what I have tried, I always get a key error:

logger = logging.getLogger(__name__)

syslog = logging.StreamHandler()
formatter = logging.Formatter('%(asctime)s <<<CONTEXT: %(my_context)s>>> : %(message)s')
syslog.setFormatter(formatter)

adapter = CustomAdapter(logger, {'my_context': '1956'})

logger.setLevel(logging.INFO)
logger.addHandler(syslog)

logger.info('The sky is so blue', {'my_context': '6642'})


Traceback (most recent call last):
File "/Users/me/apps/Darwin64/python2.7/lib/python2.7/logging/__init__.py", line 859, in emit
msg = self.format(record)
File "/Users/me/apps/Darwin64/python2.7/lib/python2.7/logging/__init__.py", line 732, in format
return fmt.format(record)
File "/Users/me/apps/Darwin64/python2.7/lib/python2.7/logging/__init__.py", line 474, in format
s = self._fmt % record.__dict__
KeyError: 'my_context'
Logged from file myApp.py, line 62

What is it that I am doing wrong?

--- Solution: EDIT_01 ---

I have changed the code so that it uses adapter.info('The sky is so blue', {'my_context': '6642'}). And it worked. However, I had to remove the my_context from the formatter. However, with the code below, the my_context bit is hardcoded and no matter what I pass in through the logger, it would always display the initial value. Is there a way to pass in some values to the adapter?

logger = logging.getLogger(__name__)
syslog = logging.StreamHandler()
formatter = logging.Formatter('%(asctime)s %(message)s')
syslog.setFormatter(formatter)
logger.addHandler(syslog)
adapter = CustomAdapter(logger, {'my_context': '1956'})
logger.setLevel(logging.INFO)
adapter.info('The sky is so blue', {'my_context': '6642'})

This would always generate:

2016-09-13 11:33:18,404 [1956] The sky is so blue

even we are passing 6642 through the logger.

Answer 1

You have to use the adapter for logging, not the logger. Try this:

import logging

class CustomAdapter(logging.LoggerAdapter):
    def process(self, msg, kwargs):
        # use my_context from kwargs or the default given on instantiation
        my_context = kwargs.pop('my_context', self.extra['my_context'])
        return '[%s] %s' % (my_context, msg), kwargs

logger = logging.getLogger(__name__)
syslog = logging.StreamHandler()
formatter = logging.Formatter('%(asctime)s %(message)s')
syslog.setFormatter(formatter)
logger.addHandler(syslog)
adapter = CustomAdapter(logger, {'my_context': '1956'})
logger.setLevel(logging.INFO)

adapter.info('The sky is so blue', my_context='6642')
adapter.info('The sky is so blue')

Output:

2016-09-13 14:49:28,539 [6642] The sky is so blue
2016-09-13 14:49:28,540 [1956] The sky is so blue