Logging Basics - Structured Observability for Python Applications

Reading time: ~18 minutes | Level: Foundation → Engineering

Here is a question that reveals whether you are writing software or writing scripts:

# Option A - what most beginners write
def process_payment(user_id, amount):
    print(f"Processing payment: user={user_id}, amount={amount}")
    # ... business logic ...
    print(f"Payment complete")

# Option B - what production code uses
import logging
logger = logging.getLogger(__name__)

def process_payment(user_id, amount):
    logger.info("Processing payment", extra={"user_id": user_id, "amount": amount})
    # ... business logic ...
    logger.info("Payment complete", extra={"user_id": user_id})

Both print the same information in development. But in production, only Option B gives you:

The ability to filter messages by severity (show only WARNING and above in prod)
The ability to route messages to files, external services, or both simultaneously
The ability to suppress verbose output without touching business logic code
Structured data that log aggregation systems (Datadog, CloudWatch, Splunk) can query
Automatic context: timestamp, module name, line number, log level

The print function was not designed for observability. The logging module was.

What You Will Learn

Why print is inadequate for production systems and what logging solves
The logging hierarchy: Logger, Handler, Formatter, and how they compose
The five log levels and when to use each in real engineering decisions
The logging.getLogger(__name__) pattern and why the name matters
Handler types: StreamHandler, FileHandler, RotatingFileHandler, NullHandler
Formatter syntax and how to build useful log line formats
basicConfig vs explicit configuration vs dictConfig for production
Logger propagation: how child loggers bubble up to the root logger
logger.exception(): capturing full tracebacks inside except blocks
Adding context to logs: LoggerAdapter, the extra dict, and contextvars
Structured JSON logging for log aggregation pipelines
Real-world logging configuration for FastAPI and Django applications

Prerequisites

Python 3.8+ installed
Understanding of Python exceptions and try/except blocks (covered in earlier lessons)
Basic understanding of modules and imports
Some familiarity with dictionaries and configuration concepts

Part 1 - Why `print` Fails at Scale

The Five Problems with `print` Debugging in Production

# This is what print-based "logging" looks like after a few months
def fetch_user(user_id):
    print(f"Fetching user {user_id}")        # DEBUG noise
    user = db.query(user_id)
    if not user:
        print(f"ERROR: User {user_id} not found!")  # How do you filter just errors?
    print(f"Got user: {user}")               # Prints to stdout - where does that go?
    return user

Problem 1 - No severity levels. You cannot tell the difference between a debug trace and a critical error. You cannot suppress debug output in production without deleting code.

Problem 2 - Wrong destination. print writes to stdout. Production systems expect logs on stderr, or in files, or in an external service. Redirecting stdout also redirects legitimate program output.

Problem 3 - No filtering. To silence verbose output, you must delete or comment out print statements - then add them back to debug. This is a code change requiring a deployment.

Problem 4 - No structure. Log aggregation systems (Splunk, Datadog, CloudWatch) need structured data - key-value pairs - to build dashboards and alerts. print(f"user={user_id}") is a string. You cannot query it without regex.

Problem 5 - No context. Which module did this come from? Which line? What time? Print gives you none of this without manual effort.

The logging module solves all five problems.

Part 2 - The Logging Architecture

The Three Core Components

The key design insight: Loggers form a tree. Child loggers propagate records upward to their parent by default. This lets you configure one handler at the root and have all loggers in your application use it.

Part 3 - Log Levels

The Five Standard Levels

import logging

logger = logging.getLogger(__name__)

logger.debug("Entering function with args: %s", args)        # Level 10
logger.info("User logged in successfully")                    # Level 20
logger.warning("Disk usage at 85%% - approaching limit")     # Level 30
logger.error("Database connection failed after 3 retries")   # Level 40
logger.critical("Payment processor is unreachable")          # Level 50

When to Use Each Level - Engineering Decisions

Level	Value	Use When
`DEBUG`	10	Detailed diagnostic information useful during development. Variable values, function entry/exit, loop iteration counts. NEVER enabled in production.
`INFO`	20	Confirmation that things are working as expected. "User logged in", "Payment processed", "Job started". Operational milestones you want to track.
`WARNING`	30	Something unexpected happened but the system can continue. Deprecated API used, disk space low, retry succeeded after failure. Investigate later.
`ERROR`	40	A serious problem - the current operation failed. DB query failed, external API returned 500, file not found. Needs attention, not necessarily immediate.
`CRITICAL`	50	A severe error - the application cannot continue. Cannot connect to database on startup, license expired, payment processor down. Page on-call now.

:::tip The Production Level Rule In development, set level to DEBUG to see everything. In production, set level to WARNING or INFO. A rule of thumb: if a log fires more than once per user request, it should be DEBUG. If it fires once per request, it can be INFO. If it indicates something went wrong, it is at least WARNING. :::

Level Filtering

import logging

logging.basicConfig(level=logging.WARNING)

logger = logging.getLogger("myapp")

logger.debug("This will NOT appear")    # Below WARNING threshold
logger.info("This will NOT appear")     # Below WARNING threshold
logger.warning("This WILL appear")      # At WARNING threshold
logger.error("This WILL appear")        # Above WARNING threshold

WARNING:myapp:This WILL appear
ERROR:myapp:This WILL appear

When you set a level, only records at that level and above pass through.

Part 4 - `logging.getLogger(name)`: The Module Logger Pattern

Why `name` Matters

# In file: myapp/database.py
import logging

logger = logging.getLogger(__name__)
# __name__ == "myapp.database" when this module is imported
# __name__ == "__main__" when this file is run directly

def connect(host, port):
    logger.info("Connecting to database at %s:%d", host, port)
    # ...

When __name__ is "myapp.database", the logger is named "myapp.database". This creates a logger in the hierarchy:

This gives you three important capabilities:

1. Identify the source of every log line:

2024-01-15 14:23:01 INFO  myapp.database - Connecting to database at localhost:5432
2024-01-15 14:23:01 INFO  myapp.api.users - User 42 requested profile
2024-01-15 14:23:01 ERROR myapp.payments - Stripe webhook signature invalid

You can see instantly which module generated each message.

2. Configure log levels per module:

# Silence noisy SQLAlchemy query logs in production
logging.getLogger("sqlalchemy.engine").setLevel(logging.WARNING)

# But keep your own app at INFO
logging.getLogger("myapp").setLevel(logging.INFO)

3. Inherit configuration from parent loggers: All child loggers automatically use handlers and levels set on parent loggers. Configure once at the root or at "myapp" and all sub-loggers inherit it.

:::warning Do Not Use Root Logger Directly Avoid logging.info() and logging.warning() (module-level convenience functions). These log to the root logger with no name. Every library in your project also uses the root logger by default, creating confusion about where messages originate. Always use logging.getLogger(__name__). :::

Part 5 - Handlers: Where Logs Go

A Handler decides the destination of log records.

StreamHandler - Write to stderr or stdout

import logging
import sys

logger = logging.getLogger("myapp")
logger.setLevel(logging.DEBUG)

# StreamHandler defaults to sys.stderr
handler = logging.StreamHandler()
handler.setLevel(logging.DEBUG)

logger.addHandler(handler)
logger.info("Server starting on port 8000")
# Output to stderr: INFO:myapp:Server starting on port 8000

:::note Why stderr? By convention, log messages go to stderr and program output goes to stdout. This lets users pipe program output (./app > output.txt) while still seeing logs in the terminal. StreamHandler defaults to stderr for this reason. :::

FileHandler - Write to a file

import logging

logger = logging.getLogger("myapp")
logger.setLevel(logging.INFO)

file_handler = logging.FileHandler("app.log", mode="a", encoding="utf-8")
file_handler.setLevel(logging.INFO)

logger.addHandler(file_handler)
logger.info("Application started")
# Writes to app.log: INFO:myapp:Application started

RotatingFileHandler - Prevent disk exhaustion

from logging.handlers import RotatingFileHandler
import logging

logger = logging.getLogger("myapp")

# Rotate after 10 MB, keep 5 backup files
rotating_handler = RotatingFileHandler(
    "app.log",
    maxBytes=10 * 1024 * 1024,  # 10 MB
    backupCount=5,
    encoding="utf-8",
)
logger.addHandler(rotating_handler)

# Files created: app.log, app.log.1, app.log.2, ... app.log.5
# When app.log hits 10 MB, it rotates: app.log -> app.log.1, new app.log created

:::warning Always Use RotatingFileHandler in Production Plain FileHandler will grow your log file without bound. On a busy server, you can fill a disk in hours. Always use RotatingFileHandler or TimedRotatingFileHandler (which rotates daily/hourly) in production deployments. :::

Multiple Handlers - Different Destinations Simultaneously

import logging
from logging.handlers import RotatingFileHandler

logger = logging.getLogger("myapp")
logger.setLevel(logging.DEBUG)

# Handler 1: all DEBUG+ messages to a rotating file
file_handler = RotatingFileHandler("debug.log", maxBytes=5_000_000, backupCount=3)
file_handler.setLevel(logging.DEBUG)

# Handler 2: only ERROR+ messages to stderr (visible in terminal/systemd journal)
error_handler = logging.StreamHandler()
error_handler.setLevel(logging.ERROR)

logger.addHandler(file_handler)
logger.addHandler(error_handler)

logger.debug("This goes to debug.log only")
logger.info("This goes to debug.log only")
logger.error("This goes to debug.log AND stderr")

NullHandler - The Library Author's Best Friend

# In your library code: mylib/__init__.py
import logging

# Best practice for libraries: add NullHandler to suppress output
# if the user hasn't configured logging
logging.getLogger("mylib").addHandler(logging.NullHandler())

When you publish a library, you should never configure handlers. That is the application developer's responsibility. By adding NullHandler, you prevent the "No handlers could be found for logger" warning while still allowing the application to attach real handlers if it wants.

Part 6 - Formatters: How Logs Look

A Formatter converts a LogRecord object into a string.

Standard Format Attributes

import logging

formatter = logging.Formatter(
    fmt="%(asctime)s  %(levelname)-8s  %(name)s:%(lineno)d  %(message)s",
    datefmt="%Y-%m-%d %H:%M:%S",
)

2024-01-15 14:23:01  INFO      myapp.api:47  Request received: GET /users/42
2024-01-15 14:23:01  WARNING   myapp.db:112  Slow query: 1.8s
2024-01-15 14:23:02  ERROR     myapp.api:89  Unhandled exception in view

Format String Reference

Format Attribute	What It Contains
`%(asctime)s`	Human-readable time: `"2024-01-15 14:23:01,456"`
`%(created)f`	Unix timestamp (float)
`%(filename)s`	Filename portion of `__file__`
`%(funcName)s`	Name of the function containing the log call
`%(levelname)s`	`"DEBUG"`, `"INFO"`, `"WARNING"`, `"ERROR"`, `"CRITICAL"`
`%(levelno)d`	Numeric level: 10, 20, 30, 40, 50
`%(lineno)d`	Line number in source file
`%(message)s`	The formatted log message
`%(module)s`	Module name (filename without `.py`)
`%(name)s`	Logger name (e.g., `"myapp.database"`)
`%(pathname)s`	Full path to source file
`%(process)d`	Process ID
`%(thread)d`	Thread ID
`%(threadName)s`	Thread name

Attaching a Formatter to a Handler

import logging

# Create logger
logger = logging.getLogger("myapp")
logger.setLevel(logging.DEBUG)

# Create handler
handler = logging.StreamHandler()
handler.setLevel(logging.DEBUG)

# Create formatter and attach to handler
formatter = logging.Formatter(
    "%(asctime)s [%(levelname)s] %(name)s (%(filename)s:%(lineno)d): %(message)s",
    datefmt="%Y-%m-%dT%H:%M:%S",
)
handler.setFormatter(formatter)

# Attach handler to logger
logger.addHandler(handler)

logger.info("Server listening on 0.0.0.0:8000")
# Output:
# 2024-01-15T14:23:01 [INFO] myapp (server.py:15): Server listening on 0.0.0.0:8000

Part 7 - Configuration Strategies

Strategy 1: `basicConfig` (Scripts and Simple Programs)

import logging

# Must be called before any logger is used
# Only configures the root logger; only works once
logging.basicConfig(
    level=logging.INFO,
    format="%(asctime)s [%(levelname)s] %(name)s: %(message)s",
    datefmt="%Y-%m-%d %H:%M:%S",
)

logger = logging.getLogger(__name__)
logger.info("Script starting")

basicConfig is convenient for scripts and tutorials. It has major limitations:

Only configures the root logger
Calling it again does nothing (ignored after first call)
Not suitable for complex multi-handler configurations

Strategy 2: Explicit Configuration (Medium Projects)

import logging
from logging.handlers import RotatingFileHandler

def setup_logging(log_level: str = "INFO") -> None:
    """Configure application logging explicitly."""
    level = getattr(logging, log_level.upper(), logging.INFO)

    # Root logger - suppress third-party library noise
    root = logging.getLogger()
    root.setLevel(logging.WARNING)

    # App logger - verbose for our own code
    app_logger = logging.getLogger("myapp")
    app_logger.setLevel(level)

    # Formatter
    fmt = logging.Formatter(
        "%(asctime)s [%(levelname)-8s] %(name)s: %(message)s",
        datefmt="%Y-%m-%dT%H:%M:%S",
    )

    # Console handler - INFO and above
    console = logging.StreamHandler()
    console.setLevel(logging.INFO)
    console.setFormatter(fmt)

    # File handler - DEBUG and above (all details)
    file_h = RotatingFileHandler(
        "app.log", maxBytes=10_000_000, backupCount=5, encoding="utf-8"
    )
    file_h.setLevel(logging.DEBUG)
    file_h.setFormatter(fmt)

    app_logger.addHandler(console)
    app_logger.addHandler(file_h)

# Call once at startup
setup_logging(log_level="DEBUG")

Strategy 3: `dictConfig` (Production Applications)

dictConfig is the production standard. It lets you define your entire logging configuration as a Python dictionary - which can be loaded from a JSON or YAML file, parameterized per environment, and versioned in source control.

import logging
import logging.config

LOGGING_CONFIG = {
    "version": 1,
    "disable_existing_loggers": False,   # Important: don't silence existing loggers

    "formatters": {
        "standard": {
            "format": "%(asctime)s [%(levelname)s] %(name)s: %(message)s",
            "datefmt": "%Y-%m-%dT%H:%M:%S",
        },
        "detailed": {
            "format": "%(asctime)s [%(levelname)s] %(name)s (%(filename)s:%(lineno)d): %(message)s",
        },
    },

    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "level": "INFO",
            "formatter": "standard",
            "stream": "ext://sys.stderr",
        },
        "file": {
            "class": "logging.handlers.RotatingFileHandler",
            "level": "DEBUG",
            "formatter": "detailed",
            "filename": "app.log",
            "maxBytes": 10_485_760,   # 10 MB
            "backupCount": 5,
            "encoding": "utf-8",
        },
    },

    "loggers": {
        "myapp": {
            "level": "DEBUG",
            "handlers": ["console", "file"],
            "propagate": False,   # Don't also send to root logger
        },
        "sqlalchemy.engine": {
            "level": "WARNING",   # Suppress SQL query logs
            "handlers": [],
            "propagate": True,
        },
    },

    "root": {
        "level": "WARNING",
        "handlers": ["console"],
    },
}

logging.config.dictConfig(LOGGING_CONFIG)

:::tip Use dictConfig in Every Production Application dictConfig is the official, standard-library-recommended approach for production. It is declarative, testable, and environment-configurable. Flask, Django, and FastAPI all use dictConfig-compatible configurations. :::

Part 8 - Logger Propagation: Avoiding Duplicate Logs

How Propagation Works

Fixing Duplicate Logs

import logging

# BAD: adding a handler to a child logger while root also has one
root = logging.getLogger()
root.setLevel(logging.DEBUG)
root.addHandler(logging.StreamHandler())     # Root handler

app = logging.getLogger("myapp")
app.setLevel(logging.DEBUG)
app.addHandler(logging.StreamHandler())     # App handler - DUPLICATE!

app.info("Hello")
# Prints "Hello" TWICE: once from app handler, once from root handler

# FIX 1: Disable propagation on the child logger
app = logging.getLogger("myapp")
app.propagate = False    # Stop records from reaching root logger
app.addHandler(logging.StreamHandler())

# FIX 2: Only add handlers to root (cleaner for simple setups)
logging.basicConfig(level=logging.DEBUG)
# No addHandler calls on any child logger

:::warning The Most Common Logging Bug Duplicate log messages almost always mean a handler was added to a child logger that propagates to the root logger (which also has a handler). Check logger.propagate and the handler count with logger.handlers. :::

Part 9 - Capturing Tracebacks with `logger.exception()`

The Problem: Silently Catching Exceptions

# BAD: you know something failed, but you lose all diagnostic information
try:
    result = process_data(payload)
except Exception:
    logger.error("Processing failed")
    # What failed? What was the exception? What was the traceback?
    # You have no idea. Support ticket cannot be resolved.

The Fix: `logger.exception()`

# GOOD: captures the full traceback automatically
try:
    result = process_data(payload)
except Exception:
    logger.exception("Processing failed")
    # Logs at ERROR level AND appends the full traceback

Output:

2024-01-15T14:23:01 [ERROR] myapp: Processing failed
Traceback (most recent call last):
  File "pipeline.py", line 47, in process_data
    value = record["amount"] * exchange_rates[currency]
KeyError: 'GBP'

logger.exception(msg) is equivalent to logger.error(msg, exc_info=True). The exc_info=True argument captures the current exception information from sys.exc_info() and appends it to the log record.

# These three are equivalent:
logger.exception("Something failed")

logger.error("Something failed", exc_info=True)

import sys
logger.error("Something failed", exc_info=sys.exc_info())

:::tip Always Use logger.exception() Inside except Blocks If you are inside an except block and you want to log that an error occurred, always use logger.exception() or logger.error(..., exc_info=True). Never use logger.error() alone - you will lose the traceback that explains what went wrong. :::

Part 10 - Adding Context to Logs

The `extra` Parameter

import logging

logger = logging.getLogger("myapp.api")

def handle_request(request_id: str, user_id: int, endpoint: str) -> None:
    # Pass extra context that can appear in formatted output
    logger.info(
        "Request started",
        extra={"request_id": request_id, "user_id": user_id, "endpoint": endpoint},
    )

To use extra fields in the format string:

formatter = logging.Formatter(
    "%(asctime)s [%(levelname)s] req=%(request_id)s user=%(user_id)s %(message)s"
)

LoggerAdapter - Attach Persistent Context

LoggerAdapter wraps a logger and automatically injects context into every log call without requiring you to pass extra= each time.

import logging

class RequestAdapter(logging.LoggerAdapter):
    """Injects request_id into every log message."""

    def process(self, msg, kwargs):
        kwargs.setdefault("extra", {})
        kwargs["extra"]["request_id"] = self.extra.get("request_id", "n/a")
        return msg, kwargs


base_logger = logging.getLogger("myapp.api")

def handle_request(request_id: str) -> None:
    # Create an adapter bound to this request
    logger = RequestAdapter(base_logger, {"request_id": request_id})

    logger.info("Request received")       # request_id included automatically
    logger.info("Processing payload")    # request_id included automatically
    logger.info("Response sent")         # request_id included automatically

contextvars - Thread-Safe Context (Python 3.7+)

For async frameworks (FastAPI, aiohttp), LoggerAdapter per-request is cumbersome. Use contextvars instead:

import logging
import contextvars
import uuid

# Module-level context variable
request_id_var: contextvars.ContextVar[str] = contextvars.ContextVar(
    "request_id", default="n/a"
)

class ContextFilter(logging.Filter):
    """Inject request_id from context into every log record."""

    def filter(self, record: logging.LogRecord) -> bool:
        record.request_id = request_id_var.get()
        return True

# Attach the filter to your handler or logger
logger = logging.getLogger("myapp")
logger.addFilter(ContextFilter())

# In FastAPI middleware
async def logging_middleware(request, call_next):
    token = request_id_var.set(str(uuid.uuid4()))
    try:
        return await call_next(request)
    finally:
        request_id_var.reset(token)

# Now every log call within a request automatically includes request_id

Part 11 - Structured JSON Logging

Why JSON?

In modern cloud infrastructure, logs are ingested by systems like Datadog, Splunk, CloudWatch, or Loki. These systems can parse structured data (JSON objects) and let you filter, aggregate, and alert on individual fields.

# Human-readable string - hard to query
2024-01-15 14:23:01 ERROR myapp.api: Payment failed user_id=42 amount=99.99 currency=USD

# JSON - machine-queryable
{"timestamp": "2024-01-15T14:23:01", "level": "ERROR", "logger": "myapp.api",
 "message": "Payment failed", "user_id": 42, "amount": 99.99, "currency": "USD"}

With JSON, Datadog can show you: "All ERROR logs where currency=USD and amount > 50" - without regex.

Installing python-json-logger

pip install python-json-logger

Configuring JSON Logging

import logging
from pythonjsonlogger import jsonlogger

def setup_json_logging() -> None:
    logger = logging.getLogger()
    logger.setLevel(logging.INFO)

    handler = logging.StreamHandler()
    formatter = jsonlogger.JsonFormatter(
        fmt="%(asctime)s %(levelname)s %(name)s %(message)s",
        datefmt="%Y-%m-%dT%H:%M:%S",
    )
    handler.setFormatter(formatter)
    logger.addHandler(handler)

setup_json_logging()

app_logger = logging.getLogger("myapp.api")
app_logger.info(
    "Payment processed",
    extra={"user_id": 42, "amount": 99.99, "currency": "USD", "duration_ms": 145},
)

Output (one line per log record, formatted here for readability):

{
  "asctime": "2024-01-15T14:23:01",
  "levelname": "INFO",
  "name": "myapp.api",
  "message": "Payment processed",
  "user_id": 42,
  "amount": 99.99,
  "currency": "USD",
  "duration_ms": 145
}

Part 12 - Real-World: FastAPI Logging Configuration

Here is a complete, production-grade logging setup for a FastAPI application:

# app/logging_config.py
import logging
import logging.config
import os

def get_logging_config(environment: str = "production") -> dict:
    """Return environment-specific logging configuration."""

    is_dev = environment == "development"

    return {
        "version": 1,
        "disable_existing_loggers": False,

        "formatters": {
            "json": {
                "()": "pythonjsonlogger.jsonlogger.JsonFormatter",
                "fmt": "%(asctime)s %(levelname)s %(name)s %(funcName)s %(lineno)d %(message)s",
            },
            "human": {
                "format": "%(asctime)s [%(levelname)-8s] %(name)s:%(lineno)d  %(message)s",
                "datefmt": "%H:%M:%S",
            },
        },

        "handlers": {
            "console": {
                "class": "logging.StreamHandler",
                "level": "DEBUG" if is_dev else "INFO",
                "formatter": "human" if is_dev else "json",
                "stream": "ext://sys.stderr",
            },
        },

        "loggers": {
            # Your application code
            "myapp": {
                "level": "DEBUG" if is_dev else "INFO",
                "handlers": ["console"],
                "propagate": False,
            },
            # FastAPI / uvicorn internals
            "uvicorn.access": {
                "level": "WARNING",  # Suppress per-request access logs in prod
                "handlers": ["console"],
                "propagate": False,
            },
            # Silence SQLAlchemy query echo
            "sqlalchemy.engine": {
                "level": "WARNING",
                "handlers": [],
                "propagate": True,
            },
        },

        "root": {
            "level": "WARNING",
            "handlers": ["console"],
        },
    }


# app/main.py
from fastapi import FastAPI
import logging
import logging.config
from app.logging_config import get_logging_config

ENVIRONMENT = os.getenv("APP_ENV", "production")

logging.config.dictConfig(get_logging_config(ENVIRONMENT))
logger = logging.getLogger("myapp.main")

app = FastAPI()

@app.on_event("startup")
async def startup_event():
    logger.info("Application starting", extra={"environment": ENVIRONMENT})

Interview Questions

Q1: What is the difference between `print()` and the `logging` module for production applications?

Answer: print() writes to stdout with no level filtering, no routing, no formatting metadata, and no way to suppress output without code changes. The logging module provides:

Severity levels (DEBUG through CRITICAL) so you can filter by importance without touching code
Multiple destinations simultaneously (file, stderr, external service) via Handlers
Automatic metadata (timestamp, logger name, line number, thread ID) via Formatters
Per-module configuration via the named logger hierarchy
Structured output (JSON) consumable by log aggregation systems

In production, print is never appropriate for observability. Use logging.getLogger(__name__) at module level and call logger.info(), logger.error(), etc.

Q2: Explain the logging hierarchy and how propagation works.

Answer: Python loggers form a tree that mirrors the package/module namespace. logging.getLogger("myapp.api") creates a child of logging.getLogger("myapp"), which is a child of the root logger.

When a log record is created, it travels up the tree. At each level, the logger's handlers process the record (if the level threshold passes). If logger.propagate is True (the default), the record continues to the parent. This is why you can configure one handler on the root logger and all descendant loggers will use it automatically.

The main pitfall: if both a child and the root have handlers, you get duplicate log output. Fix by setting propagate = False on the child, or by not adding handlers to the child logger at all.

Q3: Why should libraries use `logging.NullHandler()` and never configure real handlers?

Answer: A library does not know how the application wants to handle logs. If a library calls logging.basicConfig() or adds its own StreamHandler, it imposes its configuration on the application developer - overriding their carefully configured setup.

The correct pattern is:

# In mylib/__init__.py
import logging
logging.getLogger("mylib").addHandler(logging.NullHandler())

NullHandler discards all records silently. This suppresses the "No handlers found" warning while giving application developers full control to attach real handlers if they want to see the library's logs.

Q4: What does `logger.exception(msg)` do, and why should you use it inside except blocks instead of `logger.error(msg)`?

Answer: logger.exception(msg) logs at ERROR level and automatically appends the full traceback of the current exception by calling sys.exc_info() internally. It is equivalent to logger.error(msg, exc_info=True).

Using plain logger.error(msg) inside an except block logs the message but loses the traceback - the most important diagnostic information. Without the traceback you know something failed but not where, on what data, or why.

Rule: always use logger.exception() inside except blocks when you want to record that an error occurred.

Q5: What is the difference between setting the level on a Logger versus setting it on a Handler?

Answer: Both have independent level filters:

Logger level: the first gate. If the log level is below the logger's threshold, the record is dropped immediately - no handlers are called. This is efficient.
Handler level: a second gate. Even if the logger passes the record, each handler checks its own level. This lets you send DEBUG records to a file but only INFO+ to the console.

Example: logger level DEBUG, file handler level DEBUG, console handler level WARNING. The logger passes all records to both handlers. The file handler writes all of them. The console handler only writes WARNING and above. You get verbose file logs and quiet console.

Q6: What is structured logging, and when does it matter?

Answer: Structured logging means emitting log records as machine-parseable data (typically JSON) rather than human-readable strings.

It matters as soon as logs are ingested by a centralized system (Datadog, Splunk, CloudWatch, Loki). These systems can index individual fields in JSON and let you:

Filter: "show all ERROR records where user_id=42"
Aggregate: "count ERROR records per endpoint in the last hour"
Alert: "page me when duration_ms exceeds 5000 more than 10 times per minute"

None of this is possible with free-text strings without fragile regex. The python-json-logger library makes it easy: replace the standard Formatter with JsonFormatter and use extra={} to attach structured fields to each log call.

Practice Challenges

Beginner - Configure Module-Level Logging

Set up logging for a simple script that:

Creates a logger with __name__
Configures a StreamHandler that writes to stderr
Uses the format: [LEVEL] module_name: message
Logs one message at each of the five levels
Sets the threshold to WARNING so only WARNING, ERROR, and CRITICAL appear

Solution

import logging
import sys

# Module-level logger - always use __name__
logger = logging.getLogger(__name__)
logger.setLevel(logging.WARNING)   # Only WARNING and above pass

# Create and configure the handler
handler = logging.StreamHandler(sys.stderr)
handler.setLevel(logging.DEBUG)    # Handler accepts anything the logger passes

# Create and attach the formatter
formatter = logging.Formatter("[%(levelname)s] %(name)s: %(message)s")
handler.setFormatter(formatter)

# Attach handler to logger
logger.addHandler(handler)

# Prevent propagation to root logger (avoids duplicate output)
logger.propagate = False

# Log at all five levels
logger.debug("This is a DEBUG message")        # Filtered out (below WARNING)
logger.info("This is an INFO message")         # Filtered out (below WARNING)
logger.warning("This is a WARNING message")    # Appears
logger.error("This is an ERROR message")       # Appears
logger.critical("This is a CRITICAL message")  # Appears

# Expected output on stderr:
# [WARNING] __main__: This is a WARNING message
# [ERROR] __main__: This is an ERROR message
# [CRITICAL] __main__: This is a CRITICAL message

Intermediate - Logging with Exception Tracebacks

Write a function safe_divide(a, b) that:

Uses logger.exception() to log any ZeroDivisionError with its full traceback
Returns None on error instead of crashing
Uses logger.info() to log the result on success
Demonstrate it with both a success case and an error case

Solution

import logging

logging.basicConfig(
    level=logging.DEBUG,
    format="%(asctime)s [%(levelname)s] %(name)s:%(lineno)d  %(message)s",
    datefmt="%Y-%m-%dT%H:%M:%S",
)

logger = logging.getLogger(__name__)


def safe_divide(a: float, b: float) -> float | None:
    """
    Divide a by b, logging the result or any error.
    Returns None if division fails.
    """
    try:
        result = a / b
        logger.info("Division result: %s / %s = %s", a, b, result)
        return result
    except ZeroDivisionError:
        # logger.exception logs at ERROR level AND appends the full traceback
        logger.exception("Division by zero: attempted %s / %s", a, b)
        return None


# Success case
result = safe_divide(10, 2)
print(f"Result: {result}")

# Error case
result = safe_divide(10, 0)
print(f"Result: {result}")

# Expected output:
#
# 2024-01-15T14:23:01 [INFO] __main__:14  Division result: 10 / 2 = 5.0
# Result: 5.0
#
# 2024-01-15T14:23:01 [ERROR] __main__:18  Division by zero: attempted 10 / 0
# Traceback (most recent call last):
#   File "solution.py", line 12, in safe_divide
#     result = a / b
# ZeroDivisionError: division by zero
# Result: None

Advanced - Production dictConfig with JSON and Context

Build a complete logging setup for a FastAPI-style application that:

Uses dictConfig with two formatters: human-readable for development, JSON for production
Uses contextvars to inject a request_id into every log record automatically
Configures the app logger to DEBUG, silences sqlalchemy.engine at WARNING
Demonstrates the context injection by simulating two concurrent requests with different IDs

Solution

import logging
import logging.config
import contextvars
import uuid

# ── Context variable for request ID ─────────────────────────────────────────
request_id_var: contextvars.ContextVar[str] = contextvars.ContextVar(
    "request_id", default="n/a"
)

# ── Filter that injects request_id into every log record ────────────────────
class RequestIdFilter(logging.Filter):
    def filter(self, record: logging.LogRecord) -> bool:
        record.request_id = request_id_var.get()
        return True

# ── dictConfig ───────────────────────────────────────────────────────────────
LOGGING_CONFIG = {
    "version": 1,
    "disable_existing_loggers": False,

    "filters": {
        "request_id": {
            "()": "__main__.RequestIdFilter",
        },
    },

    "formatters": {
        "detailed": {
            "format": "%(asctime)s [%(levelname)-8s] req=%(request_id)s %(name)s:%(lineno)d  %(message)s",
            "datefmt": "%Y-%m-%dT%H:%M:%S",
        },
    },

    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "level": "DEBUG",
            "formatter": "detailed",
            "filters": ["request_id"],
            "stream": "ext://sys.stderr",
        },
    },

    "loggers": {
        "myapp": {
            "level": "DEBUG",
            "handlers": ["console"],
            "propagate": False,
        },
        "sqlalchemy.engine": {
            "level": "WARNING",
            "handlers": [],
            "propagate": True,
        },
    },

    "root": {
        "level": "WARNING",
        "handlers": ["console"],
    },
}

logging.config.dictConfig(LOGGING_CONFIG)
logger = logging.getLogger("myapp.api")


# ── Simulated request handler ─────────────────────────────────────────────
def handle_request(user_id: int) -> None:
    """Simulate processing a web request with its own request_id."""
    rid = str(uuid.uuid4())[:8]
    token = request_id_var.set(rid)

    try:
        logger.info("Request started", extra={"user_id": user_id})
        logger.debug("Fetching user data from database", extra={"user_id": user_id})
        logger.info("Request complete", extra={"user_id": user_id})
    except Exception:
        logger.exception("Unexpected error in request handler")
    finally:
        request_id_var.reset(token)


# Simulate two requests - each gets its own request_id in logs
handle_request(user_id=101)
handle_request(user_id=202)

# Expected output (request IDs are random UUID prefixes):
#
# 2024-01-15T14:23:01 [INFO    ] req=a3f1b2c4 myapp.api:56  Request started
# 2024-01-15T14:23:01 [DEBUG   ] req=a3f1b2c4 myapp.api:57  Fetching user data from database
# 2024-01-15T14:23:01 [INFO    ] req=a3f1b2c4 myapp.api:58  Request complete
# 2024-01-15T14:23:01 [INFO    ] req=7d9e0f12 myapp.api:56  Request started
# 2024-01-15T14:23:01 [DEBUG   ] req=7d9e0f12 myapp.api:57  Fetching user data from database
# 2024-01-15T14:23:01 [INFO    ] req=7d9e0f12 myapp.api:58  Request complete

Quick Reference

Task	Code
Create a module logger	`logger = logging.getLogger(__name__)`
Basic script setup	`logging.basicConfig(level=logging.INFO, format="...")`
Log at INFO level	`logger.info("Message: %s", value)`
Log with traceback	`logger.exception("Failed")` (inside except block)
Add a stream handler	`logger.addHandler(logging.StreamHandler())`
Add a rotating file handler	`from logging.handlers import RotatingFileHandler`
Set level on logger	`logger.setLevel(logging.DEBUG)`
Set level on handler	`handler.setLevel(logging.WARNING)`
Attach a formatter	`handler.setFormatter(logging.Formatter("%(levelname)s: %(message)s"))`
Disable propagation	`logger.propagate = False`
Production config	`logging.config.dictConfig(config_dict)`
Silence noisy library	`logging.getLogger("sqlalchemy").setLevel(logging.WARNING)`
Add extra context	`logger.info("msg", extra={"key": "value"})`
Wrap with adapter	`logger = logging.LoggerAdapter(base, {"request_id": rid})`
JSON logging	`pip install python-json-logger`, use `jsonlogger.JsonFormatter`

Key Takeaways

print is not logging - it has no levels, no routing, no filtering, and no metadata; use logging.getLogger(__name__) in every module
The logging system has three components: Logger (receives calls), Handler (routes records), Formatter (formats the output string)
Log levels from lowest to highest: DEBUG (10), INFO (20), WARNING (30), ERROR (40), CRITICAL (50); set the threshold to match your environment
logging.getLogger(__name__) creates a hierarchical logger named after the module, enabling per-module configuration and clear source identification in logs
Propagation moves log records up the logger tree; if both parent and child have handlers, you get duplicate output - fix with logger.propagate = False
Always use logger.exception() inside except blocks - it logs at ERROR level with the full traceback attached automatically
Use dictConfig in production: it is declarative, environment-configurable, and the official standard for complex logging setups
Structured JSON logging (via python-json-logger) is essential in cloud environments where log aggregation systems need to query individual fields

What You Will Learn​

Prerequisites​

Part 1 - Why print Fails at Scale​

The Five Problems with print Debugging in Production​

Part 2 - The Logging Architecture​

The Three Core Components​

Part 3 - Log Levels​

The Five Standard Levels​

When to Use Each Level - Engineering Decisions​

Level Filtering​

Part 4 - logging.getLogger(__name__): The Module Logger Pattern​

Why __name__ Matters​

Part 5 - Handlers: Where Logs Go​

StreamHandler - Write to stderr or stdout​

FileHandler - Write to a file​

RotatingFileHandler - Prevent disk exhaustion​

Multiple Handlers - Different Destinations Simultaneously​

NullHandler - The Library Author's Best Friend​

Part 6 - Formatters: How Logs Look​

Standard Format Attributes​

Format String Reference​

Attaching a Formatter to a Handler​

Part 7 - Configuration Strategies​

Strategy 1: basicConfig (Scripts and Simple Programs)​

Strategy 2: Explicit Configuration (Medium Projects)​

Strategy 3: dictConfig (Production Applications)​

Part 8 - Logger Propagation: Avoiding Duplicate Logs​

How Propagation Works​

Fixing Duplicate Logs​

Part 9 - Capturing Tracebacks with logger.exception()​

The Problem: Silently Catching Exceptions​

The Fix: logger.exception()​

Part 10 - Adding Context to Logs​

The extra Parameter​

LoggerAdapter - Attach Persistent Context​

contextvars - Thread-Safe Context (Python 3.7+)​

Part 11 - Structured JSON Logging​

Why JSON?​

Installing python-json-logger​

Configuring JSON Logging​

Part 12 - Real-World: FastAPI Logging Configuration​

Interview Questions​

Q1: What is the difference between print() and the logging module for production applications?​

Q2: Explain the logging hierarchy and how propagation works.​

Q3: Why should libraries use logging.NullHandler() and never configure real handlers?​

Q4: What does logger.exception(msg) do, and why should you use it inside except blocks instead of logger.error(msg)?​

Q5: What is the difference between setting the level on a Logger versus setting it on a Handler?​

Q6: What is structured logging, and when does it matter?​

Practice Challenges​

Beginner - Configure Module-Level Logging​

Intermediate - Logging with Exception Tracebacks​

Advanced - Production dictConfig with JSON and Context​

Quick Reference​

Key Takeaways​

What You Will Learn

Prerequisites

Part 1 - Why `print` Fails at Scale

The Five Problems with `print` Debugging in Production

Part 2 - The Logging Architecture

The Three Core Components

Part 3 - Log Levels

The Five Standard Levels

When to Use Each Level - Engineering Decisions

Level Filtering

Part 4 - `logging.getLogger(name)`: The Module Logger Pattern

Why `name` Matters

Part 5 - Handlers: Where Logs Go

StreamHandler - Write to stderr or stdout

FileHandler - Write to a file

RotatingFileHandler - Prevent disk exhaustion

Multiple Handlers - Different Destinations Simultaneously

NullHandler - The Library Author's Best Friend

Part 6 - Formatters: How Logs Look

Standard Format Attributes

Format String Reference

Attaching a Formatter to a Handler

Part 7 - Configuration Strategies

Strategy 1: `basicConfig` (Scripts and Simple Programs)

Strategy 2: Explicit Configuration (Medium Projects)

Strategy 3: `dictConfig` (Production Applications)

Part 8 - Logger Propagation: Avoiding Duplicate Logs

How Propagation Works

Fixing Duplicate Logs

Part 9 - Capturing Tracebacks with `logger.exception()`

The Problem: Silently Catching Exceptions

The Fix: `logger.exception()`

Part 10 - Adding Context to Logs

The `extra` Parameter

LoggerAdapter - Attach Persistent Context

contextvars - Thread-Safe Context (Python 3.7+)

Part 11 - Structured JSON Logging

Why JSON?

Installing python-json-logger

Configuring JSON Logging

Part 12 - Real-World: FastAPI Logging Configuration

Interview Questions

Q1: What is the difference between `print()` and the `logging` module for production applications?

Q2: Explain the logging hierarchy and how propagation works.

Q3: Why should libraries use `logging.NullHandler()` and never configure real handlers?

Q4: What does `logger.exception(msg)` do, and why should you use it inside except blocks instead of `logger.error(msg)`?

Q5: What is the difference between setting the level on a Logger versus setting it on a Handler?

Q6: What is structured logging, and when does it matter?

Practice Challenges

Beginner - Configure Module-Level Logging

Intermediate - Logging with Exception Tracebacks

Advanced - Production dictConfig with JSON and Context

Quick Reference

Key Takeaways