Python logging multiple modules logger not working outside main program

Question

My goal is to log from multiple modules, while only configuring the logger in one place - in the main program. As shown in this answer, one should include

logging.config.fileConfig('/path/to/logging.conf') 

in the main program, then in all other modules include

logger = logging.getLogger(__name__)

I believe that's what I've done below, yet I get unexpected behaviour.

c.py

# c.py
import logging
import logging.config
import d

logging.config.fileConfig("logging.conf")
logger = logging.getLogger(__name__)

logger.warning('logging from c')
d.foo()

d.py

# d.py
import logging

logger = logging.getLogger(__name__)

# this will print when d is imported
logger.warning('logging from d on import')

def foo():
    # this does not print
    logger.warning("logging from d on call foo()")

Output

$ python c.py
logging from d on import
logging from c

What I would expect, is that when d.foo() executes in c.py, that a message would be logged from d, however, that's not the case. This is confusing because when the logger is called from module level in d, it logs a message to the console, but when called from inside foo() it doesn't.

Config file

[loggers]
keys=root

[handlers]
keys=consoleHandler

[formatters]
keys=simpleFormatter

[logger_root]
level=DEBUG
handlers=consoleHandler

[handler_consoleHandler]
class=StreamHandler
level=DEBUG
formatter=simpleFormatter
args=(sys.stdout,)

[formatter_simpleFormatter]
format=%(message)s
datefmt=

Further analysis

So I've noticed that if I remove the line

logging.config.fileConfig("logging.conf")

from c.py, then logging from d.foo() works as expected. So there's either something wrong in the configuration file or due to the fact that I provide a configuration file something causes the logger in d.py to get messed up.

Question

1. Why does a message get logged from d when called from module level, but not from inside d.foo()?
2. And how can I achieve the goal of logging from multiple modules, while only configuring the logging in the main program?

Stomach

Answer 1

The problem lies in the fact that

import d

comes before

logging.config.fileConfig("logging.conf")

as pointed out by @davidejones. Here's why:

As stated in the docs, when logging.config.fileConfig() is called, its default behaviour is to disable any existing loggers. So when import d happens, logger is initialised in d, then when logging.config.fileConfig() is called, the logger in d is disabled, which is why we didn't see any logging when d.foo() was called.

Solution

logging.config.fileConfig() takes an argument, disable_existing_loggers, which is True by default. Use

logging.config.fileConfig("logging.conf", disable_existing_loggers=False)

And output becomes

>>> python c.py
logging from d on import
logging from c
logging from d on call foo()

As expected.

Stomach

ah nice i forgot about the disable loggers setting, glad you found what you needed this seems like a much better solution – Axe

Thanks. You definitely helped me get on the right track. Much appreciated. – Stomach

Answer 2

I think that the import of d is happening before the config of the logger so doing something like this might give what you want?

# c.py
import logging
import logging.config

logging.config.fileConfig("logging.conf")
logger = logging.getLogger(__name__)

import d


logger.warning('logging from c')
d.foo()

it gives me these results

logging from d on import
logging from c
logging from d on call foo()

EDIT

Looking at the code it might make more sense to have a seperate file to have the logging setup then you import that once in you main file the other modules will have it then and it doesn't look as messy. So maybe having a logsetup.py like this

import logging
import logging.config

logging.config.fileConfig("logging.conf")

and then c.py looking like this instead which still gives the same results

# c.py
import logsetup
import logging
import d

logger = logging.getLogger(__name__)

logger.warning('logging from c')
d.foo()

Axe

I see. I guess when I import d before configuring the logger, the logger in d is left without a handler, so it doesn't print anywhere. But when I don't include the statement logging.config.fileConfig("logging.conf") at all I would expect neither logger to print anything (which is not the case and they both do print to console). But I guess in that case both loggers end up with a default console handler... – Stomach

Yea i think that's a fair assessment. I've updated my answer to do it slightly differently. I think maybe having a separate file to setup the logger would be best. Similar to how a framework like django or flask might have a settings.py file to deal with this kind of thing, hope it helps – Axe

I like your second approach. I'll accept that answer after some time if I don't get another perspective from someone else. Thanks for help. – Stomach

Hey @FilipKilibarda did you find any other solutions in the end? – Axe

Hey @davidejones, I've answered my own question with the solution I thought was most straightforward. – Stomach