Search code examples
pythoncherrypy

CherryPy add contextual information to logging


I'm using CherryPy 3.7.0 to build a small web app.

My problem is that I can't figure out how to add contextual information to its logging output.

Even though I've gone through its docs several times it's not clear how to achieve such thing. I am interested in adding a task attribute in the logger so that in one of my views I should be able to write:

logger.info('Processing finished', extra={'task': 'jashgd-765273-ehdfiuh'})

How should I do that?

Thanks in advance


Solution

  • Reading docs

    Here is what docs of logging.debug say about extra keyword argument:

    The third optional keyword argument is extra which can be used to pass a dictionary which is used to populate the __dict__ of the LogRecord created for the logging event with user-defined attributes. These custom attributes can then be used as you like. For example, they could be incorporated into logged messages. For example:

    FORMAT = '%(asctime)-15s %(clientip)s %(user)-8s %(message)s'
    logging.basicConfig(format=FORMAT)
    d = {'clientip': '192.168.0.1', 'user': 'fbloggs'}
    logging.warning('Protocol problem: %s', 'connection reset', extra=d)
    

    I.e. extra is not logged auto-magically -- you need to provide appropriate formatter.

    And here's CherryPy's routine, cherrypy._cplogging.LogManager.error , which effectively passes data to stdlib's logger:

    def error(self, msg='', context='', severity=logging.INFO, traceback=False):
        """...
        This is not just for errors! Applications may call this at any time
        to log application-specific information.
        ...
        """
        if traceback:
            msg += _cperror.format_exc()
        self.error_log.log(severity, ' '.join((self.time(), context, msg)))
    

    Also take a look at the docstring of cherrypy._cplogging. It explains the expected extension of CherryPy's logging.

    Writing code

    From the section above we have consequences. Simple answer is that you can't do it directly. Also @AndrewKloos answer is not actually the answer, because you can't pass a dict in sequence to str.join. Also you can't even pass extra keyword argument, because there's no such formal argument in the signature. Even if you could, giving formatter extra placeholders would result in string interpolation errors in any CherryPy's normal logging (that obviously don't provide any extra keys).

    Thus the best compromise is just to do:

    cherrypy.log('Processing finished ' + str({'task': 'jashgd-765273-ehdfiuh'}))
    

    Other options:

    • Create own logger besides error and access logs,
    • Invoke cherrypy.log.error_log.info directly
    • Monkeypatch cherrypy.log with your subclass of cherrypy._GlobalLogManager

    Update

    Introspect Python logging with logging_tree is nice article (and package) which explains logging hierarchy and message passing on example of CherryPy application.