1

I've been going around in circles with this for the last four hours. I've read the docs and this other SO page. This GitHub code recommends importing modules after logging has been setup in the main script, whereas this post suggests each module should have a complete implementation of the logger.

The way logging works has me completely mystified. I'm running Python 3.9.

Here the code at the top of my main script:

import logging def logger(): # Adding the following line logs each message twice to the console # logging.basicConfig(level=logging.DEBUG) # Create the logger logger = logging.getLogger(__name__) logger.setLevel(logging.DEBUG) # Create handlers ch = logging.StreamHandler() fh = logging.FileHandler('log.log', mode='w') ch.setLevel(logging.DEBUG) fh.setLevel(logging.DEBUG) # Create formatters ch.setFormatter(logging.Formatter('[ %(levelname)s ] %(name)s : %(message)s')) fh.setFormatter(logging.Formatter('%(asctime)s [ %(levelname)s ] %(name)s : %(message)s')) # Add handlers to logger logger.addHandler(ch) logger.addHandler(fh) return logger logger = logger() import log_module # Linter complains but at this point I don't care anymore logger.debug('Help') log_module.foo() 

In log_module.py, I have the following:

import logging logger = logging.getLogger(__name__) def foo(): logger.setLevel(logging.DEBUG) logger.debug('Debugging in module') 

If I run the main script, I only get one log message: [ DEBUG ] __main__ : Help.

If I uncomment the line with basicConfig in the logger function, I get three log messages, unformatted:

[ DEBUG ] __main__ : Help DEBUG:__main__:Help DEBUG:log_module:Debugging in module 

If I copy the whole logger() function over to log_module.py, I get the output I'm expecting, in the correct format, which is:

[ DEBUG ] __main__ : Help [ DEBUG ] log_module : Debugging in module 

However, it seems very silly to copy entire chunks of code across modules.

  • What am I doing wrong?
  • What should I be doing instead?
  • Does this need to be this convoluted just to get logs from multiple modules?

Thanks a lot in advance for your help.

1 Answer 1

3
  • What am I doing wrong?

You're configuring one logger and using a different logger. When you call logger() in the main script, the returned logger is the __main__ because that is what __name__ evaluates to from the main script. When you call logging.getLogger() from log_module.py, you get a module named log_module.

  • What should I be doing instead?

Either explicitly configure the log_module logger by calling a configure_logger function that accepts a logger instance as an argument, or configure the root logger (get the root logger by calling logging.getLogger() with no arguments). The root logger's configuration will be inherited by the others.

  • Does this need to be this convoluted just to get logs from multiple modules?

Once you understand that loggers are a hierarchy, it's a little simpler conceptually. It works nicely when you have nested packages/modules.

  • logging.getLogger() (root logger)
    • logging.getLogger('foo') (inherits configuration from root logger)
      • logging.getLogger('foo.bar') (inherits configuration from foo)
      • logging.getLogger('foo.baz') (inherits configuration from foo)
Sign up to request clarification or add additional context in comments.

6 Comments

Typo, I think: foo.bar and foo.baz both inherit configuration from foo.
Thank you. It took a while for me to realise that, to make it short, the logger instance in the main script should simply not have a name... It works when I'm using the above barebones scripts, so thanks a lot for clearing that out. However, as soon as I import a module such as PySide into those scripts, every log message is doubled with a non-formatted one. I have not changed anything else otherwise, and still don't understand what logger instance is producing that (since I'm only calling my loggers).
I managed to make this work when PySide is imported by adding the following line immediately after I instantiate my logger in the main script, before I do anything else: for h in logger.handlers: logger.removeHandler(h). This removes all the handlers which might be there (PySide adds only one). I don't know if this is the way this should be done, but if so maybe it should be added to the answer.
It sounds like you're calling logging.basicConfig(), which adds a stream handler to the root logger, and also adding handlers your module loggers. If you add a handler to the root logger and to a module logger, that would cause multiple log messages. When writing an application, in most cases, you only want to configure the root logger. Sometimes you'll want to configure a separate file handler each module of your application so each module logs to a separate path. A well-behaved library will not configure the root logger (i.e. importing a file should never modify the root logger).
@Cirrocumulus If you reply with a link to current code, I can take a look at your specific situation later tonight.
|

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.