[Python-Dev] Using logging in the stdlib and its unit tests

[Vinay Sajip]

Antoine Pitrou <solipsis <at> pitrou.net> writes:

> 
> I thought "error" and "critical" messages were logged to stderr by
> default? Isn't it the case?
> 

Only if you call basicConfig() or use the logging.debug(), logging.info(), etc.
module-level convenience functions (which call basicConfig under the hood).

> If any library defining a logger must also add a NullHandler just in
> case, ISTM that complicates a lot the use of logging (and could explain
> its impopularity). Both for library writers and application writers,
> apparently (since the former will have to add the NullHandler, and the
> latter will have to override it so that error messages get printed out
> rather than lost).
> 

No - the application developer doesn't have to do anything special. Adding the
NullHandler is only needed for the top-level logger of a library package, so
it's hardly more onerous than doing an import. It doesn't complicate anything,
as far as I can see. It's to be done once per library, and trivial in comparison
with all the work needed to develop, test, and package a library. For the
stdlib, for example, if we were to standardize and say that all stdlib loggers
were to be located below the "py" namespace, then I could put the relevant
NullHandler-adding code in the logging package and no other stdlib maintainer
would have to do anything other than name their stdlib loggers beginning with
"py." (e.g. "py.concurrent.futures") for things to work as expected. If you
don't like "py", then pick "std", "stdlib" or whatever.

When is the NullHandler needed? Only for cases where an application developer
uses a library which does logging under the covers (for those users who might be
interested in logging its operations), but where that application developer
doesn't use logging themselves for that application. In such a case, a library
call which generated a logging event would cause logging to look for handlers,
and if one is not found, print that one-off "no handlers could be found for
logger XXX" message. This message is there because errors should not pass
silently; but in the case of an application developer oblivious of logging who
uses a library which uses logging under the hood, you can't argue that that
developer has made any error. So the library developer, by adding a NullHandler,
can improve things for their users by not forcing them to configure logging
handlers (in order to avoid the message).

#mylib.py
import logging

logger = logging.getLogger(__name__)
logger.addHandler(logging.NullHandler())

def func():
    logger.warning('Something happened!')

#myapp.py
import mylib

mylib.func()

If you run myapp.py, no message is printed. If you comment out the "addHandler"
line and re-run, then you see

No handlers could be found for logger "mylib"

which is the misconfiguration message. With the line commented back in, you as
an application developer get expected behaviour (no spurious messages about
missing handlers). When you decide to use logging in myapp.py, simply insert 

import logging

logging.basicConfig()

before calling mylib.func(), and you get

WARNING:mylib:Something happened!

which is what you would expect.

Regards,

Vinay Sajip