16

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?

2 Answers 2

21

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.

Sign up to request clarification or add additional context in comments.

2 Comments

ah nice i forgot about the disable loggers setting, glad you found what you needed this seems like a much better solution
Thanks. You definitely helped me get on the right track. Much appreciated.
5

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() 

5 Comments

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...
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
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.
Hey @FilipKilibarda did you find any other solutions in the end?
Hey @davidejones, I've answered my own question with the solution I thought was most straightforward.

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.