Logging

print() is perfectly fine while you are prototyping in a notebook. The moment your code runs on a real server, though, you need something with levels you can filter, timestamps you can sort by, and a single switch to quiet the chatty parts and turn up whatever you are debugging right now. That something is the logging module — and once its output is structured JSON flowing into a log aggregator, you have production-grade observability almost for free.

Note: the logged lines below normally begin with a timestamp (%(asctime)s). We leave it out of these examples so the output is identical on every run; in real code you keep it.

What is wrong with print

print("user", user.id, "logged in")

That one line has five problems, roughly in order of how badly they bite. There is no level, so you cannot ask for “errors only” or “be quieter”. There is no timestamp, so real logs cannot be ordered in time. There is no context — which module was this, auth or payments? There is no control — you cannot redirect it to a file or an aggregator without rewriting every call. And there is no structure, so downstream tools cannot read it without regex. Logging fixes all five.

The basics

logging.basicConfig sets things up once at startup; after that you grab a logger and call it by level:

import logging

logging.basicConfig(
    level=logging.INFO,
    format="%(levelname)-7s %(name)s: %(message)s",   # (timestamp omitted for a stable demo)
)
log = logging.getLogger("demo")

log.debug("won't appear — the level is INFO")
log.info("user 42 logged in")
log.warning("disk usage at 87%")
log.error("payment service unreachable")

INFO    demo: user 42 logged in
WARNING demo: disk usage at 87%
ERROR   demo: payment service unreachable

Notice the debug line is simply absent. The five levels, lowest priority to highest, are DEBUG, INFO, WARNING, ERROR, CRITICAL; setting the logger to INFO silences DEBUG and lets everything from INFO up through. Production typically runs at INFO, and you flip a single environment variable to DEBUG while reproducing a problem. One more method worth knowing: inside an except block, log.exception("...") logs at ERROR level and attaches the full traceback — the right call when you have caught something and want the stack with it.

getLogger(name) — the per-module pattern

Every module should open with the same line:

log = logging.getLogger(__name__)

Because __name__ is the module’s dotted path (myapp.payments.stripe), the loggers form a hierarchy, each inheriting configuration from its parents. That is what lets you configure once at the root and then quiet a single noisy submodule without touching its code:

logging.getLogger("myapp.payments").setLevel(logging.WARNING)

The architecture: logger → handler → formatter

The piece that trips people up is that three different objects share the work, and keeping them straight is most of the battle. A logger is what you call (log.info(...)), tagged by name. A handler is where the record goes — the console, a file, syslog, an HTTP endpoint. A formatter is how it looks — plain text, JSON, anything. Crucially, one logger can feed several handlers at once, and each handler has its own formatter and its own level:

Wired up explicitly, that fan-out looks like this — one logger sending INFO-and-up to the console while a file quietly captures everything including DEBUG:

import logging

log = logging.getLogger("demo2")
log.setLevel(logging.DEBUG)
log.handlers.clear()

# Handler 1: console, INFO and up.
console = logging.StreamHandler()
console.setLevel(logging.INFO)
console.setFormatter(logging.Formatter("%(levelname)-7s %(message)s"))

# Handler 2: file, EVERYTHING including DEBUG.
debug_file = logging.FileHandler("/tmp/debug.log", mode="w")
debug_file.setLevel(logging.DEBUG)
debug_file.setFormatter(logging.Formatter("%(name)s %(levelname)s %(message)s"))

log.addHandler(console)
log.addHandler(debug_file)

log.debug("debug — file only")
log.info("info — console AND file")
log.error("error — both")

print("--- /tmp/debug.log ---")
print(open("/tmp/debug.log").read(), end="")

INFO    info — console AND file
ERROR   error — both
--- /tmp/debug.log ---
demo2 DEBUG debug — file only
demo2 INFO info — console AND file
demo2 ERROR error — both

The console never showed the DEBUG line — its handler is set to INFO — but the file captured all three, because each handler filters by its own level. That is the whole point of separating logger from handler.

Configuring from a dict — dictConfig

In real applications you do not wire handlers up by hand; you declare a config dict (often loaded from YAML) and let logging.config.dictConfig build it. This is the shape you will recognise in every Flask, Django, and FastAPI template:

import logging
import logging.config

CONFIG = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "default": {"format": "%(levelname)-7s %(name)s: %(message)s"},
        "json": {"format": '{"level":"%(levelname)s","logger":"%(name)s","msg":"%(message)s"}'},
    },
    "handlers": {
        "console": {"class": "logging.StreamHandler", "formatter": "default", "level": "INFO"},
    },
    "loggers": {
        "myapp": {"handlers": ["console"], "level": "DEBUG", "propagate": False},
        "myapp.noisy": {"level": "WARNING"},     # quiet one submodule
    },
    "root": {"handlers": ["console"], "level": "WARNING"},
}

logging.config.dictConfig(CONFIG)

logging.getLogger("myapp").info("app started")
logging.getLogger("myapp.noisy").info("ignored — noisy is set to WARNING")
logging.getLogger("myapp.noisy").warning("but this gets through")

INFO    myapp: app started
WARNING myapp.noisy: but this gets through

The middle line vanished exactly as configured — myapp.noisy is pinned to WARNING, so its INFO was dropped while its WARNING propagated up to myapp’s console handler. All of that came from data, not code, which is why config-as-a-dict scales.

Structured logging — JSON for aggregators

Production logs flow into Datadog, Splunk, Grafana Loki, CloudWatch, or the like, and those tools index dramatically better when each line is JSON. The standard library can emit JSON through a custom formatter, but the ergonomics are nicer with structlog or loguru:

# loguru — minimal ceremony
from loguru import logger
logger.add("app.log", serialize=True)            # JSON file
logger.info("user logged in", user_id=42, ip="10.0.0.1")

# structlog — more configurable
import structlog
log = structlog.get_logger()
log.info("payment_attempted", user_id=42, amount=99.99, currency="USD")

The idea is to log events with key-value context, not formatted prose. "user logged in user_id=42" is fine for a human to read, but {"event": "user_login", "user_id": 42} is something a machine can query.

Request-scoped context

In a web service you want every line from one request stamped with the same request_id, so that grepping that id reconstructs the request’s entire trail. A logging Filter can inject a field onto every record. Here the ids are fixed so the output is exact; a real service would generate a uuid and scope it per task with contextvars:

import logging

class RequestIdFilter(logging.Filter):
    def __init__(self):
        super().__init__()
        self.request_id = "-"
    def filter(self, record):
        record.request_id = self.request_id
        return True

req_filter = RequestIdFilter()

log = logging.getLogger("svc")
log.handlers.clear()
log.propagate = False
h = logging.StreamHandler()
h.setFormatter(logging.Formatter("%(levelname)-7s [%(request_id)s] %(message)s"))
h.addFilter(req_filter)
log.addHandler(h)
log.setLevel(logging.INFO)

def handle_request(req_id, payload):
    req_filter.request_id = req_id
    log.info("request received")
    log.info(f"processing payload size={len(payload)}")
    log.info("request done")

handle_request("req-001", "hello world")
handle_request("req-002", "another payload")

INFO    [req-001] request received
INFO    [req-001] processing payload size=11
INFO    [req-001] request done
INFO    [req-002] request received
INFO    [req-002] processing payload size=15
INFO    [req-002] request done

Every line within a request carries its own request_id, so debugging becomes “grep for req-002” and you see precisely that request’s story, even with many requests interleaved in the real log.

Never log secrets

log.info(f"user logged in with password={password}")          # never
log.info(f"auth header: {request.headers['Authorization']}")  # never

Logs land in centralised stores that support engineers, SREs, and analysts can all read. A secret in a log line is a secret leaked to fifty places at once. Audit both your log calls and your formatters’ default fields for anything sensitive.

In one breath

• Replace print with logging — it adds levels, timestamps, context, routing, and structure.
• Use logging.getLogger(__name__) per module; the dotted hierarchy lets you tune one module without code changes.
• Logger → Handler → Formatter: one logger, many handlers, each with its own level and format.
• Configure real apps from a dict via logging.config.dictConfig.
• Log structured JSON events with key-value context for queryability — and never log secrets.

Practice

What’s next

You can control how your code reports what it is doing. The next block turns to the structure of the code itself — classes, the building blocks of Python’s object-oriented half.