How to use logging.getLogger(__name__) in multiple modules

From the logging howto for Python 2.7 (my emphasis):

A good convention to use when naming loggers is to use a module-level logger, in each module which uses logging, named as follows:

logger = logging.getLogger(__name__)

This means that logger names track the package/module hierarchy, and it’s intuitively obvious where events are logged just from the logger name.

Sounds like good advice.

Now, the logging cookbook provides an example for multiple modules, which uses hard-coded logger names instead of the __name__ constant. In the "main module" from the example we find

logger = logging.getLogger('spam_application')

and in the "auxiliary module" we find

module_logger = logging.getLogger('spam_application.auxiliary')

I copied this example verbatim into a package folder with the following structure:

cookbook-example
|- __init__.py
|- main_module.py
|- auxiliary_module.py

This runs without issue, producing the expected logging output from both the main module and the auxiliary module, but here's the thing:

If I now replace the hard-coded logger names by the __name__ constant, as recommended by the logging howto, the cookbook example breaks down: I only get logging messages from the main module, but nothing from the auxiliary module.

I must be missing something obvious. Any ideas what I am doing wrong?

Note:

There are a lot of very similar questions and related answers, e.g.: 1, 2, 3, 4, 5, 6, and many more. However, none of those appear to address this specific question.

--Edit--

Here's a minimal example based on the cookbook example, with the explicit name strings replaced by __name__.

main_module.py

import logging
import auxiliary_module

# create and configure main logger
logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)
# create console handler with a higher log level
handler = logging.StreamHandler()
handler.setLevel(logging.DEBUG)
# create formatter and add it to the handler
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
handler.setFormatter(formatter)
# add the handler to the logger
logger.addHandler(handler)

logger.info('message from main module')
auxiliary_module.some_function()

auxiliary_module.py

import logging

# create logger
module_logger = logging.getLogger(__name__) 

def some_function():
    module_logger.info('message from auxiliary module')

As pointed out by @shmee in this answer, the logger hierarchy must be defined explicitly in the logger name, using dot-notation. That is, if the logger name in main_module.py is e.g. 'a', then the logger name in auxiliary_module.py must be 'a.b' (not just 'b'), in order for it to inherit the configuration of logger 'a'. This is also mentioned in the getLogger() documentation.

However, this should be taken care of automatically when using __name__, as noted in the logging how-to:

This means that logger names track the package/module hierarchy, and it’s intuitively obvious where events are logged just from the logger name.

The thing is, for this to work, you need to use __name__ in the correct way, and I did not do that.

The problem in my example is in the organization of the files in the cookbook-example package folder:

Both the main module and the auxiliary module are at the same level (i.e. in the same folder). So, as explained here, the __name__ for the main module will then be '__main__' (as it is the top-level script), and the __name__ for the auxiliary module will be 'auxiliary_module' (i.e. the filename), NOT '__main__.auxiliary_module'.

As a result, the logger in the auxiliary module will be a child of the root logger, not a child of the '__main__' logger, and it will thus inherit the root logger configuration (which still has the default logging level WARNING) instead of the configuration specified in the main module.

So, to make the example work, we have several options:

1. Replace getLogger(__name__) in the main module by getLogger(). This will apply the config to the root logger and therefore also to the auxiliary module logger, as suggested by @shmee.

2. Replace getLogger(__name__) in the auxiliary module by getLogger('__main__.' + __name__). The result will be equivalent to the original cookbook-example (except that the main logger is now called '__main__' instead of 'spam_application').

The naming of the loggers is what you are missing. In the example, a logger named spam_application is created in the main module. Then handlers and formatters are created and added to that logger.

In auxiliary_module loggers are created with names that start with spam_application resp. spam_application.auxiliary. This effectively creates a hierarchy of loggers that propagate to their respective parents unless explicitly disabled. This hierarchy is spam_appliclation <- spam_application.auxiliary <- spam_application.auxiliary.Auxiliary or logger <- module_logger <- self.logger in the case of the cookbook example.

If you replace the explicit logger names by __name__ you end up having a configured logger named __main__ in your main module, which is configured with handlers, but the naming of your auxiliary loggers is not in a way that it would create a hierarchy, hence your auxiliary_module loggers propagate to the implicit root logger which has no handlers configured.

Try the following: Change your class' init method as follows:

def __init__(self):
    self.logger = logging.getLogger('spam_application.auxiliary.Auxiliary')
    print self.logger.parent
    self.logger.info('creating an instance of Auxiliary')

Then run your main module once with

self.logger = logging.getLogger('spam_application.auxiliary.Auxiliary')

and once with

self.logger = logging.getLogger(__name__)

The output should look like this:

<Logger spam_application.auxiliary (WARNING)> # with explicit logger name
<RootLogger root (WARNING)>                   # using __name__