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@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/sysl... [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