Is it better to use root logger or named logger in Python

Question

I am trying to figure out the best practice for using logging in python across multiple modules. I see here: http://docs.python.org/2/howto/logging#logging-from-multiple-modules on how to use the root logger to log across multiple modules. As the link points out though, you can't tell where in your application your messages come from as they all show name "root."

It seems to me there are two options (this assumes my modules are NOT in a package structure, but are just a bunch of modules in the same folder):

1) Use the root logger as in the example, but change the log formatting to include the filename:

# myapp.py
import logging
import mylib

def main():
    logging.basicConfig(format='%(asctime)s %(filename)s %(levelname)s: %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p', level=logging.INFO)  #filename='myapp.log', 
    logging.info('Started')
    mylib.do_something()
    logging.info('Finished')

if __name__ == '__main__':
    main()

#mylib.py
import logging

def do_something():
    logging.info('Do something')




In [4]: import myapp

In [5]: myapp.main()
03/06/2014 12:22:07 PM myapp.py INFO: Started
03/06/2014 12:22:07 PM mylib.py INFO: Do something
03/06/2014 12:22:07 PM myapp.py INFO: Finished

2) Use a root logger in the main app but a named logger in the submodules, and use 'name' instead of 'filename' in the log format:

# myapp.py
import logging
import mylib

def main():
    #logging.basicConfig(format='%(asctime)s %(filename)s %(levelname)s: %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p', level=logging.INFO)  #filename='myapp.log', 
    logging.basicConfig(format='%(asctime)s %(name)s %(levelname)s: %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p', level=logging.INFO)  #filename='myapp.log', 
    logging.info('Started')
    mylib.do_something()
    logging.info('Finished')

if __name__ == '__main__':
    main()

#mylib.py
import logging

def do_something():
    #logging.info('Do something')
    logger = logging.getLogger(__name__)
    logger.info('Do something')



In [3]: import myapp

In [4]: myapp.main()
03/06/2014 12:27:29 PM root INFO: Started
03/06/2014 12:27:29 PM mylib INFO: Do something
03/06/2014 12:27:29 PM root INFO: Finished

score 13 · Accepted Answer · edited May 23 '17 at 12:00

13

Vinay Sajip (maintainer of the logging module) makes a recommendation here which is similar to your option #2, except that you could use a named logger everywhere, even in myapp:

import logging
import mylib
logger = logging.getLogger(__name__)

def main():
    logging.basicConfig(format='%(asctime)s %(module)s %(levelname)s: %(message)s',
                        datefmt='%m/%d/%Y %I:%M:%S %p', level=logging.INFO)  
    logger.info('Started')
    mylib.do_something()
    logger.info('Finished')

if __name__ == '__main__':
    main()

which yields

03/06/2014 12:59:25 PM myapp INFO: Started
03/06/2014 12:59:25 PM mylib INFO: Do something
03/06/2014 12:59:25 PM myapp INFO: Finished

Note that if you use %(module)s instead of %(name)s, then you get myapp where before you got root or myapp.py, or __main__.

This symmetry -- of always using logger -- may be especially useful if myapp is sometimes called as a script and sometimes imported as a module.

edited May 23 '17 at 12:00

Community

1
1

answered Mar 06 '14 at 17:55

unutbu

842,883
184
1,785
1,677

Thanks! I tried this, and it works, but I don't understand why. (Having both loggers in myapp and mylib named "\__name__".) \__name__ in myapp is "myapp" if myapp is imported like it is in my example. \__name__ in mylib is "mylib" So in each file, when logger = logging.getLogger(\__name__), aren't they creating two different loggers? Does it work because the output from each separate logger is still being passed up to the root logger, and then to the console? – bobo5645 Mar 06 '14 at 20:07
Also, can you elaborate on your last comment of always using "logger" being useful if myapp is sometimes called as a script or imported as a module. You mean using logger = logging.getLogger(..) is better for this than just using root logger directly: logging.info("..")? – bobo5645 Mar 06 '14 at 20:15
Yes, you are getting two different loggers. [This flowchart](http://docs.python.org/2/howto/logging.html#logging-flow) shows loggers (by default) propagate records to parent loggers. So the root logger's handler(s) get a chance to handle the record. – unutbu Mar 06 '14 at 20:53
Suppose you were to use `logging.info` in the main script, myapp, but `logger.info` in modules. Suppose later you create a new script which *imports* `myapp`. Now the logging output would use `root` as the `%(name)s` whenever a logging message came from myapp, whereas for consistency you'd rather have it report `myapp`. If you instead *always* use `logger.info`, even in the main script, then you future-proof your code against the possibility that it may one day be used as a module. – unutbu Mar 06 '14 at 20:57
Thanks for the flowchart, and your explanation of the advantage of using logger. Both make sense to me now. Not sure if I should start a new question but: if in this example I want to have multiple handlers, i.e., INFO level goes to stdout and a file, and ERROR level is sent to an email address, is there a way to do that? I assume it's not logging.addHandler()? Maybe logging.config.fileConfig()? – bobo5645 Mar 06 '14 at 21:08
Yes, you could use a [LevelFilter](http://stackoverflow.com/a/7447596/190597) and a [SMTPHandler](http://docs.python.org/2/library/logging.handlers.html#smtphandler). – unutbu Mar 06 '14 at 21:12
But "basicConfig" affect ALL the handlers or the system (or, more precisely, the root handler), doesn't it? – DGoiko Jan 08 '19 at 09:34
Yes, `basicConfig` does add handlers to the root logger. But `basicConfig` is [just a convenience function](https://stackoverflow.com/a/4139462/190597). You don't have to use it. If you want to add handlers to other named loggers, you are free to do that instead. The link above gives one such example. – unutbu Jan 08 '19 at 13:13

Is it better to use root logger or named logger in Python

1 Answers1

Linked