[Python-Dev] spice for PEP 282

David Goodger goodger@users.sourceforge.net
Fri, 15 Feb 2002 18:38:04 -0500

Here's some spice for the logger recipe.  Please season to taste.


The dps.utils.Reporter class (http://docstring.sf.net/dps/utils.py)
implements a logger but with *multiple* thresholds per category
(stream/channel).  Similarly to log4j, there's a "warninglevel"
threshold, which determines if a message gets sent to the warning
stream (sys.stderr).  There's also an "errorlevel" threshold which
determines if a message is converted into a *raised exception*,
potentially halting processing.  And a "debug" flag which turns debug
messages on or off independently of the "warninglevel" threshold.  I
suggest that the Python stdlib logging module adopt some of these


I've been working on the DPS & reStructuredText projects (soon to be
merged and officially renamed to "Docutils") on and off for some
months now.  Docutils will parse texts (files or docstrings) into
DOM-like document trees, then convert them to HTML etc.  Early on I
saw the need to insert "system_message" feedback elements of different
levels into the doctree and implemented dps.utils.Reporter.  I
included thresholds for logging to sys.stderr and raising exceptions,
initially with only one setting (like log4j with only the root
"category" set).  This Reporter class has been very successful

As a pointed reminder of how wheels are continually reinvented, I
learned about log4j (just before the python-dev effort got underway; I
probably read the same message that got Guido started).  I already had
4 message levels (what log4j called "logging priorities"), and log4j's
notion of "logging categories" seemed a powerful one, so I retrofitted
the dps.utils.Reporter class with support for categories.  I also
added a "debug" category, which I had been handling separately.

>From the revised PEP 258 (not yet checked in to the Python CVS):

    When the parser encounters an error in markup, it inserts a system
    message (DTD element 'system_message').  There are five levels of
    system messages:

    - Level-0, "DEBUG": an internal reporting issue.  There is no
      effect on the processing.  Level-0 system messages are
      handled separately from the others.

    - Level-1, "INFO": a minor issue that can be ignored.  There is no
      effect on the processing.  Typically level-1 system messages are
      not reported.

    - Level-2, "WARNING": an issue that should be addressed.  If
      ignored, there may be unpredictable problems with the output.

    - Level-3, "ERROR": an error that should be addressed.  If
      ignored, the output will contain errors.

    - Level-4, "SEVERE": a severe error that must be addressed.
      Typically level-4 system messages are turned into exceptions
      which halt processing.  If ignored, the output will contain
      severe errors.

    Although the initial message levels were devised independently,
    they have a strong correspondence to VMS error condition severity
    levels [9]; the names in quotes for levels 1 through 4 were
    borrowed from VMS.  Error handling has since been influenced by
    the log4j project [10].


    [9] http://www.openvms.compaq.com:8000/73final/5841/

    [10] http://jakarta.apache.org/log4j/

Here's the docstring of dps.utils.Reporter:

    Info/warning/error reporter and ``system_message`` element

    Five levels of system messages are defined, along with
    corresponding methods: `debug()`, `info()`, `warning()`,
    `error()`, and `severe()`.

    There is typically one Reporter object per process.  A Reporter
    object is instantiated with thresholds for generating warnings and
    errors (raising exceptions), a switch to turn debug output on or
    off, and an I/O stream for warnings.  These are stored in the
    default reporting category, '' (zero-length string).

    Multiple reporting categories may be set, each with its own
    warning and error thresholds, debugging switch, and warning
    stream.  Categories are hierarchically-named strings that look
    like attribute references: 'spam', 'spam.eggs', 'neeeow.wum.ping'.
    The 'spam' category is the ancestor of 'spam.bacon.eggs'.  Unset
    categories inherit stored values from their closest ancestor
    category that has been set.

    When a system message is generated, the stored values from its
    category (or ancestor if unset) are retrieved.  The system message
    level is compared to the thresholds stored in the category, and a
    warning or error is generated as appropriate.  Debug messages are
    produced iff the stored debug switch is on.  Message output is
    sent to the stored warning stream.

The Point

I submit that the priority/level spectrum is not continuous.  There is
a break between "debug" and "info":


In the Docutils application, and (I think) in general, debug logging
is better treated separately from info/warning/error logging.  Debug
logging is often used by the developer but only rarely used by the
end-user.  However, depending on the type of application,
info/warning/error logging can be useful to the end-user.  Compilers,
parsers, and filters are such applications.

In addition, having a separate threshold for warning output (typical
logging) and error generation (raising exceptions) has been very
useful to the Docutils application, and may be useful in general for a
logging module.

When I run the test suite, I run with warnings and errors turned off
(I get feedback from system_message elements added to the doctree).
Real processing typically runs with "WARNING" and higher generating
warning output, and "SEVERE" (FATAL) raising exceptions.  A "make sure
this input has absolutely no problems whatsoever" run might have
thresholds set lower, so "INFO" is reported and "WARNING" and higher
turn into exceptions.

David Goodger    goodger@users.sourceforge.net    Open-source projects:
 - Python Docstring Processing System: http://docstring.sourceforge.net
 - reStructuredText: http://structuredtext.sourceforge.net
 - The Go Tools Project: http://gotools.sourceforge.net