title: Python: custom logging across all modules
body: <p><strong>Task</strong></p>
  
  <p>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.</p>
  
  <p>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.</p>
  
  <p>The submodules I'd be importing into the app should only (or rather I wish them to)</p>
  
  <ul>
  <li>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.</li>
  <li>should just log messages with log.info/error('message') without adding anything site-specific to them</li>
  <li>should use the already configured 'root' logger with all its formatting and handers and not affect the root logger's configuration</li>
  </ul>
  
  <p>*custom_logger.py*</p>
  
  <pre><code>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
  </code></pre>
  
  <p>Then comes the submodule which has a few test messages with examples of what works and what doesn't.</p>
  
  <p><em>submodule.py</em></p>
  
  <pre><code>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')
  </code></pre>
  
  <p>And the main app: <em>app.py</em> Nothing special here:</p>
  
  <pre><code>#!/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
  </code></pre>
  
  <p>Output that I'm after and that I'm getting, just in an exteremely ugly way:</p>
  
  <pre><code>% ./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
  </code></pre>
  
  <p>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.</p>
  
  <p>Also, an ugly workaround: if I place the below code after the imports in submodule.py:</p>
  
  <pre><code>log = custom_logger.getLogger('root')
  </code></pre>
  
  <p>it will be executed before my logger is configured in app.py, effectively making the submodule, not my app configure logging.</p>
  
  <p>Another workaround I considered: within the constuctor of the SubClass class, I could define </p>
  
  <p><code>self.log = custom_logger.getLogger('root')</code></p>
  
  <p>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!</p>
  
  <p>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.</p>
  
  <p>Thank you!</p>