[ python-Bugs-932563 ] logging: need a way to discard Logger objects

Wed Sep 22 15:43:45 CEST 2004

Bugs item #932563, was opened at 2004-04-09 21:51
Message generated for change (Comment added) made by vsajip
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=105470&aid=932563&group_id=5470

Category: Python Library
Group: Feature Request
Status: Open
Resolution: None
>Priority: 7
Submitted By: Fred L. Drake, Jr. (fdrake)
Assigned to: Fred L. Drake, Jr. (fdrake)
Summary: logging: need a way to discard Logger objects

Initial Comment:
There needs to be a way to tell the logging package
that an application is done with a particular logger
object.  This is important for long-running processes
that want to use a logger to represent a related set of
activities over a relatively short period of time
(compared to the life of the process).

This is useful to allow creating per-connection loggers
for internet servers, for example.  Using a
connection-specific logger allows the application to
provide an identifier for the session that can be
automatically included in the logs without having the
application encode it into each message (a far more
error prone approach).

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

>Comment By: Vinay Sajip (vsajip)
Date: 2004-09-22 13:43

Message:
Logged In: YES 
user_id=308438

Hi Fred,

Any update on this? If you haven't the time (which I quite
understand), please post the code which does the Right Thing
(or mail it to me) without an explanation, and I'll try to
understand it.

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

Comment By: Fred L. Drake, Jr. (fdrake)
Date: 2004-07-01 03:53

Message:
Logged In: YES 
user_id=3066

Vinay:  I don't think that will work.  Another issue that
crops up once I start looking into the Logger class is that
findCaller() won't do (what I think is) the Right Thing when
wrappers and subclasses are involved.

After reviewing my application, I think the only thing the
application really needs to control is the creation of the
record objects, but that has to happen on the wrapper, or
there's no way to get the necessary information into the
record (without seriously performing surgery on the
underlying logger).

I think I've come up with a base class that does the Right
Thing, but I need to write up an explanation of why it works
the way it does.  It's not massively mysterious, but does
end up dealing with more than I really like worrying about.
 I don't have any more time for this tonight, but will write
up what I have and post it here in the next few days.

It shouldn't be hard to refactor what's in logging.Logger
and my base class to share most of the code.  Having the
base class in the logging package would avoid having to use
a separate findCaller() implementation.

Boosting the priority to make sure this stays on my radar.

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

Comment By: Vinay Sajip (vsajip)
Date: 2004-06-29 22:10

Message:
Logged In: YES 
user_id=308438

I just had a further thought: is the approach below any good 
to you? Apart from not being able to use the root logger, it 
seems to meet your need.

import logging

class MyLogger(logging.Logger):
  def makeRecord(self, name, level, fn, lno, msg, args, 
exc_info):
    record = logging.Logger.makeRecord(self, name, level, fn, 
lno, msg, args, exc_info)
    record.magicnumber = 0xDECAFBAD    # special number
    return record

logging._loggerClass = MyLogger

h = logging.StreamHandler()
logger = logging.getLogger("mylogger")
h.setFormatter(logging.Formatter("%(asctime)s %(levelname)
s %(magicnumber)X %(message)s"))
logger.addHandler(h)
logger.warn("There's a custom attribute in my message!")

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

Comment By: Vinay Sajip (vsajip)
Date: 2004-06-24 15:28

Message:
Logged In: YES 
user_id=308438

Suppose I add a callable "recordMaker" to logging, and modify 
makeRecord() to call it with logger + the args passed to 
makeRecord(). If it's necessary to add extra attrs to the 
LogRecord, this can be done by replacing recordMaker with 
your own callable. Seems less icky - what do you think? If 
you think it'll fly, are there any other args you think I need to 
pass into the callable?

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

Comment By: Fred L. Drake, Jr. (fdrake)
Date: 2004-06-24 14:06

Message:
Logged In: YES 
user_id=3066

I've attached a file showing the class I came up with.  I
don't consider this to be a good wrapper, just what worked.

I think one of the problems is that what I really want to
override is the makeRecord() method, not the logging methods
themselves.  There's too much logic in those dealing with
the disabling and level filtering that I don't want to
duplicate, but as soon as I pass the calls on to the
underlying logger, I can no longer change the makeRecord().

It would be possible to inject a new makeRecord() while my
methods are active (in my definition for log() in the
sample), and restore the original in a finally clause, but
that feels... icky.

The advantage of overriding makeRecord() is that formatter
can deal with with how the additional information is added
to the log because more information is made available on the
record.

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

Comment By: Vinay Sajip (vsajip)
Date: 2004-06-24 10:58

Message:
Logged In: YES 
user_id=308438

How about if I add a LoggerAdapter class which takes a 
logger in the __init__ and has logging methods debug(), info() 
etc. [and including _log()] which delegate to the underlying 
logger? Then you could subclass the Adapter and just 
override the methods you needed. Would that fit the bill? Of 
course the package can use a Logger-derived class, but this 
would apply to all loggers where the LoggerAdapter could be 
used for just some of the loggers in a system.

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

Comment By: Fred L. Drake, Jr. (fdrake)
Date: 2004-06-24 04:13

Message:
Logged In: YES 
user_id=3066

Looking at this again, after adjusting the application I
have that used the connection-specific loggers, I decided
that a different approach better solves the problem.

What you've shown requires exactly what I wanted to avoid:
having to make a gesture at each logging call (to transform
the message).  Instead of doing this, I ended up writing a
wrapper for the logger objects that implement the methods
log(), debug(), info(), warn(), warning(), error(),
exception(), critical(), and fatal().  These methods each
transform the message before calling the underlying logger.

It would be really nice to have something like this that
isolates the final call to Logger._log() so specific
implementations can simply override _log() (or some other
helper routine that gets all the info) and maybe the
__init__().  I don't think that's completely necessary, but
would probably make it a lot easier to implement this pattern.

There's probably some useful documentation improvements that
could be made to help people avoid the issue of leaking loggers.

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

Comment By: Fred L. Drake, Jr. (fdrake)
Date: 2004-06-10 16:50

Message:
Logged In: YES 
user_id=3066

Sorry for the delay in following up.

I'll re-visit the software where I wanted this to see how
it'll work out in practice.

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

Comment By: Tim Peters (tim_one)
Date: 2004-06-09 16:01

Message:
Logged In: YES 
user_id=31435

Assigned to Fred, because Vinay wants his input (in general, 
a bug should be assigned to the next person who needs 
to "do something" about it, and that can change over time).

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

Comment By: Vinay Sajip (vsajip)
Date: 2004-06-09 09:28

Message:
Logged In: YES 
user_id=308438

Fred, any more thoughts on this? Thanks, Vinay

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

Comment By: Vinay Sajip (vsajip)
Date: 2004-05-08 19:28

Message:
Logged In: YES 
user_id=308438

The problem with disposing of Logger objects 
programmatically is that you don't know who is referencing 
them. How about the following approach? I'm making no 
assumptions about the actual connection classes used; if you 
need to make it even less error prone, you can create 
delegating methods in the server class which do the 
appropriate wrapping.

class ConnectionWrapper:
	def __init__(self, conn):
		self.conn = conn

	def message(self, msg):
		return "[connection: %s]: %s" % 
(self.conn, msg)

and then use this like so...

class Server:

	def get_connection(self, request):
		# return the connection for this request

	def handle_request(self, request):
		conn = self.get_connection(request)
		# we use a cache of connection wrappers
		if conn in self.conn_cache:
			cw = self.conn_cache[conn]
		else:
			cw = ConnectionWrapper(conn)
			self.conn_cache[conn] = cw
		#process request, and if events need to 
be logged, you can e.g.
		logger.debug(cw.message("Network packet 
truncated at %d bytes"), n)
		#The logged message will contain the 
connection ID

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

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