A new way to configure Python logging

[Wolodja Wentland]

On Thu, Oct 22, 2009 at 09:25 +0000, Vinay Sajip wrote:

> I need your feedback to make this feature as useful and as easy to use as
> possible. I'm particularly interested in your comments about the dictionary
> layout and how incremental logging configuration should work, but all feedback
> will be gratefully received. Once implemented, the configuration format will
> become subject to backward compatibility constraints and therefore hard to
> change, so get your comments and ideas in now!

First and foremost: A big *THANK YOU* for creating and maintaining the
logging module. I use it in every single piece of software I create and
am very pleased with it.

You asked for feedback on incremental logging and I will just describe
how I use the logging module in an application.

Almost all applications I write consist of a/many script(s) (foo-bar,
foo-baz, ...) and a associated package (foo).

Logger/Level Hierarchy
----------------------

I usually register a logger 'foo' within the application and one logger
for each module in the package, so the resulting logger hierarchy will
look like this:

    foo
     |__bar
     |__baz
     |__newt
        |___witch

I set every loggers log level to DEBUG and use the respective logger in
each module to log messages with different log levels. A look at the
code reveals, that I use log levels in the following way:

* DEBUG - Low level chatter:
    * Called foo.bar.Shrubbery.find()
    * Set foo.newt.Witch.age to 23
    * ...

* INFO - Messages of interest to the user:
    * Read configuration from ~/.foorc
    * Processing Swallow: Unladen

* WARNING - yeah, just that (rarely used)
    * Use of deprecated...

* ERROR:
    * No such file or directory: ...
    * Bravery fail: Sir Robin

Among other levels specific to the application, like PERFORMANCE for
performance related unit tests, ...

And *yes*: I use the logging module to output messages to the user of
which I think she *might* be interested in seeing/saving them.

Application User Interface
--------------------------

I like to give my users great freedom in configuring the application and
its output behaviour. I therefore usually have the following command
line options:

    -q, --quiet     No output at all
    -v, --verbose   More output (Messages with Level >= INFO)
    --debug         All messages

And I like the idea to enable the user to configure logging to the
console and to a log file independently, so I also provide;

   --log-file=FILE          Path of a file logged messages will get saved to
   --log-file-level=LEVEL   Messages with level >= LEVEL will be saved

Sometimes I need special LogRecord handling, for example, if I want to
enable the user to save logs to a html file, for which I write a HTML
Handler and expose the templates (mako, jinja, you-name-it) used for
generating the HTML to the user.

The last facet of the logging system I expose to the user is the format
of the log messages. I usually do this within the applications
configuration file (~/.foorc) in a special section [Logging].

Implementation
--------------

You have rightfully noted in the PEP, that the ConfigParser method
is not really suitable for incremental configuration and I therefore
configure the logging system programmatically.

I create all loggers with except the root (foo) with:

LOG = logging.getLogger(__name__)
LOG.setLevel(logging.DEBUG)

within each module and then register suitable handlers *with the root
logger* to process incoming LogRecords. That means that I usually have a
StreamHandler, a FileHandler among other more specific ones.

The Handlers I register have suitable Filters associated with them,
so that it is easy to just add multiple handlers for various levels to
the root handler without causing LogRecords to get logged multiple
times.

I have *never* had to register any handlers with loggers further down in
the hierarchy. I much rather like to combine suitable Filters and
Handlers at the root logger. But that might just be me and due to my
very restricted needs. What is a use case for that?

The unsuitabililty of the ConfigParser method however is *not* due to the
*format* of the textual logging configuration (ie. ini vs dict) but
rather due to the fact that the logging library does not expose all
aspects of the configuration to the programmer *after* it was configured
with .fileConfig().

Please contradict me if I am wrong here, but there seems to be *no* method 
to change/delete handlers/loggers  once they are configured. Surely I
could temper with logging's internals, but I don't want to do this.

PEP 391
-------

I like PEP 391 a lot. Really! Thanks for it. The configuration format is
very concise and easily readable. I like the idea of decoupling the
object ultimately used for configuring (the dict) from the storage of
that object (pickled, YAML, JSON, ...).

What I dislike is the fact that I will still not be able to use it with
all its potential. If PEP 391 would have already been implemented right
now I would expose the logging configuration to the user in:

    ~/.foo/logging

load the dictionary and *programmatically* change the configuration to
meet the user demands (quiet, verbose, file, ...) stated with command
line options by adding/deleting/changing handlers in the dict before
passing it to dictConfig.

That seems suboptimal. ;-)

What I would *love* to see in the future would be:

* Default logging configuration in a YAML/JSON/... file somewhere in
  {/etc/foo/logging.conf, WindowsFooMagic/logging.conf} which describes
  all loggers/handlers/filters/... that *might* get used by the
  application eventually

* Additionally: The possibility to *override* some parts of the
  configuration in another file (files?). 

* The possibility to enable/disable certain parts of the configuration.

* Access to all parts of the logging infrastructure, so that I can adapt
  already configured parts to my actual needs.

* Easy configuration of a lower *and* upper bound for Handlers, so that
  I can easily add additional (more verbose) Handlers without fear of
  messages getting logged multiple times.

The point of all this is, that the final configuration of the logging
system is unknown until the configuration files *and* the command
line have been parsed and does not change (often) afterwards.

My main idea is to see the configuration files not as the final
configuration of the logging system but rather as a definition of the
building blocks that can be plucked together easily programmatically if
the developer sees the need to do so.

with kind regards

    Wolodja Wentland

Post Scriptum

I just wrote what came to my mind. It might be that I am not aware of
better ways to deal with incremental configuration. And I read PEP 391
for the first time today, so I might have overlooked a lot of points. 

But this is how I do it right now. Please point out anything that might
make my life easier.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 853 bytes
Desc: Digital signature
URL: <http://mail.python.org/pipermail/python-list/attachments/20091023/95261337/attachment.sig>