classification
Title: Logging ancestors ignored after configuration
Type: behavior Stage:
Components: Library (Lib) Versions: Python 2.5
process
Status: closed Resolution: not a bug
Dependencies: Superseder:
Assigned To: vinay.sajip Nosy List: acooke, sayap, vinay.sajip
Priority: normal Keywords:

Created on 2008-04-26 13:46 by acooke, last changed 2008-05-06 01:41 by acooke. This issue is now closed.

Messages (4)
msg65843 - (view) Author: andrew cooke (acooke) Date: 2008-04-26 13:46
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.

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")
msg65915 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2008-04-28 13:15
This is not a bug - it's by design, as I explained in my reply to your
posting on comp.lang.python. In my reply, I suggested how you could
avoid problems.
msg66265 - (view) Author: Yap Sok Ann (sayap) Date: 2008-05-05 09:56
I'd think that it is a rather common situation where one wants to use 
use both fileConfig and module-level logger. As of now, the workaround 
suggested by Andrew seems to be the only viable way to achieve that. 
The alternative approach mentioned, i.e. to name all loggers explicitly 
in the configuration file, is just too unintuitive.
msg66300 - (view) Author: andrew cooke (acooke) Date: 2008-05-06 01:41
Got more important things than this to worry about, but yes, original
response not very helpful.  In a perfect world this might be either
justified more clearly or addressed.  OTOH, I get the impression hardly
anyone uses this package (docs were pretty opaque...)

Also, isn't this a "won't fix" rather than an "invalid"?
History
Date User Action Args
2008-05-06 01:41:29acookesetmessages: + msg66300
2008-05-05 09:56:17sayapsetnosy: + sayap
messages: + msg66265
2008-04-28 13:15:53vinay.sajipsetstatus: open -> closed
assignee: vinay.sajip
resolution: not a bug
messages: + msg65915
nosy: + vinay.sajip
2008-04-26 13:46:36acookecreate