Python: custom logging across all modules

Question

Task

I have a collection of scripts and I'd like them to produce unified logging messages with minimum alterations to modules doing logging the actual messages.

I've written a small module 'custom_logger' which I plan to call from the main application once, have it return a logger, which I'd then continue using.

The submodules I'd be importing into the app should only (or rather I wish them to)

• should only "import logging as log" - so that nothing specific to my site is required to make them just run if someone else finds them useful.
• should just log messages with log.info/error('message') without adding anything site-specific to them
• should use the already configured 'root' logger with all its formatting and handers and not affect the root logger's configuration

*custom_logger.py*

import logging import logging.handlers import os import sys   def getLogger(name='root', loglevel='INFO'):   logger = logging.getLogger(name)    # if logger 'name' already exists, return it to avoid logging duplicate   # messages by attaching multiple handlers of the same type   if logger.handlers:     return logger   # if logger 'name' does not already exist, create it and attach handlers   else:     # set logLevel to loglevel or to INFO if requested level is incorrect     loglevel = getattr(logging, loglevel.upper(), logging.INFO)     logger.setLevel(loglevel)     fmt = '%(asctime)s %(filename)-18s %(levelname)-8s: %(message)s'     fmt_date = '%Y-%m-%dT%T%Z'     formatter = logging.Formatter(fmt, fmt_date)     handler = logging.StreamHandler()     handler.setFormatter(formatter)     logger.addHandler(handler)      if logger.name == 'root':       logger.warning('Running: %s %s',                      os.path.basename(sys.argv[0]),                      ' '.join(sys.argv[1:]))     return logger 

Then comes the submodule which has a few test messages with examples of what works and what doesn't.

submodule.py

import sys import custom_logger import logging   class SubClass(object):    def __init__(self):     # NOK (no idea why since by default (no name parameter), it should return the root logger)     #log = logging.getLogger()     #log.info('message from SubClass / __init__')      # OK (works as expected)     #log = logging.getLogger('root')     #log.info('message from SubClass / __init__')      # OK (works as expected)     log = custom_logger.getLogger('root')     log.info('message from SubClass / __init__')     def SomeMethod(self):     # OK but I'd have to define `log` for every method, which is unacceptable     # Please see question below all code snippets     log = custom_logger.getLogger('root')     log.info('message from SubClass / SomeMethod') 

And the main app: app.py Nothing special here:

#!/usr/bin/python  import custom_logger import submodule  log = custom_logger.getLogger('root', loglevel='DEBUG')  log.debug('debug message') log.info('info message') log.warning('warning message') log.error('error message')  a = submodule.SubClass() # this should produce a log message a.SomeMethod()           # so should this 

Output that I'm after and that I'm getting, just in an exteremely ugly way:

% ./app.py  2013-04-08T03:07:46BST custom_logger.py   WARNING : Running: app.py  2013-04-08T03:07:46BST app.py             DEBUG   : debug message 2013-04-08T03:07:46BST app.py             INFO    : info message 2013-04-08T03:07:46BST app.py             WARNING : warning message 2013-04-08T03:07:46BST app.py             ERROR   : error message 2013-04-08T03:07:46BST submodule.py       INFO    : message from SubClass / __init__ 2013-04-08T03:07:46BST submodule.py       INFO    : message from SubClass / SomeMethod 

I want to be able to define a logger in the app.py and then in the submodules only use the standard Python logging library to make use of an already configured logger in the app.py.

Also, an ugly workaround: if I place the below code after the imports in submodule.py:

log = custom_logger.getLogger('root') 

it will be executed before my logger is configured in app.py, effectively making the submodule, not my app configure logging.

Another workaround I considered: within the constuctor of the SubClass class, I could define

self.log = custom_logger.getLogger('root')

and then use self.log.error('some error'). There must be a nicer way - if you can suggest something useful or point out where I misunderstood the documentation, I'd be very grateful!

PS. I've spent quite a bit reading the Python logging howto (basic and advanced) and the cookbook so if I've missed something useful there, please point it out.

Thank you!

Answer 1

If you want to change root logger you could just use getLogger() everywhere, with no arguments.

Regarding the instance setup only in the main module, you can instantiate your logger, add your own Handler, and use it in all the other submodules (as I did bellow).

I created a class that inherits the StreamHandler in custom_logger.py:

class MyHandler(logging.StreamHandler):      def __init__(self):         logging.StreamHandler.__init__(self)         fmt = '%(asctime)s %(filename)-18s %(levelname)-8s: %(message)s'         fmt_date = '%Y-%m-%dT%T%Z'         formatter = logging.Formatter(fmt, fmt_date)         self.setFormatter(formatter) 

Then, in submodule.py, I put the getLogger after the imports and commented it in the methods:

import sys import logging  log = logging.getLogger('root')  class SubClass(object):      def __init__(self):          log.info('message from SubClass / __init__')      def SomeMethod(self):         log.info('message from SubClass / SomeMethod') 

Then, in app.py I created a Logger instance (that will be the same in all modules) and added my handler, which formats the output:

#!/usr/bin/python  import logging import custom_logger import submodule  log = logging.getLogger('root') log.setLevel('DEBUG') log.addHandler(custom_logger.MyHandler())  log.debug('debug message')  log.info('info message') log.warning('warning message') log.error('error message')  a = submodule.SubClass() # this should produce a log message a.SomeMethod()           # so should this 

Output:

./app.py  2013-04-08T15:20:05EEST app.py             DEBUG   : debug message 2013-04-08T15:20:05EEST app.py             INFO    : info message 2013-04-08T15:20:05EEST app.py             WARNING : warning message 2013-04-08T15:20:05EEST app.py             ERROR   : error message 2013-04-08T15:20:05EEST submodule.py       INFO    : message from SubClass / __init__ 2013-04-08T15:20:05EEST submodule.py       INFO    : message from SubClass / SomeMethod