Logging — why print() doesn't scale, and how the logging module actually works
print() has no levels, no timestamps, no way to turn it off in production without deleting code, and no way to route it anywhere but stdout. The logging module solves all four — and its one genuinely confusing part is how logger hierarchy and propagation actually work.
4 min read
Why print() stops being enough
print("Starting job")
print(f"Processing item {item_id}")
print(f"ERROR: failed to process {item_id}: {error}")This works fine for a small script, but breaks down fast in anything larger: there's no way to distinguish a routine status message from an actual error except by reading the text, no timestamp, no way to say "show me warnings and above, but not routine info" without deleting print calls, and no way to send output to a file and the console and an external monitoring service without hand-rolling it. The logging module (standard library, no install needed) solves exactly this set of problems.
The five levels, and why they exist
import logging
logger = logging.getLogger(__name__)
logger.debug("Cache lookup for key=%s", key) # fine-grained, dev-only detail
logger.info("Job started for user_id=%s", user_id) # routine, expected events
logger.warning("Retry #%d for %s", attempt, url) # unexpected, but handled
logger.error("Failed to process order %s: %s", order_id, err) # a real failure
logger.critical("Database connection pool exhausted") # the whole app is in troubleLevels exist so the same code can be run with different verbosity in different contexts — DEBUG and INFO during local development, WARNING and above in production — without touching a single log call, by changing the logger's configured level in one place. Note the %s-style placeholders passed as separate arguments rather than an f-string: logging only formats the message string if the level is actually enabled, so logger.debug("...", expensive_value) skips the string-building work entirely when DEBUG is disabled — an f-string version would build the string every time regardless, whether or not it ever gets logged.
logging.getLogger(__name__): one logger per module, by convention
# inside payments/stripe_client.py
logger = logging.getLogger(__name__) # __name__ is "payments.stripe_client"__name__ is a built-in variable holding the current module's dotted import path — using it to name the logger is the standard convention, because it means every log line can be traced back to exactly which module produced it, and because it builds a hierarchy for free: a logger named "payments.stripe_client" is automatically a child of "payments", which is a child of the unnamed root logger. Loggers are almost never instantiated by hand with an arbitrary string — getLogger(__name__) at the top of every module is the pattern used everywhere in practice.
Handlers and formatters: where logs go, and what they look like
handler = logging.StreamHandler() # sends output to the console
handler.setFormatter(logging.Formatter(
"%(asctime)s %(levelname)s %(name)s: %(message)s"
))
logger.addHandler(handler)
logger.setLevel(logging.INFO)A logger decides whether a message is worth recording at all (based on its level); a handler decides where the message goes once accepted — StreamHandler for console output, FileHandler for a file, SMTPHandler for emailing critical errors, and third-party handlers for shipping logs to external services. A formatter controls the actual text layout — timestamp, level name, logger name, the message itself. A single logger can have multiple handlers attached at once, each with its own level and formatter — e.g. INFO and above to the console, but ERROR and above additionally emailed.
Propagation: why a child logger's messages can appear twice
root_handler = logging.StreamHandler()
logging.getLogger().addHandler(root_handler) # attached to the ROOT logger
child = logging.getLogger("payments.stripe_client")
child.addHandler(logging.StreamHandler()) # ALSO attached directly to the child
child.info("charge succeeded") # prints TWICE — once via its own handler,
# once via propagation up to the root's handlerBy default, a log record processed by a child logger doesn't stop there — it also propagates up to every ancestor logger's handlers, all the way to the root. This is deliberate (it's what lets one root-level handler capture output from every module in an app without configuring each one individually), but it's also the single most common logging surprise: attaching a handler directly to a child logger and having a handler on the root produces duplicate output, since the record is processed by both. Setting logger.propagate = False on the child stops it from bubbling further up, when that's genuinely the intent.
Further reading
Check your understanding
A quick comprehension check — not tracked, not graded, just for you.
1. Why does `logger.debug("...", expensive_value)` avoid building the log message when DEBUG is disabled?
2. Why is `logging.getLogger(__name__)` the standard convention?
3. What is a handler's job, as distinct from a logger's?
4. Why might a child logger's message appear twice in the console?