Django Logging Configuration: How the Default Settings Interfere with Yours

My colleague Vinod recently found the answer on Stack Overflow to something that's been bugging me for a long time - why do my Django logging configurations so often not do what I think they should?

Short answer

If you want your logging configuration to behave sensibly, set LOGGING_CONFIG to None in your Django settings, and do the logging configuration from scratch using the Python APIs:

LOGGING_CONFIG = None
LOGGING = {...}  # whatever you want

import logging.config
logging.config.dictConfig(LOGGING)

Explanation

The kernel of the explanation is in this Stack Overflow answer by jcotton; kudos to jcotton for the answer: before processing your settings, Django establishes a default configuration for Python's logging system, but you can't override it the way you would think, because disable_existing_loggers doesn't work quite the way the Django documentation implies.

The Django documentation for disable_existing_loggers in 1.6, 1.7, and dev (as of January 8, 2015) says "If the disable_existing_loggers key in the LOGGING dictConfig is set to True (which is the default) the default configuration is completely overridden." (emphasis added)

That made me think that I could set disable_existing_loggers to True (or leave it out) and Django's previously established default configuration would have no effect.

Unfortunately, that's not what happens. The disable_existing_loggers flag only does literally what it says: it disables the existing loggers, which is different from deleting them. The result is that they stay in place, they don't log any messages, but they also don't propagate any messages to any other loggers that might otherwise have logged them, regardless of whether they're configured to do so.

What if you try the other option, and set disable_existing_loggers to False? Then your configuration is merged with the previous one (the default configuration that Django has already set up), without disabling the existing loggers. If you use Django's LOGGING setting with the default LOGGING_CONFIG, there is no setting that will simply replace Django's default configuration.

Because Django installs several django loggers, the result is that unless you happened to have specified your own configuration for each of them (replacing Django's default loggers), you have some hidden loggers possibly blocking what you expect to happen.

For example - when I wasn't sure what was going on in a Django project, sometimes I'd try just adding a root logger, to the console or to a file, so I could see everything. I didn't know that the default Django loggers were blocking most log messages from Django itself from ever reaching the root logger, and I would get very frustrated trying to see what was wrong with my logging configuration. In fact, my own logging configuration was probably fine; it was just being blocked by a hidden, overriding configuration I didn't know about.

We could work around the problem by carefully providing our own configuration for each logger included in the Django default logging configuration, but that's subject to breaking if the Django default configuration changes.

The most fool-proof solution is to disable Django's own log configuration mechanism by setting LOGGING_CONFIG to None, then setting the log configuration explicitly ourselves using the Python logging APIs. There's an example above.

The nitty-gritty

The Python documentation is more accurate: "disable_existing_loggers – If specified as False, loggers which exist when this call is made are left enabled. The default is True because this enables old behavior in a backward- compatible way. This behavior is to disable any existing loggers unless they or their ancestors are explicitly named in the logging configuration."

In other words, disable_existing_loggers does literally what it says: it leaves existing loggers in place, it just changes them to disabled.

Unfortunately, Python doesn't seem to document exactly what it means for a logger to be disabled, or even how to do it. The code seems to set a disabled attribute on the logger object. The effect is to stop the logger from calling any of its handlers on a log event. An additional effect of not calling any handlers is to also block propagation of the event to any parent loggers.

Status of the problem

There's been some recent discussion on the developers' list about at least improving the documentation, with a core developer offering to review anything submitted. And that's where things stand.