Logging

Why not print

print has one volume and one destination. Logging lets you leave the detail in place and decide later how much to show, and where to send it.

Python

import logging

logging.basicConfig(level=logging.INFO, format="%(levelname)s %(message)s")
log = logging.getLogger("demo")

log.debug("only useful when hunting a bug")
log.info("the program is doing something")
log.warning("something looks odd")
log.error("something failed")

Output

INFO the program is doing something
WARNING something looks odd
ERROR something failed

The debug line was written and not shown. Change one number and it appears, with no edit to the code that logs it.

The five levels

Level	Use it for
`DEBUG`	detail for diagnosing a problem
`INFO`	the program is doing what it should
`WARNING`	something unexpected, but it carried on
`ERROR`	an operation failed
`CRITICAL`	the program cannot continue

Setting a level shows that level and everything above it:

Python

import logging

logging.basicConfig(level=logging.WARNING, format="%(levelname)s %(message)s", force=True)
log = logging.getLogger("demo")

log.info("not shown")
log.warning("shown")
log.critical("also shown")

Output

WARNING shown
CRITICAL also shown

force=True lets basicConfig reconfigure; without it, a second call is ignored.

Pass the values, do not format them

Python

import logging

logging.basicConfig(level=logging.INFO, format="%(message)s", force=True)
log = logging.getLogger("demo")

name = "Ada"
count = 3

log.info("loaded %s with %d items", name, count)

Output

loaded Ada with 3 items

Writing log.info(f"loaded {name}") builds the string whether or not it will be shown. Passing the arguments means the formatting only happens if the message actually gets emitted — which matters for debug inside a loop.

Logging an exception

Python

import logging
import io

captured = io.StringIO()
logging.basicConfig(level=logging.ERROR, format="%(levelname)s %(message)s",
                    stream=captured, force=True)
log = logging.getLogger("demo")

try:
    int("abc")
except ValueError:
    log.exception("could not parse the value")

written = captured.getvalue()
print(written.splitlines()[0])
print("Traceback" in written)
print("ValueError" in written)

Output

ERROR could not parse the value
True
True

log.exception is log.error plus the traceback, and it only works inside an except block. It is the single most useful call in the module.

A useful format

Python

import logging
import io

captured = io.StringIO()
logging.basicConfig(
    level=logging.INFO,
    format="%(asctime)s %(levelname)-8s %(name)s: %(message)s",
    datefmt="%H:%M:%S",
    stream=captured,
    force=True,
)
logging.getLogger("app.database").info("connected")

line = captured.getvalue().strip()
print(line.split()[1:])
print(len(line.split()[0]) == len("12:34:56"))

Output

['INFO', 'app.database:', 'connected']
True

The time is real, so the example checks its shape rather than printing it. Note the log went to captured here; by default it goes to stderr, which is deliberate — your data goes to stdout and your diagnostics do not pollute it.

One logger per module

Python

import logging

logging.basicConfig(level=logging.INFO, format="%(name)s: %(message)s", force=True)

db = logging.getLogger("app.database")
api = logging.getLogger("app.api")

db.info("connected")
api.info("listening")

logging.getLogger("app.database").setLevel(logging.WARNING)
db.info("not shown any more")
api.info("still shown")

Output

app.database: connected
app.api: listening
app.api: still shown

The convention is logging.getLogger(__name__) at the top of each module. The dots make a hierarchy, so you can silence one noisy component without touching the rest.

Writing to a file

Python

import logging

logging.basicConfig(
    filename="app.log",
    level=logging.INFO,
    format="%(levelname)s %(message)s",
    force=True,
)
logging.getLogger("demo").info("written to the file")
logging.shutdown()

with open("app.log", encoding="utf-8") as f:
    print(f.read().strip())

Output

INFO written to the file

For a real application, logging.handlers.RotatingFileHandler caps the size and keeps a few old files, so a long-running program cannot fill the disk.

Why not print

The five levels

Pass the values, do not format them

Logging an exception

A useful format

One logger per module

Writing to a file

Test yourself

Why write log.info("loaded %s", name) rather than an f-string?

What does log.exception() add over log.error()?

Command-line Arguments