CODEWITHSUNDEEP
pythonpython-logging
mguijarr
mguijarr

Reputation: 7908

Logging module weirdness, wrong display of log message?

Here is a small example of something I find very weird about the logging module:

import logging
logging.basicConfig()

#
# making a hierarchy like this:
#     root
#       |- session
#             |-session.foo
#
root_logger = logging.getLogger()
session_logger = logging.getLogger("session")
foo_logger = logging.getLogger("session.foo")
#
# root_logger and session_logger effective log levels
# are set to 30 (= WARNING)
#
foo_logger.debug("WA") #nothing is printed, so far so good
#
# and now enters the problem...
#
foo_logger.setLevel(logging.DEBUG)
foo_logger.debug("HELLO") #HELLO log message is printed!!!

I do not get why the 'HELLO' log message is printed, to my understanding since there is no handler attached to logger foo_logger the log message should bubble up, and effectively be stopped by higher level logger (session), since its level is set to WARNING (by default).

It seems like setting the level on foo_logger gives it rights to display through the handler but it is very unclear to me.

Can someone explain to me why the message is printed ? And what should I do to have the logger hierarchy as I would like ?

Upvotes: 0

Views: 413

Answers (1)

bruno desthuilliers
bruno desthuilliers

Reputation: 77902

Both loggers AND handlers have a level setting, and the default level for handlers is 0. You'd need to set the level of the parent handler - in your case root_logger.handlers[0] above logging.DEBUG to filter out the debug() calls on foo_logger:

root_logger.handlers[0].level = logging.WARN
foo_logger.debug("peekaboo") # should not be printed

Note that logging.basicConfig() only does a very simplistic config - it's mostly meant as a way to get started with logging, for any serious configuration you want dictConfig instead, which let you specify the handlers, formatters, levels etc as you see fit. Also note that a logger actually has a list of handlers (not a single one) and that multiple loggers can use the same handler, so who logs what (and where) depends on the combination of loggers AND handlers levels (and on the logger's propagate option too).

As a practical example, on my current (django) project we have (amongst others) a "console" handler (logs to stdout, which gunicorn redirects to it's own log file) whose level is set to INFO and a "notify" handler (sends emails notifications) with level set to WARN, so that some of our loggers (those for the most sensitive parts) will send INFO and above messages to gunicorn's logs and send WARN messages and above as notification emails too.

Upvotes: 1

Related Questions