python-peps/pep-0282.txt

PEP: 282
Title: A Logging System
Version: $Revision$
Last-Modified: $Date$
Author: vinay_sajip@red-dove.com (Vinay Sajip)
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: