Proposed changes to logging defaults

[Vinay Sajip]

Some changes are being proposed to how logging works in default
configurations.

Briefly - when a logging event occurs which needs to be output to some
log, the behaviour of the logging package when no explicit logging
configuration is provided will change, most likely to log those events
to sys.stderr with a default format.

Since this proposed change to behaviour is backwards-incompatible (and
scheduled to come in to Python 3.2 - earlier Pythons, including 2.X,
are unaffected), you may be interested in seeing if the changes affect
you. More details are available here:

http://plumberjack.blogspot.com/2010/12/proposed-changes-to-logging-defaults.html

Please feel free to add comments to the linked blog post.

Regards,

Vinay Sajip

 

[Ethan Furman]

Some changes are being proposed to how logging works in default
configurations.

I like the changes proposed.

Question about the "handler of last resort": is there only one of them,
or will each library have its own so it can decide what the minimum
severity should be for itself?

(My apologies if this question only reveals my own ignorance.)

~Ethan~

 

[Vinay Sajip]

I like the changes proposed.

Question about the "handler of last resort":  is there only one of them,
or will each library have its own so it can decide what the minimum
severity should be for itself?

Libraries decide their severities differently, by setting a level on
their top level logger. There's only one handler of last resort (else
it wouldn't be a last resort). Generally, application developers
determine the level for each logger they're interested; if no explicit
levels are set, the default is the level of the root logger (WARNING
by default).

Thanks for the feedback,

Vinay Sajip

 

[Jean-Michel Pichavant]

Some changes are being proposed to how logging works in default
configurations.

Briefly - when a logging event occurs which needs to be output to some
log, the behaviour of the logging package when no explicit logging
configuration is provided will change, most likely to log those events
to sys.stderr with a default format.

Since this proposed change to behaviour is backwards-incompatible (and
scheduled to come in to Python 3.2 - earlier Pythons, including 2.X,
are unaffected), you may be interested in seeing if the changes affect
you. More details are available here:

http://plumberjack.blogspot.com/2010/12/proposed-changes-to-logging-defaults.html

Please feel free to add comments to the linked blog post.

Regards,

Vinay Sajip

Why would you log informative messages to stderr ? (debug, info, warning)
How stderr is a better choice than stdout ?

A naive approach would rather send errors to stderr & everything else on
stdout (including warnings ?).

IMO, the StreamHandler(sys.stderr) level should be set to logging.ERROR
by default. Because nobody can answer the question 'is a warning an
error', endless debate, there's a risk to log warnings to stderr.
I also think that if someone did'nt care about configuring the logging
machine for 3rd party libraries, this guy just don't care about those
library warnings.

Last question, if no handler is found, why not simply drop the log
event, doing nothing ? It sounds pretty reasonable and less intrusive.

JM

 

[Antoine Pitrou]

Why would you log informative messages to stderr ? (debug, info, warning)
How stderr is a better choice than stdout ?

By construction really. stderr is initially for errors, but it is
generally used for "out of band" messages such as warnings and various
optional information. stdout is used to output whatever data the user
asked for (which generally isn't errors and warnings). If you redirect
said data to a file, you don't want out of band information to end up
mingled with it.

Regards

Antoine.

 

[Vinay Sajip]

On Dec 10, 10:17 am, Jean-Michel Pichavant <[email protected]>
wrote:

Hi Jean-Michel,

I think Antoine answered your other points, so I'll address the last
one:

Last question, if no handler is found, why not simply drop the log
event, doing nothing ? It sounds pretty reasonable and less intrusive.

That is what happens at the moment if configured for production
(logging.raiseExceptions is False) - nothing happens, and the event is
discarded. For development (logging.raiseExceptions is True), the "No
handlers were found for logger XXX" is printed once, to assist
developers to detect misconfiguration. However, the original logged
event is still discarded.

The original philosophy (when logging was added to Python) was that
logging is an adjunct to the operation of the program using it - the
program should work the same way whether or not logging is configured.
However, the consensus on Python-dev is that the logging package
should do useful work, and not just act as an adjunct, i.e. notify the
user on warning and error conditions by default if no logging
configuration is set up. A program will now work differently depending
on whether logging is configured, but if it is not configured, the
default should be to display warnings and errors, unless explicitly
silenced (as per the Zen of Python).

These two approaches (original vs. proposed) are of course quite
different, and there's no way of satisfying both proponents of both
approaches, nor any easy way of measuring how many of each there are.
The proposed change moves logging closer to the current Python-dev
consensus, and means that messages currently written to sys.stderr by
stdlib modules could be logged instead, with the stdlib maintainers
writing those messages knowing that unless explicitly silenced, those
messages will appear to the user as they would via a
sys.stderr.write(). It will be good if this happens, so that
application writers will have better control over what messages are
displayed (when they need it), by configuring logging.

Remember - no changes to behaviour will occur if this change is
implemented and an application configures logging. It's only the no-
configuration case that will change.

To get the current behaviour after the proposed changes are
implemented, an application developer would have to do
logging.lastResort = None, which is a small price to pay (and more or
less equivalent in difficulty with what users who want verbosity by
default have to do, e.g. call basicConfig().

Regards,

Vinay Sajip

 

[Jean-Michel Pichavant]

On Dec 10, 10:17 am, Jean-Michel Pichavant <[email protected]>
wrote:

Hi Jean-Michel,

I think Antoine answered your other points, so I'll address the last
one:



That is what happens at the moment if configured for production
(logging.raiseExceptions is False) - nothing happens, and the event is
discarded. For development (logging.raiseExceptions is True), the "No
handlers were found for logger XXX" is printed once, to assist
developers to detect misconfiguration. However, the original logged
event is still discarded.

The original philosophy (when logging was added to Python) was that
logging is an adjunct to the operation of the program using it - the
program should work the same way whether or not logging is configured.
However, the consensus on Python-dev is that the logging package
should do useful work, and not just act as an adjunct, i.e. notify the
user on warning and error conditions by default if no logging
configuration is set up. A program will now work differently depending
on whether logging is configured, but if it is not configured, the
default should be to display warnings and errors, unless explicitly
silenced (as per the Zen of Python).

These two approaches (original vs. proposed) are of course quite
different, and there's no way of satisfying both proponents of both
approaches, nor any easy way of measuring how many of each there are.
The proposed change moves logging closer to the current Python-dev
consensus, and means that messages currently written to sys.stderr by
stdlib modules could be logged instead, with the stdlib maintainers
writing those messages knowing that unless explicitly silenced, those
messages will appear to the user as they would via a
sys.stderr.write(). It will be good if this happens, so that
application writers will have better control over what messages are
displayed (when they need it), by configuring logging.

Remember - no changes to behaviour will occur if this change is
implemented and an application configures logging. It's only the no-
configuration case that will change.

To get the current behaviour after the proposed changes are
implemented, an application developer would have to do
logging.lastResort = None, which is a small price to pay (and more or
less equivalent in difficulty with what users who want verbosity by
default have to do, e.g. call basicConfig().

Regards,

Vinay Sajip

Thanks for the explanation.

JM

 

[samwyse]

Some changes are being proposed to how logging works in default
configurations.

Briefly - when a logging event occurs which needs to be output to some
log, the behaviour of the logging package when no explicit logging
configuration is provided will change, most likely to log those events
to sys.stderr with a default format.

I'm in favor of this change. I've long wished that I could just add
lots of warning/error/info logging to a script and have it just work
without having to spend time configuring the logging system.

 

[John Nagle]

Some changes are being proposed to how logging works in default
configurations.

Briefly - when a logging event occurs which needs to be output to some
log, the behaviour of the logging package when no explicit logging
configuration is provided will change, most likely to log those events
to sys.stderr with a default format.

Bad idea.

You're assuming that the logging package has the right to blither
on the default sys.stderr. There are many cases in which it
should not. The program could be running in a web server, and
output would end up in the output HTML. The program could be
running as a subprocess, and the output could end up in the
pipe back to the the parent. "sys.stderr" might be connected
to a dead pipe, and writing to it would then kill the program.

So this change could break existing programs in subtle ways.

John Nagle

 

[Vinay Sajip]

    You're assuming that theloggingpackage has the right to blither
on the default sys.stderr.  There are many cases in which it
should not.  The program could be running in a web server, and
output would end up in the output HTML.  The program could be
running as a subprocess, and the output could end up in the
pipe back to the the parent.  "sys.stderr" might be connected
to a dead pipe, and writing to it would then kill the program.

    So this change could break existing programs in subtle ways.

I'm not assuming anything, and the rationale for the change is
described in detail in the linked-to post. The reason for posting the
link on this list is to give people advance warning of the changes, so
they can see if they're affected and take the appropriate action.

Note that since this change only affects the user who is using Python
3.2 and has not configured logging. Since the necessary configuration
is easy to do, I'm assuming people who might be affected can easily
update their code in time for the 3.2 release.

Regards,

Vinay Sajip

 

[Steve Holden]

I'm not assuming anything, and the rationale for the change is
described in detail in the linked-to post. The reason for posting the
link on this list is to give people advance warning of the changes, so
they can see if they're affected and take the appropriate action.

Note that since this change only affects the user who is using Python
3.2 and has not configured logging. Since the necessary configuration
is easy to do, I'm assuming people who might be affected can easily
update their code in time for the 3.2 release.

I might add that any web server that sends sys.stderr to the HTTP output
stream is not likely to be professionally managed. It's far preferable,
in the general case, to ensure that logging messages do not enter the
stdout-stdin pipelines carrying information between coordinating processes.

If a current task is assuming the prior logging package's behavior and
analysing a process's stdout for messages it arguably needs fixing
anyway, though I agree that breakage of any kind is unfortunate.

regards
Steve

 

[Terry Reedy]

You're assuming that the logging package has the right to blither
on the default sys.stderr.

The Python stdlib *already* assumes that it can write to stderr. Using
logging instead will make it easier for app writers to do something else.

 

[Gregory Ewing]

The Python stdlib *already* assumes that it can write to stderr.

Also ISTM that any program relying on nothing it calls ever
writing to stderr would be rather fragile.