PEP 282: A Logging System -- comments please
Trent Mick
trentm at ActiveState.com
Fri Feb 15 19:43:33 EST 2002
Howdy all,
I would appreciate any comments you might have on this proposal for adding a
logging system to the Python Standard Library. This PEP is still an early
draft so please forward your comments just to me directly for now.
Thanks,
Trent
-----------------------------------------------------------
PEP: 282
Title: A Logging System
Version: $Revision: 1.1 $
Last-Modified: $Date: 2002/02/15 04:09:17 $
Author: trentm at activestate.com (Trent Mick)
Status: Draft
Type: Standards Track
Created: 4-Feb-2002
Python-Version: 2.3
Post-History:
Abstract
This PEP describes a proposed logging package for Python's
standard library.
Basically the system involves the user creating one or more
logging objects on which methods are called to log debugging
notes/general information/warnings/errors/etc. Different logging
'levels' can be used to distinguish important messages from
trivial ones.
A registry of named singleton logger objects is maintained so that
1) different logical logging streams (or 'channels') exist
(say, one for 'zope.zodb' stuff and another for
'mywebsite'-specific stuff)
2) one does not have to pass logger object references around.
The system is configurable at runtime. This configuration
mechanism allows one to tune the level and type of logging done
while not touching the application itself.
Motivation
If a single logging mechanism is enshrined in the standard
library, 1) logging is more likely to be done 'well', and 2)
multiple libraries will be able to be integrated into larger
applications which can be logged reasonably coherently.
Influences
This proposal was put together after having somewhat studied the
following logging packages:
o java.util.logging in JDK 1.4 (a.k.a. JSR047) [1]
o log4j [2]
These two systems are *very* similar.
o the Syslog package from the Protomatter project [3]
o MAL's mx.Log package [4]
This proposal will basically look like java.util.logging with a
smattering of log4j.
Simple Example
This shows a very simple example of how the logging package can be
used to generate simple logging output on stdout.
--------- mymodule.py -------------------------------
import logging
log = logging.getLogger("MyModule")
def doit():
log.debug("doin' stuff")
# do stuff ...
-----------------------------------------------------
--------- myapp.py ----------------------------------
import mymodule, logging
log = logging.getLogger("MyApp")
log.info("start my app")
try:
mymodule.doit()
except Exception, e:
log.error("There was a problem doin' stuff.")
log.info("end my app")
-----------------------------------------------------
> python myapp.py
0 [myapp.py:4] INFO MyApp - start my app
36 [mymodule.py:5] DEBUG MyModule - doin' stuff
51 [myapp.py:9] INFO MyApp - end my app
^^ ^^^^^^^^^^^^ ^^^^ ^^^^^ ^^^^^^^^^^
| | | | `-- message
| | | `-- logging name/channel
| | `-- level
| `-- location
`-- time
NOTE: Not sure exactly what the default format will look like yet.
Control Flow
[Note: excerpts from Java Logging Overview. [5]]
Applications make logging calls on *Logger* objects. Loggers are
organized in a hierarchical namespace and child Loggers may
inherit some logging properties from their parents in the
namespace.
Notes on namespace: Logger names fit into a "dotted name"
namespace, with dots (periods) indicating sub-namespaces. The
namespace of logger objects therefore corresponds to a single tree
data structure.
"" is the root of the namespace
"Zope" would be a child node of the root
"Zope.ZODB" would be a child node of "Zope"
These Logger objects allocate *LogRecord* objects which are passed
to *Handler* objects for publication. Both Loggers and Handlers
may use logging *levels* and (optionally) *Filters* to decide if
they are interested in a particular LogRecord. When it is
necessary to publish a LogRecord externally, a Handler can
(optionally) use a *Formatter* to localize and format the message
before publishing it to an I/O stream.
Each Logger keeps track of a set of output Handlers. By default
all Loggers also send their output to their parent Logger. But
Loggers may also be configured to ignore Handlers higher up the
tree.
The APIs are structured so that calls on the Logger APIs can be
cheap when logging is disabled. If logging is disabled for a
given log level, then the Logger can make a cheap comparison test
and return. If logging is enabled for a given log level, the
Logger is still careful to minimize costs before passing the
LogRecord into the Handlers. In particular, localization and
formatting (which are relatively expensive) are deferred until the
Handler requests them.
Levels
The logging levels, in increasing order of importance, are:
DEBUG
INFO
WARN
ERROR
FATAL
ALL
This is consistent with log4j and Protomatter's Syslog and not
with JSR047 which has a few more levels and some different names.
Implementation-wise: these are just integer constants, to allow
simple comparison of importance. See "What Logging Levels?" below
for a debate on what standard levels should be defined.
Loggers
Each Logger object keeps track of a log level (or threshold) that
it is interested in, and discards log requests below that level.
The *LogManager* maintains a hierarchical namespace of named
Logger objects. Generations are denoted with dot-separated names:
Logger "foo" is the parent of Loggers "foo.bar" and "foo.baz".
The main logging method is:
class Logger:
def log(self, level, msg, *args):
"""Log 'msg % args' at logging level 'level'."""
...
however convenience functions are defined for each logging level:
def debug(self, msg, *args): ...
def info(self, msg, *args): ...
def warn(self, msg, *args): ...
def error(self, msg, *args): ...
def fatal(self, msg, *args): ...
XXX How to defined a nice convenience function for logging an exception?
mx.Log has something like this, doesn't it?
XXX What about a .raising() convenience function? How about:
def raising(self, exception, level=ERROR): ...
It would create a log message describing an exception that is
about to be raised. I don't like that 'level' is not first
when it *is* first for .log().
Handlers
Handlers are responsible for doing something useful with a given
LogRecord. The following core Handlers will be implemented:
- StreamHandler: A handler for writing to a file-like object.
- FileHandler: A handler for writing to a single file or set
of rotating files.
More standard Handlers may be implemented if deemed desirable and
feasible. Other interesting candidates:
- SocketHandler: A handler for writing to remote TCP ports.
- CreosoteHandler: A handler for writing to UDP packets, for
low-cost logging. Jeff Bauer already had such a system [5].
- MemoryHandler: A handler that buffers log records in memory
(JSR047).
- SMTPHandler: Akin to log4j's SMTPAppender.
- SyslogHandler: Akin to log4j's SyslogAppender.
- NTEventLogHandler: Akin to log4j's NTEventLogAppender.
Formatters
A Formatter is responsible for converting a LogRecord to a string
representation. A Handler may call its Formatter before writing a
record. The following core Formatters will be implemented:
- Formatter: Provide printf-like formatting, perhaps akin to
log4j's PatternAppender.
Other possible candidates for implementation:
- XMLFormatter: Serialize a LogRecord according to a specific
schema. Could copy the schema from JSR047's XMLFormatter or
log4j's XMLAppender.
- HTMLFormatter: Provide a simple HTML output of log
information. (See log4j's HTMLAppender.)
Filters
A Filter can be called by a Logger or Handler to decide if a
LogRecord should be logged.
JSR047 and log4j have slightly different filtering interfaces. The
former is simpler:
class Filter:
def isLoggable(self):
"""Return a boolean."""
The latter is modeled after Linux's ipchains (where Filter's can
be chained with each filter either 'DENY'ing, 'ACCEPT'ing, or
being 'NEUTRAL' on each check). I would probably favor to former
because it is simpler and I don't immediate see the need for the
latter.
No filter implementations are currently proposed (other that the
do nothing base class) because I don't have enough experience to
know what kinds of filters would be common. Users can always
subclass Filter for their own purposes. Log4j includes a few
filters that might be interesting.
Configuration
Note: Configuration for the proposed logging system is currently
under-specified.
The main benefit of a logging system like this is that one can
control how much and what logging output one gets from an
application without changing that application's source code.
Log4j and Syslog provide for configuration via an external XML
file. Log4j and JSR047 provide for configuration via Java
properties (similar to -D #define's to a C/C++ compiler). All
three provide for configuration via API calls.
Configuration includes the following:
- What logging level a logger should be interested in.
- What handlers should be attached to which loggers.
- What filters should be attached to which handlers and loggers.
- Specifying attributes specific to certain Handlers and Filters.
- Defining the default configuration.
- XXX Add others.
In general each application will have its own requirements for how
a user may configure logging output. One application
(e.g. distutils) may want to control logging levels via
'-q,--quiet,-v,--verbose' options to setup.py. Zope may want to
configure logging via certain environment variables
(e.g. 'STUPID_LOG_FILE' :). Komodo may want to configure logging
via its preferences system.
This PEP proposes to clearly document the API for configuring each
of the above listed configurable elements and to define a
reasonable default configuration. This PEP does not propose to
define a general XML or .ini file configuration schema and the
backend to parse it.
It might, however, be worthwhile to define an abstraction of the
configuration API to allow the expressiveness of Syslog
configuration. Greg Wilson made this argument:
In Protomatter [Syslog], you configure by saying "give me
everything that matches these channel+level combinations",
such as "server.error" and "database.*". The log4j "configure
by inheritance" model, on the other hand, is very clever, but
hard for non-programmers to manage without a GUI that
essentially reduces it to Protomatter's.
Case Scenarios
This section presents a few usage scenarios which will be used to
help decide how best to specify the logging API.
(1) A short simple script.
This script does not have many lines. It does not heavily use
any third party modules (i.e. the only code doing any logging
would be the main script). Only one logging channel is really
needed and thus, the channel name is unnecessary. The user
doesn't want to bother with logging system configuration much.
(2) Medium sized app with C extension module.
Includes a few Python modules and a main script. Employs,
perhaps, a few logging channels. Includes a C extension
module which might want to make logging calls as well.
(3) Distutils.
A large number of Python packages/modules. Perhaps (but not
necessarily) a number of logging channels are used.
Specifically needs to facilitate the controlling verbosity
levels via simple command line options to 'setup.py'.
(4) Large, possibly multi-language, app. E.g. Zope or (my
experience) Komodo.
(I don't expect this logging system to deal with any
cross-language issues but it is something to think about.)
Many channels are used. Many developers involved. People
providing user support are possibly not the same people who
developed the application. Users should be able to generate
log files (i.e. configure logging) while reproducing a bug to
send back to developers.
Implementation
XXX Details to follow consensus that this proposal is a good idea.
What Logging Levels?
The following are the logging levels defined by the systems I looked at:
- log4j: DEBUG, INFO, WARN, ERROR, FATAL
- syslog: DEBUG, INFO, WARNING, ERROR, FATAL
- JSR047: FINEST, FINER, FINE, CONFIG, INFO, WARNING, SEVERE
- zLOG (used by Zope):
TRACE=-300 -- Trace messages
DEBUG=-200 -- Debugging messages
BLATHER=-100 -- Somebody shut this app up.
INFO=0 -- For things like startup and shutdown.
PROBLEM=100 -- This isn't causing any immediate problems, but
deserves attention.
WARNING=100 -- A wishy-washy alias for PROBLEM.
ERROR=200 -- This is going to have adverse effects.
PANIC=300 -- We're dead!
- mx.Log:
SYSTEM_DEBUG
SYSTEM_INFO
SYSTEM_UNIMPORTANT
SYSTEM_MESSAGE
SYSTEM_WARNING
SYSTEM_IMPORTANT
SYSTEM_CANCEL
SYSTEM_ERROR
SYSTEM_PANIC
SYSTEM_FATAL
The current proposal is to copy log4j. XXX I suppose I could see
adding zLOG's "TRACE" level, but I am not sure of the usefulness
of others.
Static Logging Methods (as per Syslog)?
Both zLOG and Syslog provide module-level logging functions rather
(or in addition to) logging methods on a created Logger object.
XXX Is this something that is deemed worth including?
Pros:
- It would make the simplest case shorter:
import logging
logging.error("Something is wrong")
instead of
import logging
log = logging.getLogger("")
log.error("Something is wrong")
Cons:
- It provides more than one way to do it.
- It encourages logging without a channel name, because this
mechanism would likely be implemented by implicitly logging
on the root (and nameless) logger of the hierarchy.
References
[1] java.util.logging
http://java.sun.com/j2se/1.4/docs/guide/util/logging/
[2] log4j: a Java logging package
http://jakarta.apache.org/log4j/docs/index.html
[3] Protomatter's Syslog
http://protomatter.sourceforge.net/1.1.6/index.html
http://protomatter.sourceforge.net/1.1.6/javadoc/com/protomatter/syslog/syslog-whitepaper.html
[4] MAL mentions his mx.Log logging module:
http://mail.python.org/pipermail/python-dev/2002-February/019767.html
[5] Jeff Bauer's Mr. Creosote
http://starship.python.net/crew/jbauer/creosote/
Copyright
This document has been placed in the public domain.
Local Variables:
mode: indented-text
indent-tabs-mode: nil
fill-column: 70
End:
--
Trent Mick
TrentM at ActiveState.com
More information about the Python-list
mailing list