Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Python logging multiple modules logger not working outside main program

Tags:

python

logging

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?
like image 587
Filip Kilibarda Avatar asked Feb 24 '17 05:02

Filip Kilibarda


People also ask

Is Python logging multiprocessing safe?

As Matino correctly explained: logging in a multiprocessing setup is not safe, as multiple processes (who do not know anything about the other ones existing) are writing into the same file, potentially intervening with each other.

What is logging getLogger (__ name __) Python?

To start logging using the Python logging module, the factory function logging. getLogger(name) is typically executed. The getLogger() function accepts a single argument - the logger's name. It returns a reference to a logger instance with the specified name if provided, or root if not.

How do I add a logger to a Python module?

Best practice is, in each module, to have a logger defined like this: import logging logger = logging.getLogger (__name__) near the top of the module, and then in other code in the module do e.g. logger.debug ('My message with %s', 'variable data')

Is it possible to use multiple loggers in same module?

Now you could use multiple loggers in same module and across whole project if the above is defined in a separate module and imported in other modules were logging is required. a=get_logger("__app___") b=get_logger("__basic_log__") a.info("Starting logging!") b.debug("Debug Mode") Share Improve this answer Follow

How do you define logging in a module?

Best practice is, in each module, to have a logger defined like this: import logging logger = logging.getLogger(__name__) near the top of the module, and then in other code in the module do e.g. logger.debug('My message with %s', 'variable data') If you need to subdivide logging activity inside a module, use e.g.

What is a logger object in Python?

The Logger object is the object of this module which we can manipulate to do all our required logging. To instantiate a Logger object, we must always specify: Multiple calls to getLogger (name) with the same name always give a reference to the same object. Now that we have our logger object, we can use multiple functions on it.


1 Answers

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.

like image 84
Filip Kilibarda Avatar answered Sep 22 '22 14:09

Filip Kilibarda