[Python-Dev] Is Barry receiving email at barry@zope.com? PEP number please.
Trent Mick
trentm@ActiveState.com
Thu, 14 Feb 2002 14:58:12 -0800
Barry,
Could I have a PEP number for my logging system proposal please?
Here is what I have put together so far.
Others,
Feel free to send me comments on this if you like. I will official post a
request for comment when I get a PEP number for it.
Trent
------------------------------------------------------------------------------
PEP: XXX
Title: A Logging System
Version: $Revision$
Last-Modified: $Date$
Author: trentm@activestate.com (Trent Mick)
Python-Version: 2.3
Status: Draft
Type: Standards Track
Created: 4-Feb-2002
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); and
(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 subnamespaces. 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
comparsion 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 desireable 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.
- SMTPHandler: Akin to log4j's SMTPAppender.
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 an
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@ActiveState.com