Python Logging: A Practical Setup for Real Projects

print() is fine while you write a script and watch it run. It stops working the day the script runs unattended: at 3 a.m. from a scheduler, in a container, or as a web service handling hundreds of requests. Then you need to know what happened, when, where in the code, and how bad it was, and you need to adjust how much detail you get without editing code. That is what the standard library's logging module is for.

Four ideas, one picture

• Loggers are what your code calls. Create one per module with logging.getLogger(__name__); the dotted module names form a hierarchy, so shop.orders is a child of shop.
• Levels rank messages: DEBUG, INFO, WARNING, ERROR and CRITICAL. A logger or handler set to WARNING ignores INFO and DEBUG.
• Handlers decide where messages go: the console, a file, a network service.
• Formatters decide what each line looks like.

A message travels up the logger hierarchy to the handlers attached along the way, usually on the root logger, and each handler applies its own level and format (Python docs: logging HOWTO).

import logging
import sys

logging.basicConfig(stream=sys.stdout, level=logging.INFO, format="%(levelname)-8s %(name)s: %(message)s", force=True)

orders = logging.getLogger("shop.orders")
orders.debug("cart contents: %s", ["pen", "pad"])      # below INFO: dropped
orders.info("order %s placed", 1042)
logging.getLogger("shop").setLevel(logging.WARNING)
orders.info("order %s placed", 1043)                   # shop now requires WARNING
orders.warning("stock for %s below threshold", "pen")

INFO     shop.orders: order 1042 placed
WARNING  shop.orders: stock for pen below threshold

Raising the level on shop silenced INFO messages from every module underneath it, with no change to the code that logs. That is the main reason to name loggers after modules.

Which level for what

Production usually runs at INFO; switch a module to DEBUG temporarily when investigating it.

One configuration for a real application

basicConfig suits small scripts. Applications should configure logging once, at startup, from a dictionary with logging.config.dictConfig (Python docs: dictConfig). This one prints readable lines to the console and keeps a detailed, rotating log file:

import logging.config

LOGGING = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "console": {"format": "%(levelname)-8s %(name)s: %(message)s"},
        "file": {"format": "%(asctime)s %(levelname)s %(name)s [%(module)s:%(lineno)d] %(message)s"},
    },
    "handlers": {
        "console": {"class": "logging.StreamHandler", "stream": "ext://sys.stdout",
                    "formatter": "console", "level": "INFO"},
        "file": {"class": "logging.handlers.RotatingFileHandler", "filename": "app.log",
                 "maxBytes": 5_000_000, "backupCount": 5, "encoding": "utf-8",
                 "formatter": "file", "level": "DEBUG"},
    },
    "root": {"handlers": ["console", "file"], "level": "DEBUG"},
    "loggers": {"urllib3": {"level": "WARNING"}},
}

logging.config.dictConfig(LOGGING)
log = logging.getLogger("billing")
log.debug("tax table loaded")                 # file only
log.info("invoice %s generated", "INV-1042")  # console and file
print(open("app.log", encoding="utf-8").read().count("\n"), "lines in app.log")

INFO     billing: invoice INV-1042 generated
2 lines in app.log

The console shows INFO and above; the file captures DEBUG too, with timestamps and the source line, for later investigation. RotatingFileHandler starts a new file at 5 MB and keeps five old ones, so the log can never fill the disk (Python docs: RotatingFileHandler). disable_existing_loggers: False keeps loggers that libraries created before your configuration ran. Turning urllib3 down to WARNING shows how to quieten a chatty library.

Log exceptions with their tracebacks

Inside an except block, log.exception() logs at ERROR level and appends the full traceback:

def charge(amount):
    raise ConnectionError("gateway timeout")

try:
    charge(1499)
except ConnectionError:
    log.exception("payment failed for invoice %s", "INV-1042")
print(open("app.log", encoding="utf-8").read().count("Traceback"), "traceback in app.log")

ERROR    billing: payment failed for invoice INV-1042
Traceback (most recent call last):
  File "...", line ..., in <module>
    charge(1499)
  File "...", line ..., in charge
    raise ConnectionError("gateway timeout")
ConnectionError: gateway timeout
1 traceback in app.log

(File paths and line numbers are elided here.) Log an exception once, where you handle it; logging and re-raising at every layer repeats the same traceback several times. Error handling in Python covers where to catch.

Pass values as arguments, not f-strings

Write log.info("order %s placed", order_id), not log.info(f"order {order_id} placed"). With arguments, the message is only formatted if a handler will actually emit it, and log tools can group all "order %s placed" lines together because the template is the same (Python docs: logging HOWTO).

Add context that every line needs

In services and pipelines, a line is far more useful when it says which request, user or batch it belongs to. LoggerAdapter adds context to every message from one place (Python docs: logging cookbook):

class RequestAdapter(logging.LoggerAdapter):
    def process(self, msg, kwargs):
        return f"[req {self.extra['request_id']}] {msg}", kwargs

req_log = RequestAdapter(logging.getLogger("api"), {"request_id": "7f3a"})
req_log.info("GET /orders returned %d rows", 25)

INFO     api: [req 7f3a] GET /orders returned 25 rows

When logs go to a central system, a JSON formatter that writes fields such as the request ID separately makes them searchable; the same idea applies.

Where logs should go: containers, servers and scheduled jobs

• In containers, log to standard output only and let the platform collect, store and search the stream. Writing files inside a container loses them when it is replaced.
• On a server or a laptop, a rotating file like the one above is simple and survives restarts.
• For scheduled jobs, finish every run with one INFO summary line, such as "processed 480 files, 2 failed, 41 s", and exit with a non-zero status on failure. Whoever checks the job can read one line instead of scrolling.
• Timestamps in UTC avoid confusion when servers and people sit in different time zones. Setting logging.Formatter.converter = time.gmtime makes %(asctime)s use UTC.

What not to log

• Secrets: passwords, API keys, tokens, full card numbers. Log that a key was loaded, never the key; see environment variables and secrets.
• Personal data you do not need: email addresses, phone numbers, addresses. Log an internal ID instead.
• Every loop iteration at INFO. Put per-item detail at DEBUG and a summary line at INFO.

Libraries: do not configure logging

If you write a package that others import, create module loggers as usual but do not call basicConfig or add handlers; the application that uses your library decides where logs go. The logging HOWTO recommends adding only a NullHandler to the library's top-level logger.

Logs are the first thing to check when a scheduled job fails, which is why the automation scripts guide ends with them. Exception handling, debugging and logging basics make up one module of the Python Programming course.

Sources

• Logging HOWTO — Python documentation
• logging.config — dictConfig — Python documentation
• RotatingFileHandler — Python documentation
• Logging Cookbook — Python documentation