A new way to configure Python logging

[Wolodja Wentland]

On Sat, Oct 24, 2009 at 07:54 +0000, Vinay Sajip wrote:
> Wolodja Wentland <wentland <at> cl.uni-heidelberg.de> writes:
[snip]
> >     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. 
OK, thanks for pointing that out!

[snip]
> > 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?
Exactly. I used that particular level for logging within a unit test
framework for messages about performance related tests. Combined with a
Handler that generated HTML files from the LogRecord queue using various
templates (make, jinja, ...) it became a nice way to create nice looking
test reports.

Could a HTMLHandler be added to the standard set? Preferably one that
leaves the choice of the template engine to the user.

> > Application User Interface
> [snip]
> All of this sounds quite reasonable.
 Great :-)
>  
> > 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.
Yes, but that could be made easier. (see below)

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

Exactly. The Handlers will usually employ elaborate filtering, so they
can be "plugged together" easily:

    - User wants html? Ah, just add the HTMLHandler to the root logger
    - User wants verbose output? Ah, just add the VerboseHandler to ...
    - ...

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

Guess I never had the need for that. 

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

Which is exactly what I do and I think that it fits my particular
mindset. I see the root handler basically as a multiplexer that feeds
LogRecords to various various co-routines (ie handlers) that decide what
to do with them. I like working on the complete set of LogRecords
accumulated from different parts of the application. The
handler/filter/... naming convention is just a more verbose/spelled out
way of defining different parts of the pipeline that the developer might
want to use. I guess I would welcome general purpose hook for each edge
in the logger tree and in particular one hook feeding different
co-routines at the root logger.

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

I was thinking along the line of ConfigParser.read([file1, file2, ...]),
so that you could have:

--- /etc/foo/logging.conf ---
...
formatters:
  default:
    format: '%(asctime)s %(levelname)-8s %(name)-15s %(message)s'
    datefmt: '%Y-%m-%d %H:%M:%S'
...
--- snip ---

and:

--- ~/.foo/logging.conf ---
formatters:
  # You can adapt the message and date format to your needs here.
  # The following placeholder can be used:
  # asctime    - description
  # ...

  default:
    format: '%(levelname)-8s %(name)-15s %(message)s'
    datefmt: '%Y-%m-%d %H:%M:%S'
--- snip ---

So that if I call:

logging.config.fromFiles(['/etc/foo/logging.conf,
                           os.path.expanduser(
                           '~/.foo/logging.conf')])

The user adaptations will overrule the defaults in the shipped
configuration. I know that I could implement that myself using
{}.update() and the like, but the use case might be common enough to
justify inclusion in the logging module.

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

I will give an example.. The basic problem I have with *all* config file
based configuration right now is that I have to *register* every single
handler/filter with a logger *within* the configuration or their
configuration will be lost.

Assume the following configuration:

--- snip ---
handlers:
  h1: #This is an id
   # configuration of handler with id h1 goes here
  h2: #This is another id
   # configuration of handler with id h2 goes here
loggers:
  foo.bar.baz:
    # other configuration for logger 'foo.bar.baz'
    handlers: []
--- snip ---

In this configuration the handlers will be lost. There is no way to
retrieve he configured handlers later on. (or is there?).

What I would like to do is:

--- snip ---
...
if options.user_wants_h1:
  try:
      someLogger.addHandler(logging.getConfiguredHandler('h1'))
  except HandlerNotFound as handler_err:
    # handle exception

if options.user_wants_h2:
  try:
      someLogger.addHandler(logging.getConfiguredHandler('h2'))
  except HandlerNotFound as handler_err:
    # handle exception
--- snip ---

... same for loggers, filters, etc.

That would enable me to:

* Create a comprehensive logging building block configuration in its
  entirety in a nice configuration format. (ie. config file)

* Easily combine these blocks programmatically

In a way I see three members to the party in the development/usage of
logging:

* Logging Expert

 Will design the logging system for an application/library. Knows the
 requirements and will be able to design different parts of the system.
 She will then tell another developer (see below) which blocks are
 available.

* Developer

  A person that knows about the blocks and combines them
  programmatically, designs the user interface and complains about
  bugs/new requirements in/for the logging system to the "Logging
  Expert".

* User

  A user gets exposed to different ways in which to change the logging
  system:

  - command line options (switches to turn whole blocks off/on)
  - configuration files

    These *may* a subset of the configuration options that the developer
    wants to expose to the user (format, dateformat, ...)
    (see above)

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

Thanks for that link! I will certainly investigate that library.

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

Which is one point I like about PEP 391. Just wanted to give some
feedback :-) . You can basically write everything yourself, it is just
that I think that a usage pattern that is frequently implemented on top
of a stdlib should be eventually incorporated into said library.

have a nice day

    Wolodja
-------------- 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/20091024/923892be/attachment.sig>