[Python-Dev] Re: PEP 282 comments

[Vinay Sajip]

[Jeremy, on logging tracebacks at any level]
> I actually need this feature.  If the standard logger doesn't have it,
> we'll have to extend Zope with a Zope-specific logger that adds the
> feature.  I'm not asking for a feature because I think it might be
> useful.
Let me try and summarise - perhaps only for my own benefit :-)

1. Jeremy would like to be able to send traceback information from a logging
call at any level.
2. Guido is not keen on passing in exc_info from client code - the logger
should call sys.exc_info() automatically when required. And the "when" is
the crux of it...
3. In the context of an exception handler, a developer may want to send
different things to different loggers - e.g.

#Assume the traceback will provide info on which table, record, etc. caused
the problem
adminEmailer.exception("A record lock prevented completion. Please deal with
the mess.")
#We'd like to tell the developers the exact context too, as a diagnostic aid
developers.info("Yet another record locking problem was seen. Why oh why?")
#No traceback needed for this, it's just for the record (no pun intended)
dbstats.info("%-20s %s '%s'", "RECORD LOCK", self.table, self.key)

In the first call, the logic of "when" is built into the choice of call. In
the other two calls, we'd like to use the same method, but have it behave
differently in the two cases. Now, the decision about tracebacks has to be
made at *some* point. Let's assume that wherever that decision is made, we
can just call the low-level logging method _log(), as defined below:

class Logger:
...
  def _log(self, level, want_traceback, msg, args_tuple):
    """Low level logging method"""
    #Do the needful - if want_traceback is true, call sys.exc_info() and log
traceback info
    ...

So, the convenience methods become something like:

  def log(self, level, msg, *args):
    """For cases where the level needs to be computed by the caller at run
time"""
    if self.enabledFor(level):
      self._log(level, 0, msg, args)

  def info(self, msg, *args):
    if self.enabledFor(INFO):
      self._log(INFO, 0, msg, args)
  #and analogously for DEBUG, WARN, ERROR, FATAL

and then

  def exception(self, msg, *args):
    """Use when handling an exception"""
    if self.enabledFor(ERROR):
      self.log(ERROR, 1, msg, args)

Now, I hope all would agree that for "normal" use, the interface is fairly
minimal and in keeping with XP principles. In fact, some would argue that
debug(), info() etc. are redundant - so you can think of them as syntactic
sugar. Now to deal with the case of tracebacks at arbitrary levels, I
implemented

  def logException(self, level, msg, *args):
    """The same as log, except that it sends a 1 to _log for
want_traceback"""
    if self.enabledFor(level):
      self._log(level, 1, msg, args)

But I think we all neglected to see that by implementing exception with one
extra argument, the whole controversy goes away. Just remove logException
and change exception so that it becomes

  def exception(self, level, msg, *args):
    """Use when handling an exception"""
    if self.enabledFor(level):
      self.log(level, 1, msg, args)

We've effectively renamed logException() as exception(). There's not a lot
to choose between

    logger.exception(INFO, msg, args)

and

    logger.exception(msg, args)

If people can't stomach having to put the level into every call to
exception, then we can keep exception as it was [syntactic sugar] and
reintroduce logException (perhaps change the name, it's a bit of a sore
thumb).

If any more syntactic sugar is wanted, then I think it's reasonable for
people to roll their own classes. For example, some users want to use their
own levels, no doubt for their own good reasons. The current implementation
supports this. They can use log() and logException(), but debug(), info(),
warn(), error(), fatal() and exception() are useless to them - and so
exposed as the syntactic sugar they really are. So if users really want,
they can define a level BAD_HAIR_DAY and a corresponding sugar method
bad_hair_day(self, msg, *args) which calls either log() or logException(),
as they please. It's not a job for the standard module, I'm sure all would
agree.

[Slightly OT] The above issues have generated an awful lot of discussion,
and perhaps rightly so, but I'm conscious of time slipping by. I'd certainly
like logging to make it into 2.3a1, and there are a lot of other, more
important functional issues (such as: configurability) which need your
thoughts and ideas. Can I make a plea for input in this area? I know that
Python-dev people are busy people, so I don't know how many of you have had
time to actually try out the implementation, but I think it would help the
cause of PEP 282 if they gave specific feedback in other areas? For example:

Packaging: I originally implemented it as a package with separate modules
for logger, handler etc. and then consolidated into one module. I think one
module is better, except for the specific handlers - they don't all need to
be in the standard module. Perhaps MemoryHandler, StreamHandler and
FileHandler. But others such as SysLogHandler, NTEventLogHandler,
SMTPHandler, and perhaps even SocketHandler and DatagramHandler - should
they be in the same module, or should they perhaps go into a separate
"loghandlers" module which is also part of Python?

Specific handler implementations: what improvements could be made?

[Even more OT - for Monty Python fans] You know, it's really surprising that
Python hasn't had a logging module before, especially given the "Lumberjack"
song. I even thought of calling the package "Lumberjack" before the idea of
putting it into core Python came up :-)

Thanks & Regards

Vinay Sajip