classification
Title: logger use dict for loggers instead of WeakValueDictionary
Type: enhancement Stage:
Components: Library (Lib) Versions: Python 3.3
process
Status: closed Resolution: not a bug
Dependencies: Superseder:
Assigned To: vinay.sajip Nosy List: socketpair, terry.reedy, vinay.sajip
Priority: normal Keywords:

Created on 2011-04-28 19:29 by socketpair, last changed 2011-04-29 23:38 by terry.reedy. This issue is now closed.

Messages (4)
msg134714 - (view) Author: Марк Коренберг (socketpair) * Date: 2011-04-28 19:29
logger use dict for loggers instead of WeakValueDictionary

Now, when object returned by getLogger() gets unreferenced - it will not be garbage collected, as reference is stored in logging module. This will results in leaked file object, that cannot be closed in easy way. Some modules (notable yum) opens dozen of loggers that prevents me to unmount directory where logs placed. Now, I use workaround:

-----------------------
try:
    # work with yum
finally:
    yum_base_cli.close()
    yum_base_cli.closeRpmDB()
    yum_base_cli.doUnlock()
    del yum_base_cli
    # gc.collect() may be called here, but it does not actually change anything....
    for logger_name,logger in cli.logging.Logger.manager.loggerDict.iteritems():
        if not logger_name.startswith('yum'):
            continue
        for h in logger.handlers:
            h.flush()
            h.close()
-----------------------
The problem in that logging module stores many references in lists and dicts. So just replacing {} with WeakValueDictionary() 
does not eliminate problem fully.

I have checked, problem exists in all python versions
msg134788 - (view) Author: Vinay Sajip (vinay.sajip) * (Python committer) Date: 2011-04-29 16:48
I had to delete my previous response to the initial post, as something got mangled in it. Here's what I meant to say:
----------------------------------------------
It sounds to me as if there's a problem in yum that needs sorting out: I'm not sure why it would need dozens of loggers.

As your workaround snippet shows, leaking files is not due to loggers but due to handlers - they're a different animal. Handlers need not be leaked - they can just be closed when you're done with them. Handlers *are* stored with weak references.

The design contract for loggers precludes using weak references for them. For example, if I use a library and from my logging initialization code get a reference to its top-level logger and e.g. set that logger's level, then when I've finished, there may not be any other references to that logger until I do an import of some library module. I wouldn't want the reference to the logger to go away, because then the library wouldn't know my intention regarding the level setting.

Normal practice would be to add a few handlers to yum's top-level logger and let descendant loggers inherit them. I'm not familiar with yum, so I don't know if/why it deviates from this common and best practice approach.

As you state, replacing {} with WeakValueDictionary() wouldn't solve the problem, and would violate the design assumptions/contract relating to loggers.

By the way, the logging module does not store loggers in lists and dicts - just in a single dict in a manager. Handlers are stored in weak reference dicts as well as lists but that does not mean they are guaranteed to be garbage collected, since there could also be references to them in user code. Likewise for loggers - typically there would be references to them in lines like

logger = logging.getLogger(__name__)

in numerous modules. Even if yum consists of dozens of modules (which perhaps explains dozens of loggers), they needn't leak files, as just adding a single FileHandler to yum's top-level logger would serve to capture logging events from the entire yum package hierarchy.
msg134807 - (view) Author: Марк Коренберг (socketpair) * Date: 2011-04-29 18:38
I'm not YUM developer, I'm very sad user of YUM API. Also, I'm novice in python logging complex system.

1. There is no way to remove logger once it added via getLogger(). why?
2. When yum should close handlers? In destructor (cleanup function) of module?
3. Why this code does not close log files?
----------------
def test():
    import yum
    # work with yum

test()
gc.collect() # to sure that nothing have extra references.
# yum logs still alive in spite of that yum module (and imported logging module) 'is unloaded'
-----------------
3. Also, logger.handlers is not documented...it's definitely the bug as I think.
msg134823 - (view) Author: Terry J. Reedy (terry.reedy) * (Python committer) Date: 2011-04-29 23:38
Mark, this is a feature request to change the storage of loggers.  A behavior issue (bug report) must report a discrepancy between doc and behavior. Vinay rejected that request as not really possible.

Questions about using yum should go to a yum list or to python-list.
The tracker is not a tutorial list.

"logger.handlers is not documented"
Please look at section 15.9. logging.handlers — Logging handlers
Are you referring specifically to how they are stored?
We do not usually document the internal details of modules.
History
Date User Action Args
2011-04-29 23:38:58terry.reedysetversions: - Python 3.1, Python 2.7, Python 3.2
nosy: + terry.reedy

messages: + msg134823

type: behavior -> enhancement
2011-04-29 23:06:36terry.reedysetversions: - Python 2.6, Python 3.4
2011-04-29 18:38:59socketpairsetmessages: + msg134807
2011-04-29 16:48:25vinay.sajipsetmessages: + msg134788
2011-04-29 16:41:36vinay.sajipsetmessages: - msg134786
2011-04-29 16:40:37vinay.sajipsetstatus: open -> closed

nosy: + vinay.sajip
messages: + msg134786

assignee: vinay.sajip
resolution: not a bug
2011-04-28 19:29:16socketpaircreate