Structured Logging in Python: A Practical Guide

Most Python projects start with print() statements scattered wherever something seemed worth watching, and that is a reasonable way to begin. The trouble shows up later, when a script that used to run once now runs on a schedule, or a small intake tool starts handling requests from more than one source at once. At that point the question stops being "did this run" and becomes "which request failed, when, and why" — and free-form text cannot answer that reliably. Structured logging is the practice of emitting log events as key-value data, usually JSON, instead of a sentence a person has to parse by eye.

Why plain-text logs stop scaling first

A line like print(f"Processing load {load_id} for carrier {carrier}") is fine until two things happen at once. First, the volume grows past what a person will scroll through, and now someone needs to grep for a specific load. That works until the message format changes slightly — an extra word, a reordered field — and the old grep pattern silently stops matching. Second, the code starts running in more than one place: a background worker and a request handler, for example. Now a shared log stream interleaves lines from both, and there is nothing in a free-text line that reliably says which one produced it, short of also embedding that detail in every message by hand and hoping it is never forgotten.

The fix is not to write better sentences. It is to stop writing sentences and start writing records. A structured log line for the same event looks like {"event": "load_processing_started", "load_id": "L-4821", "carrier": "carrier_9", "worker": "intake-2"}. Every field is addressable. A downstream tool — even a simple one, like a Python script reading a log file line by line — can filter on load_id without caring how the message happened to be phrased that day.

A minimal setup with Python's standard logging module

Python's built-in logging module already separates the event (the log record) from its formatting (the handler and formatter), which is most of what structured logging needs. The missing piece is usually the formatter: the default one renders a sentence, not a JSON object.

import logging
import json
import time

class JsonFormatter(logging.Formatter):
    def format(self, record):
        payload = {
            "timestamp": self.formatTime(record, "%Y-%m-%dT%H:%M:%S"),
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
        }
        if hasattr(record, "extra_fields"):
            payload.update(record.extra_fields)
        if record.exc_info:
            payload["exc_info"] = self.formatException(record.exc_info)
        return json.dumps(payload)

logger = logging.getLogger("intake")
handler = logging.StreamHandler()
handler.setFormatter(JsonFormatter())
logger.addHandler(handler)
logger.setLevel(logging.INFO)

Every module gets its own logger with logging.getLogger(__name__), which is what makes the logger field in the output meaningful — it names the specific module that produced the line, not just "the app." The formatter is configured once, near the entry point, and every logger created anywhere in the codebase inherits it through Python's logger hierarchy, so individual modules never need to know or care that their output ends up as JSON.

Attaching context without repeating yourself

The part that actually makes structured logs useful is consistent context: the same identifying fields on every line related to one unit of work, so they can be grouped later. The extra argument to a logging call is the built-in way to attach that context without changing the message string:

logger.info(
    "load processing started",
    extra={"extra_fields": {"load_id": load_id, "carrier": carrier, "worker": worker_name}},
)

Repeating that dictionary on every call inside a function is tedious and easy to get wrong — a copy-pasted extra block that silently drifts from the actual variable names is worse than no context at all, because it looks trustworthy. A LoggerAdapter solves this by binding the shared context once and letting every subsequent call inherit it automatically:

class LoadLogger(logging.LoggerAdapter):
    def process(self, msg, kwargs):
        kwargs.setdefault("extra", {})["extra_fields"] = self.extra
        return msg, kwargs

load_logger = LoadLogger(logger, {"load_id": load_id, "carrier": carrier})
load_logger.info("processing started")
load_logger.info("validation passed")
load_logger.error("carrier lookup failed")

All three lines now carry load_id and carrier without repeating them, and the adapter is created once per unit of work rather than once per log call. This is the same idea as a correlation ID in a distributed system, just scoped to a single script or worker process rather than a network of services.

Choosing what belongs at each level

Structured fields solve the "what" of a log line; log levels solve the "how urgent." A common failure mode is using ERROR for anything that looks bad and INFO for everything else, which makes both levels useless for filtering. A more defensible split: DEBUG for detail only useful while actively investigating something, INFO for normal milestones worth keeping a record of, WARNING for a condition the code recovered from on its own, and ERROR or CRITICAL reserved for failures that need a person's attention. A validation rejection that the code handles gracefully — reject the record, return a clear error — is a WARNING, not an ERROR; reserving ERROR for things that actually need someone to look is what makes an alert on that level meaningful instead of noisy.

Event names benefit from the same discipline that fields do. A short, consistent, past-tense name — load_processing_started, validation_rejected, carrier_lookup_failed — is easy to filter on and easy to keep stable across a refactor, in a way that a hand-written sentence is not. Changing the wording of a sentence to make it read better is a normal, harmless edit; changing the wording of an event name silently breaks every saved filter and every downstream script built on top of it.

What not to log

Structured logs make it easier to search for a field, which cuts both ways: whatever gets logged is now easy to find, including things that should not have been logged at all. Full request bodies, tokens, and anything that looks like a credential should never land in a log line — not because structured logging causes the problem, but because it makes an existing leak more discoverable. A practical habit is to log identifiers and outcomes (load_id, status, duration_ms) rather than the payload itself, matching the same instinct behind the secret-detection rule work, where the goal was catching a credential shape before it left the repository at all.

Reading the logs back

The payoff of structured logging shows up when something goes wrong and the logs need to answer a specific question. With JSON lines, that is a script, not an archaeology project:

import json

failed_loads = []
with open("intake.log") as f:
    for line in f:
        record = json.loads(line)
        if record.get("level") == "ERROR" and "load_id" in record:
            failed_loads.append(record["load_id"])

print(f"{len(failed_loads)} loads failed: {failed_loads}")

That loop is trivial to write precisely because every line is a predictable, addressable record rather than a sentence whose shape might have changed six commits ago. The format was designed for a machine to read from the start, which is the whole point.

A short checklist

Is every log line a record with named fields, not a formatted sentence?
Does each module use its own named logger (logging.getLogger(__name__)) rather than the root logger?
Is shared context (an ID, a worker name) attached once per unit of work instead of repeated per call?
Does the level of each call reflect whether a person needs to act, not just whether the news is bad?
Has every log statement been checked against what it would expose if it were ever read by the wrong person?

This pairs naturally with the third-party API failure modes covered separately — a retry loop or a timeout is only debuggable after the fact if the attempt, the failure, and the eventual outcome were all logged with enough shared context to reconstruct the sequence. It is also the same instinct behind the idempotency-key pattern: both are ways of making a system's behavior legible after something has already gone wrong, instead of only when it is being watched live.