Logging ancestors ignored if config changes?

[andrew cooke]

Hi,

I am seeing some odd behaviour with logging which would be explained
if loggers that are not defined explicitly (but which are controlled
via their ancestors) must be created after the logging system is
configured via fileConfig().

That's a bit abstract, so here's the problem itself: I define my log
within a module by doing

import logging
log = logging.getLogger(__name__)

Now typically __name__ will be something like "acooke.utils.foo".

That happens before the application configures logging, which it does
by calling logging.config.fileConfig() to load a configuration.

If I do that, then I don't see any logging output from
"acooke.utils.foo" (when using "log" from above after "fileConfig" has
been called) unless I explicitly define a logger with that name.
Neither root nor an "acooke" logger, defined in the config file, are
called.

Is this a bug? Am I doing something stupid? To me the above seems
like a natural way of using the system...

Thanks,
Andrew

 

[andrew cooke]

One way to handle this is to make creation of module-level Loggers
lazy, and make sure that logging initialisation occurs before any
other logging is actually used (which is not so hard - just init log
at the start of the application).

Of course, there's a performance hit...

For example:

class Log(object):
def __init__(self, name):
super(Log, self).__init__()
self._name = name
self._lazy = None
def __getattr__(self, key):
if not self._lazy:
self._lazy = logging.getLogger(self._name)
return getattr(self._lazy, key)

and then, in some module:

from acooke.util.log import Log
log = Log(__name__)
[...]
class Foo(object):
def my_method(self):
log.debug("this works as expected")

Andrew

 

[Vinay Sajip]

Hi,

I am seeing some odd behaviour withloggingwhich would be explained
if loggers that are not defined explicitly (but which are controlled
via their ancestors) must be created after theloggingsystem is
configured via fileConfig().

That's a bit abstract, so here's the problem itself: I define my log
within a module by doing

importlogging
log =logging.getLogger(__name__)

Now typically __name__ will be something like "acooke.utils.foo".

That happens before the application configureslogging, which it does
by callinglogging.config.fileConfig() to load a configuration.

If I do that, then I don't see anyloggingoutput from
"acooke.utils.foo" (when using "log" from above after "fileConfig" has
been called) unless I explicitly define a logger with that name.
Neither root nor an "acooke" logger, defined in the config file, are
called.

Is this a bug? Am I doing something stupid? To me the above seems
like a natural way of using the system...

Thanks,
Andrew

It's not a bug, it's by design (for better or worse). A call to
fileConfig disables all existing loggers which are not explicitly
named in the new configuration. Configuration is intended for one-off
use rather than in an incremental mode.

Better approaches would be to defer creation of the loggers
programmatically until after the configuration call, or else to name
them explicitly in the configuration.

Regards,

Vinay Sajip