[Patches] [ python-Patches-1641790 ] logging leaks loggers

[SourceForge.net]

Patches item #1641790, was opened at 2007-01-22 09:00
Message generated for change (Comment added) made by josiahcarlson
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=305470&aid=1641790&group_id=5470

Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: Library (Lib)
Group: Python 2.6
Status: Closed
Resolution: Invalid
Priority: 5
Private: No
Submitted By: TH (therve)
Assigned to: Vinay Sajip (vsajip)
Summary: logging leaks loggers

Initial Comment:
In our application, we used to create a logger per client (to get IP/port automatically in the prefix). Unfortunately logging leaks loggers by keeping it into an internal dict (attribute loggerDict of Manager).

Attached a patch using a weakref object, with a test.

----------------------------------------------------------------------

Comment By: Josiah Carlson (josiahcarlson)
Date: 2007-01-27 11:10

Message:
Logged In: YES 
user_id=341410
Originator: NO

pitrou: you aren't understanding vsajip .  Either factories or custom
classes are *trivial* to write to "do the right thing".

If I understand what you are doing, you have been doing...

class connection:
    def __init__(self, ...):
        self.logger = logging.getLogger(<socket info>)
    def foo(self, ...):
        self.logger.info(message) #or equivalent debug, warning, etc.

If you define the following class:

class loggingwrapper(object):
    __slots__ = ['socketinfo']
    def __init__(self, socketinfo):
        self.socketinfo = str(socketinfo)
    def __getattr__(self, attr):
        fcn = getattr(logger.getLogger(''), attr)
        def f2(msg, *args, **kwargs):
            return fcn("%s %s"%(self.socketinfo, str(msg)), *args,
**kwargs)
        return f2

You can then do *almost* the exact same thing you were doing before...

class connection:
    def __init__(self, ...):
        self.logger = loggingwrapper(<socket info>) #note the change
    def foo(self, ...):
        self.logger.info(message)

And it will work as you want.

----------------------------------------------------------------------

Comment By: Antoine Pitrou (pitrou)
Date: 2007-01-23 09:06

Message:
Logged In: YES 
user_id=133955
Originator: NO

Ok, since I was the one bitten by this bug I might as well add my 2 cents
to the discussion.

vsajip:
> 1. Use the 'extra' parameter (added in Python 2.5).
This is not practical. I want to define a prefix once and for all for all
log messages that will be output in a given context. Explicitly adding a
parameter to every log call does not help.
(of course I can write wrappers to do this automatically - and that's what
I ended up doing -, but then I must write 6 of them: one for each of
"debug", "info", "warning", "error", "critical", and "exception"...)

> 2. Use a connection-specific factory to obtain the logging message, or
wrap the logging call on a connection-specific object which inserts the
connection info.

I don't even know what this means, but it sounds way overkill...

> 3. Use something other than a literal string for the message - as
documented, any object can be used as the message, and the logging system
calls str() on it to get the actual text of the message. The "something"
can be an instance of a class which Does The Right Thing.

IIUC this means some explicitly machinery on each logging call, since I
have to wrap every string in a constructor. Just like the "extra"
parameter, with a slightly different flavour.

It's disturbing that the logging module has so many powerful options but
no way of conveniently doing simple things without creating memory
leaks...


----------------------------------------------------------------------

Comment By: TH (therve)
Date: 2007-01-23 00:54

Message:
Logged In: YES 
user_id=1038797
Originator: YES

OK I understand the design. But it's not clear in the documentation that
once you've called getLogger('id') the logger will live forever. It's
especially problematic on long-running processes.

It would be great to have at least a warning in the documentation about
this feature.

----------------------------------------------------------------------

Comment By: Vinay Sajip (vsajip)
Date: 2007-01-23 00:42

Message:
Logged In: YES 
user_id=308438
Originator: NO

This is not a leak - it's by design. You are not using best practice when
you create a logger per client; the specific scenario of getting connection
info in the logging message can currently be done in several ways, e.g.

1. Use the 'extra' parameter (added in Python 2.5).
2. Use a connection-specific factory to obtain the logging message, or
wrap the logging call on a connection-specific object which inserts the
connection info.
3. Use something other than a literal string for the message - as
documented, any object can be used as the message, and the logging system
calls str() on it to get the actual text of the message. The "something"
can be an instance of a class which Does The Right Thing.

----------------------------------------------------------------------

Comment By: Neal Norwitz (nnorwitz)
Date: 2007-01-22 20:47

Message:
Logged In: YES 
user_id=33168
Originator: NO

Vinay, can you provide some direction?  Thanks.

----------------------------------------------------------------------

Comment By: TH (therve)
Date: 2007-01-22 09:09

Message:
Logged In: YES 
user_id=1038797
Originator: YES

Looking at the documentation, it seems keeping it is mandatory because you
must get the same instance with getLogger. Maybe it'd need a documented way
to remove from the dict, though.

----------------------------------------------------------------------

You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=305470&aid=1641790&group_id=5470