logging documentation is tough for beginners

[quicknir]

Something of a perennial issue that I've seen is that folks:

a) complain that logging is hard to use, hard to configure. Somebody called logging an "advanced" module recently.
b) a lot of real world code gets written not following what most people with even moderate experience consider the most basic of best practices. Namely:
- using logging.warning instead of logger = logging.getLogger(__name__); logger.warning..
- library code behaving like it "owns" the root logger: making changes on the root logger, calling logging.basicConfig, heck even calling logging.warning falls into this category, even though it seems totally innocuous, since it can call basicConfig

Now, I think the logging module is fantastic, and that the documentation is generally excellent, and I don't think it's hard to use. However, when idiomatic usage of logging is not really that difficult, I struggle to understand why there isn't an example of idiomatic, correct usage, right on the very first page, as the first code example that people see (instead of showing logging.warning, which is something that should almost never be used).

It's somewhat hard to tell someone that logging isn't an advanced module, when I say "it's easy, just do logger = logging.getLogger(name) at the top of each file, and then..." but such code is only shown as a block in the "Advanced" section of the tutorial, which itself is a small link off the main page.

I am not suggesting any dramatic change to the overall documentation; but it is a bit dramatic I suppose insofar as I think it's important to change the very first thing that people see when they look at logging. Namely, on that very first screen, I would like to see code blocks like this:

# myapp.py
import logging
import mylib

logger = logging.getLogger(__name__)

def main():
    logging.basicConfig(filename='myapp.log', level=logging.INFO)
    logger.info('Started')
    mylib.do_something()
    logger.info('Finished')

if __name__ == '__main__':
    main()

# mylib.py
import logging
logger = logging.getLogger(__name__)

def do_something():
    logger.debug('Debug message')
    logger.warning('Warning message')

Along with a few accompanying sentences, before or after, explaining the basic ideas here (and yes, it should only take a few sentences), namely:

• most files should only need to create a logger, and then use logger methods, and not have any other interactions.
• main should be the place where logger configuration is handled (generally, and for simple use cases)
• encourage the user to play around with the log levels

In my view, this is all of the starting information you need to start using logging well, at the very start. I use logging quite a lot, but 95% of the time at least, my real world production code still uses logging in this basic way, and it works fantastically. People new to logging often are not going to stick around for 30 minutes and read most of the documentation; let's make sure that if they only read one screen worth of docs on their first visit, it leaves them writing code they'll be happy with later.

I'm happy to submit a PR with a draft of the new first section (and slight removal of duplicated material in the tutorial) if there is some receptiveness to the ideas here.

Linked PRs

• gh-98731: Improvements to the logging documentation #101618
• [3.11] gh-98731: Improvements to the logging documentation (GH-101618) #116733
• [3.12] gh-98731: Improvements to the logging documentation (GH-101618) #116734

[JelleZijlstra]

cc @vsajip for logging

[vsajip]

right on the very first page

Well, but what is that first page? Originally (a long while ago now) the logging docs mixed tutorial and reference documentation, which people found hard to follow - fair enough. It was then split into reference, basic and advanced tutorials and cookbook, which was generally well received. The current scheme sort of follows the Diátaxis framework, though that's by coincidence - I was unaware of the framework when I reorganised the docs. The very beginning of the reference documentation says

Important

This page contains the API reference information. For tutorial information and discussion of more advanced topics, see

and then links to the two tutorials and cookbook.

Also, remember that logging is also used by people who write simple one-off scripts, sometimes in educational settings. It is for those uses that the module-level convenience functions are provided, and this is what leads to that "simplest example" being as it is. For those uses, the examples you give might be seen as "too complicated" by some users. And I have no problems at all with those examples - they're fine - the problem really boils down to, "what kind of user is this documentation page aimed at?", but knowing that any level of user can land on any part of the documentation, which might or might not be specifically aimed at them.

Currently, the core developer discussions around Python documentation in general seem to be going in the direction of Diátaxis, with which logging docs are pretty much in line already. I have no problem with adding more examples at the top of the reference documentation page, but it might be an idea for them to be in summary-detail sections so that the "more complicated" examples are hidden by default. The summaries would be "normal practice for short one-off scripts", "best practice for applications", "best practice for library modules" where the current first example corresponds to the first summary, and the other two would be the examples you give. How does that sound?

[quicknir]

Well, but what is that first page?

In practical terms, I think the first page is wherever the majority of people land when they google "python logging". It may not be fair or make sense, but if we're evaluating things by practical impact, that should be how we regard it. And that page for me and in my overwhelming experience, is https://docs.python.org/3/library/logging.html. When I talk to people and they show me where they looked at docs, what confused them, etc, that page is mentioned more than the tutorial; at least 10x more.

I know on the one hand it seems crazy because the tutorial link is right there and it clearly states what it does. I just know from experience; I didn't click that link the first or second or third time I visited that page, and it doesn't seem like most people do. I learned about logger = logging.getLogger(__name__) from a blog post. Now, obviously, we can only protect people from themselves to a certain degree. But I think it's fair to think in these terms: if people visit the main logging page only, and only read the first screen, and then go write a pile of logging code before they run into a problem that forces them to learn more... what do we want on that first screen?

Also, remember that logging is also used by people who write simple one-off scripts, sometimes in educational settings.

I guess I have a few thought on this. First, the entirety of the benefit of logging.warning() over the much more correct alternative is to just save one line of code. This is a very small savings. If we told people to just use logger = .. from the start, folks writing one file scripts would have no problem just copying that single line, and their lives wouldn't really be any different when writing the single file.

Second, for those same people, their lives will be much better when they started writing multiple files; keep in mind that people are not likely to go back to the logging docs when they transition from single-file to multiple-file programs. They'll check the logging docs once to get started, and again when they need to do something they don't know how to do. In between those two points people may write quite a lot of code, with many files (I find this common in the wild).

Third, while I don't claim that logging is an advanced library, I'm just not sure I see logging as something where a substantial chunk of people landing on that page, are still just writing single file scripts (and would be intimidated by a multi-file example). Logging is all about maintaining records of program execution in "principled, flexible" etc insert more software engineering-y terms ;-). People who are really only writing single file scripts, are probably more concerned with other things (control structures, how to define a class, maybe even how to write a multi-file project!). If it occurs to them to maintain a record of program execution, they may well just print or write to a file. logging libraries basically exist because of larger pieces of software; for one file programs just printing or writing to a file is fine. So I think it's pretty fair for the first logging example to use a two-file example like I have above (which, lets keep in mind, is still very very basic in the grand scheme of things).

I have no problem with adding more examples at the top of the reference documentation page...

I admit I'm not 100% clear on all of what you are suggesting here. But I do think an example similar to what I gave should be first and foremost, uncollapsed. If it is collapsed, and the "one off script" example is not, then I think we are not changing things too much from the present situation, with the same result: folks will stop by, grab that first piece of code (because they're just getting started with logging), see that it works in their short program, and then just keep using it forever.

I guess a lot of this boils down to how much weight is being given to people, not those who are about to write a standalone script, but to people who only understand standalone scripts, i.e. not even beginners, but python novices, who have never imported any code they have written. For anyone who understands putting python code in multiple files, the example I gave is extremely basic, and quick to learn, and it achieves that while still really being fundamentally "the right thing". I think it is a mistake to pessimize the docs for logging specifically, for folks who understand multi-file python, in favor of those who do not.

Should I try to encourage folks who I've had some of these conversations with, to also give experience reports? I think you'll see a lot of the same patterns; a very quick initial visit to the main page, immediately going back to writing code without understanding sufficient basics, etc.

Sorry for writing a book!

[vsajip]

You make some valid points - it's just a judgement call at the end of the day. I've certainly had people on forums complaining as if even one line is too much, which is why I've been wary of making the first example longer. Maybe I've given too much weight to such comments! But I take your points, so please feel free to go ahead and create a PR with your suggested approach.

[vsajip]

(and slight removal of duplicated material in the tutorial)

If you mean stuff in the tutorial duplicates stuff you add in the reference page, then I think some repetition is acceptable across different pages.

[quicknir]

Just commenting here that I have not vanished off the face of the earth :-) I will do this in the coming couple of weeks, just trying to find time.

[vsajip]

No problem. Take your time, and thanks for the update 😄

[vsajip]

Not trying to rush you or anything, but just for my information - are you still planning to do something on this?

[quicknir]

I am planning to, yes. I think towards the end of the month I'll probably have a couple days off work and it'll be easier. Is that a decent timeline or too far out?

[vsajip]

Is that a decent timeline

Yes, IMO.

[vsajip]

@quicknir Did you get a chance to look at this near the end of last month?

[quicknir]

@vsajip Hi, I'm working on it now.

One brief question: is there any reason why logger.debug and logging.debug are both documented, from scratch, essentially? Also, they differ slightly in the kwargs they claim to expect but this is strange because logging.debug as I would have expected seems to just defer to logger.debug. I wanted to add a note in logging.debug and came across this; it seems to make sense to me to just delete most of the docs for logging.debug and note that one should consult logger.debug for the majority of the behavior, and only document the parts that are specific to logging.debug

[quicknir]

A couple more thoughts as I try to wrangle this thing.

In the current version of the docs, only logging.info et al are mentioned prior to the Advanced Section. Even the multi module example in the tutorial, still uses logging.info rather than logger.info (which isn't great, IMHO0. If logger.info et all are introduced earlier, then we have a choice: also introduce logging.info, in which case the difference will need to be explained, or we simply continue using logger.info throughout.

Do you have any thoughts on which of these is preferable in your view? Maybe it seems radical but I would actually advocate for the latter:

1. Less to explain in total.
2. We consistently use the single, idiomatic approach to logging.
3. Some aspects of logging.info et all are actually more complex and we can just avoid explaining those in the tutorials entirely, namely the lazy initialization of basicConfg.

[vsajip]

Hi, I'm working on it now.

👍 Thanks!

is there any reason why logger.debug and logging.debug are both documented, from scratch, essentially?

Not a good one - it makes it more likely that the two versions will get out of sync - as indeed they have done.

it seems to make sense to me to just delete most of the docs for logging.debug and note that one should consult logger.debug for the majority of the behavior

Yes.

and only document the parts that are specific to logging.debug

That is just the call to basicConfig() if there are no handlers on the root logger - the code for logging.debug() is just

    if len(root.handlers) == 0:
        basicConfig()
    root.debug(msg, *args, **kwargs)

and ditto for the other module-level convenience functions.

In the current version of the docs, only logging.info et al are mentioned prior to the Advanced Section. Even the multi module example in the tutorial, still uses logging.info rather than logger.info

Yes, it seems like those examples in the multiple modules section could be better as

# myapp.py
import logging
import mylib

logger = logging.getLogger('myapp')  # names the logger the same as your app

def main():
    logging.basicConfig(filename='myapp.log', level=logging.INFO)
    logger.info('Started')
    mylib.do_something()
    logger.info('Finished')

if __name__ == '__main__':
    main()

and

# mylib.py
import logging

logger = logging.getLogger(__name__)  # names the logger the same as this module

def do_something():
    logger.info('Doing something')

resulting in

INFO:myapp:Started
INFO:mylib:Doing something
INFO:myapp:Finished

and we can then change the bit just below that which starts "Note that for this simple usage pattern, ..." to indicate that the log shows where in the code the events occurred.

and we can just avoid explaining those in the tutorials entirely, namely the lazy initialization of basicConfig.

Well, that's introduced in the second section of the basic tutorial, in the section "Logging to a file":

The call to basicConfig() should come before any calls to debug(), info(), etc. Otherwise, those functions will call basicConfig() for you with the default options. As it’s intended as a one-off simple configuration facility, only the first call will actually do anything: subsequent calls are effectively no-ops.

That doesn't seem unreasonable as is, though it could be improved:

• Qualify the debug() and info() to make it clear we're talking about the module-level functions
• Put it in a :note: section to make it stand out a bit more

[vsajip]

Any progress on this, @quicknir ? Or any idea of a timeframe when you might have time to progress it?

[quicknir]

Yes, plan to look at it this coming week. Sorry for all the delays, had a bevy of unexpected person issues.

[quicknir]

@vsajip I'm sure it's very rough around the edges but I finally put together a PR: #101618. I thought it would be helpful to have something concrete even if I have no doubt there's room to polish it (also, I didn't want to go too far down the polishing route without mostly agreeing on the basic ideas).

Not sure whether it's customary to continue the discussion here or on the PR directly but please ping me from whichever and I'll try to answer questions and keep discussing; cheers.

[quicknir]

Also, I started this thread by mentioning the kinds of conversations I saw about logging and logging docs "in the wild". Since I stumbled on a fresh conversation of this nature, I thought I'd link it https://www.reddit.com/r/Python/comments/10x421b/a_comprehensive_guide_to_logging_in_python/.

[vsajip]

Sure, but one of the very vocal posters on that thread just has opinions which differ from choices made in stdlib logging (e.g. they seem to think the default level should be DEBUG, and the fact that only WARNING or higher messages are shown is ascribed to "the compexity of the design" rather than just the choice of default level) and use that to say things like "the biggest mistake here is using python standard library logging in the first place".

While I completely agree with the thrust of your argument and look forward to your concrete suggestions, there will always be a number of people who just don't "get it" and will have difficulty understanding the documentation no matter what you do and how accessible you try to make it. Unfortunately, some of them are very vocal with their emotive criticisms ("stinks of Java") and it's just one of those things that any opinion, no matter how misguided, will have a little community of true believers on the Internet ☹️

[quicknir]

@vsajip My apologies, I should not have posted the link without comment. Yeah, there's one dude there that's clearly too much and too unkind and there's little point engaging. But there is a general trend where even people who otherwise like logging make comments about the docs, and people observing that they have encountered people using logging.info et al in the wild where it wasn't appropriate, too often.

Re my concrete suggestions, just to clarify I did open that PR, not sure if you looked at it. To be clear: there's absolutely no rush, your comment just made it seem like maybe you weren't aware that I had already put forth concrete suggestions, so wanted to clarify that.

[vsajip]

I haven't had a chance to look at it properly yet, as I am travelling and won't be back to base for another couple of weeks, when I expect to give it my full attention. At the moment my access to Internet is a little patchy (though not too bad) and I have other engagements that I am busy with.

[vsajip]

My return to base may be unavoidably delayed for another couple of weeks. I will take a look at this as soon as I can.

[quicknir]

@vsajip hey, just thought I'd ping and see if you had a chance to look at it

[vsajip]

Sorry, my return was delayed even further and I've had a mountain of stuff to catch up on 😞 I will get to it soon.

[vsajip]

Review completed.