A new way to configure Python logging

Vinay Sajip vinay_sajip at yahoo.co.uk
Sat Oct 24 09:54:04 CEST 2009


Wolodja Wentland <wentland <at> cl.uni-heidelberg.de> writes:

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

I'm glad you like it. Thanks for taking the time to write this detailed
post about your usage of logging.

> 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

You only need set foo's level to DEBUG and all of foo.bar, foo.baz etc.
will inherit that level. Setting the level explicitly on each logger is
not necessary, though doing it may improve performance slightly as the
system does not need to search ancecstors for an effective level. Also,
setting the level at just one logger ('foo') makes it easier to turn down
logging verbosity for foo.* by just changing the level in one place.

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

I'm not sure what you mean here - is it that you've defined a custom level
called PERFORMANCE?

> Application User Interface
> --------------------------
> 
[snip]

All of this sounds quite reasonable.
 
> 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.

Since you allow users the ability to control logging from the command-line,
you need to do programmatic configuration anyway.

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

See my earlier comment about setting levels for each logger explicitly. How
do you avoid low-level chatter from all modules being displayed to users? Is
it through the use of Filters?

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

There are times where specific handlers are attached lower down in the
logger hierarchy (e.g. a specific subsystem) to send information to a relevant
audience, e.g. the development or support team for that subsystem. Technically
you can achieve this by attaching everything to the root and then attaching
suitable Filters to those handlers, but it may be easier in some cases to
attach the handlers to a lower-level logger directly, without the need for
Filters.

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

You are right, e.g. the fileConfig() API does not support Filters. There is
also no API to get the current configuration in any form.

There isn't a strong use case for allowing arbitrary changes to the logging
setup using a configuration API. Deletion of loggers is problematic in a 
multi-threaded environment (you can't be sure which threads have a reference
to those loggers), though you can disable individual loggers (as fileConfig
does when called with two successive, disjoint configurations). Also, deleting
handlers is not really necessary since you can change their levels to achieve
much the same effect.

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

That's right - the dict is the lingua franca that all of these formats can
serialize/deserialize from files, sockets etc.

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

I'm not sure exactly what you mean here. The basic approach is that you
specify your default logging configuration in the dict (via YAML, JSON or
other means) and allow overriding levels via command-line, then that would be
OK. Of course if you specify a file destination in the configuration, it's not
obvious how in general you'd override the filename with a value from a
command-line option. But the answer there is to define all other handlers in
the configuration, load the configuration, then add handlers programmatically
based on command-line options specified for a particular run of a script.

> 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

The future is now, in the sense that PEP 391 is not yet implemented and people
can have an input by saying how they would like it to work. You can do that
with PEP 391 implemented as it stands, though your configuration would have to
leave out any handlers which are optionally specified via command-line
arguments.

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

That requirement is too broad to be able to give a one-size-fits-all
implementation.

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

You can do that by changing levels in an incremental call. Can you give more
details about what else you might want to enable/disable?

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

An example to illustrate your point would be helpful.

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

It's easiest to do this using a Filter with an upper bound on the level. I
appreciate that it would be easier to do with an upper bound added to the
Handler itself, but the use case is not that common to warrant such a basic
change in the API.

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

That's true most of the time, though for some long-running server-type
applications the configuration might need to change multiple times over a
long period to change verbosity levels. Of course, some listening mechanism
would need to be in place for the long-running application to register a
request to set new levels.

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

Although I can see how configuration in general can benefit from a building-
block style approach (I developed an alternative hierarchical configuration
system, see http://www.red-dove.com/python_config.html - though that uses its
own JSON-like format and offers some nice features, it's not standard enough
to consider using for the logging package.)

The use of dicts means that users can combine portions of the final dict from
different sources, PEP391 doesn't prescribe exactly how this is done. The dict
presented to dictConfig() must be complete and consistent, but where all the
different bits come from is up to the application developer/system
administrator.

Thanks very much for the feedback,


Vinay Sajip




More information about the Python-list mailing list