Back to Notes

Python Logging

Python's built-in logging module is the production standard. print() in production code has no severity levels, no structured output, and can't be selectively disabled without editing source — logging solves all three.

Log Levels

LevelValueUse
DEBUG10Detailed diagnostic detail, dev-only noise
INFO20Confirming normal expected operation
WARNING30Something unexpected, but the system is still functioning
ERROR40A real failure — an operation didn't complete
CRITICAL50The program itself may not be able to continue

Default level is WARNINGDEBUG/INFO calls are silently suppressed unless explicitly configured, which is why "I added a log line but nothing showed up" is almost always a level-configuration issue, not a bug in the log call itself.

Basic Setup

import logging

logging.basicConfig(
    level=logging.DEBUG,
    format="%(asctime)s - %(name)s - %(levelname)s - %(message)s",
)

logger = logging.getLogger(__name__)   # module-name logger, NOT the root logger directly

logger.debug("Debug message")
logger.info("Server started on port 8080")
logger.warning("Disk usage above 80%%")
logger.error("Failed to connect to database")
logger.critical("Out of memory — shutting down")

Why getLogger(__name__), never the bare root logger, especially in library code: it creates a hierarchical logger named after the module (myapp.db inside myapp/db.py) — this is what lets a consumer of your library selectively configure/silence logging from just your module, without your code ever assuming it owns the whole application's logging configuration.

Logger Hierarchy

Loggers are named with dots forming a tree — app, app.db, app.api — and by default a child logger's records propagate up to its parent's handlers. logger.propagate = False stops this, useful when a submodule needs entirely separate log routing.

Handlers — Where Records Actually Go

logger = logging.getLogger("myapp")
logger.setLevel(logging.DEBUG)          # the logger's own threshold — a message must clear THIS first

console = logging.StreamHandler()
console.setLevel(logging.INFO)          # then each handler can apply its OWN, independent threshold

file_handler = logging.FileHandler("app.log")
file_handler.setLevel(logging.DEBUG)

fmt = logging.Formatter("%(asctime)s [%(levelname)s] %(name)s: %(message)s")
console.setFormatter(fmt)
file_handler.setFormatter(fmt)

logger.addHandler(console)
logger.addHandler(file_handler)

Why two separate level checks (logger-level, then handler-level): this is what lets you log everything down to DEBUG to a file for later investigation, while only surfacing INFO-and-above on the console — one logger, two destinations, two independent verbosity thresholds, without duplicating log calls.

HandlerPurpose
StreamHandlerConsole / stderr
FileHandlerWrite to a single file
RotatingFileHandlerRotate once the file hits a max size
TimedRotatingFileHandlerRotate on a schedule (daily/weekly)
HTTPHandlerShip records to a remote endpoint

Structured (JSON) Logging — Production Necessity

Cloud log aggregators (Datadog, CloudWatch, ELK) parse structured fields, not free-text lines — plain-text logs force those tools to regex-parse messages, which is fragile the moment a message format changes.

import json

class JSONFormatter(logging.Formatter):
    def format(self, record):
        log_data = {
            "time": self.formatTime(record),
            "level": record.levelname,
            "name": record.name,
            "message": record.getMessage(),
        }
        if record.exc_info:
            log_data["exc_info"] = self.formatException(record.exc_info)
        return json.dumps(log_data)

This directly parallels [[API Design Principles]]'s consistent-error-format requirement — a request_id field included in structured logs is what actually lets an engineer correlate a specific failed request across logs, traces, and a user's bug report.

Exception Logging

try:
    result = 1 / 0
except ZeroDivisionError:
    logger.exception("Division failed")   # logs at ERROR + attaches the full traceback automatically
    # equivalent to: logger.error("msg", exc_info=True)

logger.exception() (only valid inside an except block) is strictly better than logger.error() for this case — it's the same call plus automatic traceback capture, and there's no reason to manually pass exc_info=True when the shorthand exists.

Lazy %s-Style Formatting — a Real Performance Detail

logger.debug("val: %s", expensive_to_compute())   # correct — argument only formatted if DEBUG is enabled
logger.debug(f"val: {expensive_to_compute()}")     # wrong — f-string ALWAYS evaluates, even if DEBUG is suppressed

With %s-style lazy formatting, logging only calls str() on the arguments if the log record will actually be emitted at the current level — an f-string argument, in contrast, is evaluated unconditionally before logger.debug() is even called, paying the formatting/computation cost even when the message will be discarded. This is a genuinely non-obvious perf detail worth naming if a hot code path logs at DEBUG with an expensive-to-format argument.

Key Rules (Quick Recall)

  • logging.getLogger(__name__) — never the bare root logger, especially inside library/module code.
  • Set the level on the logger, not just the handler — a handler's threshold can only make output more restrictive than the logger's own level, never less.
  • logger.exception() inside except blocks — automatic traceback, no manual exc_info=True needed.
  • %s-style formatting for lazy evaluation — avoid f-strings for expensive-to-compute log arguments on hot paths.

Interview Drills

  1. A developer adds logger.debug(...) calls but sees nothing in the output. What's the most likely cause? — The logger's (or root's) effective level is above DEBUG by default (WARNING) — DEBUG and INFO calls are silently suppressed until the level is explicitly lowered via setLevel or basicConfig(level=...); this is almost always a configuration gap, not a broken log call.
  2. Why use %s placeholders instead of an f-string inside a logger.debug() call on a hot path?%s-style arguments are only formatted into a string if the record actually gets emitted at the current level; an f-string is evaluated eagerly regardless, paying the (potentially expensive) formatting cost even when the message is discarded because DEBUG is disabled.
  3. Why should library code use logging.getLogger(__name__) instead of configuring and using the root logger directly? — It creates a hierarchical, module-scoped logger that the consuming application can independently configure or silence — a library that logs via the root logger (or configures it globally) imposes its own logging opinions on whatever application imports it, which is a real, avoidable coupling.

Cross-links

[[FastAPI]] · [[API Design Principles]]