[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

Could I have a PEP number for my logging system proposal please?
Here is what I have put together so far.

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.


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


    This PEP describes a proposed logging package for Python's standard

    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.


    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.


    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")
        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.

    The logging levels, in increasing order of importance, are:
    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.


    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 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

    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.


    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
    - HTMLFormatter: Provide a simple HTML output of log information. (See
      log4j's HTMLAppender.)


    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


    Note: Configuration for the proposed logging system is currently

    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)
        (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.


    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:
    - 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:

    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?

        - 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")

        - 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.


    [1] java.util.logging

    [2] log4j: a Java logging package

    [3] Protomatter's Syslog

    [4] MAL mentions his mx.Log logging module:

    [5] Jeff Bauer's Mr. Creosote


    This document has been placed in the public domain.

Local Variables:
mode: indented-text
indent-tabs-mode: nil
fill-column: 70

Trent Mick