I remember when the logging package seemed big and complicated and forbidding. And then I remember when I finally "got" it, started using it, even liked it. And then I've discovered that I didn't really understand the model after all.
Consider this: we have two loggers
root \ -- mylogger
configured as follows:
import logging root = logging.getLogger() root.setLevel(logging.INFO) root.addHandler(logging.FileHandler("info.log")) mylogger = logging.getLogger('mylogger') mylogger.setLevel(logging.DEBUG) mylogger.addHandler(logging.FileHandler("debug.log"))
What happens when I do
Answer: the message appears in both debug.log and info.log.
That was surprising to me. I'd always thought that a logger's level was a gatekeeper to all of that logger's handlers. In other words, I always thought that when a message was propagating from a logger to its parent (here from mylogger to root), it was also being filtered against the parent's log level. That turns out not to be the case.
What actually happens is that a message is tested against the level of the logger where it was initially logged, and if it passes the check, it gets passed to all the handlers of that logger and all its ancestors with no further checks. Unless the propagation is stopped somewhere by one of the loggers having propagate set to False. And of course each handler has its own level filtering. And I'm ignoring filters and the global level override.
Part of the confusion was caused by my misunderstanding of
logging.NOTSET. I assumed, incorrectly, that it was just a
regular logging level, one even less severe than
DEBUG. So when I
wrote code like this:
import logging root = logging.getLogger() root.setLevel(logging.INFO) root.addHandler(logging.FileHandler("info.log")) mylogger = logging.getLogger('mylogger') mylogger.setLevel(logging.NOTSET) # <-- that's the default level, actually mylogger.debug("debug message")
I saw the debug message being suppressed and assumed it was because of the root logger's level. Which is correct, in a way, just not the way I thought about it.
NOTSET does not mean "pass all messages through", it
means "inherit the log level from the parent logger". The documentation
this, although in a rather convoluted way. My own fault for misunderstanding
it, I guess.