Python cross-module logging

Question

I've googled and looked at the default documentation, but I can't figure out why this doesn't produce three lines of logging:

# main.py
import logging
import apple
import banana

log = logging.getLogger('main')
log.setLevel(logging.DEBUG)

ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)

formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
ch.setFormatter(formatter)

log.addHandler(ch)

log.info("I'm in main!")

# apple.py
import logging

log = logging.getLogger('main.apple')
log.info("I'm here in apple!")

# banana.py
import logging

log = logging.getLogger('main.banana')
log.info("I'm here in banana!")

# output
2011-09-03 16:40:54,062 - main - INFO - I'm in main!

But the example in the logging documentation works fine.

Any ideas?

Answer 1

The handler (StreamHandler) was not setup until after the imports. So the logging commands in the imported modules do not produce any output. Some handlers print to files, others communicate over a network, and some print to a console. There's no way the logging statements inside the imported modules could know what to do without the handler(s) being added to the logger.

If the logging statements in the modules reside inside a class or function, as they do in the example to which you linked, then output can be seen because by the time the module class or function is called, the handler has been added to the logger.