Logging: Levels, Handlers, Formatters & Structured Logging

0/4 in this phase0/54 across the roadmap

📖 Concept

Python's logging module is a production-grade, highly configurable logging framework built into the standard library. It supports hierarchical loggers, multiple output destinations (handlers), customizable message formatting, and filtering — all without third-party dependencies.

Why not print()?

No log levels (can't filter debug vs error)
No timestamps, source file, or line numbers
No way to route to files, syslog, or external services
Can't disable without removing code
Not thread-safe for concurrent writes

Log levels (in order of severity):

Level	Value	Use Case
`DEBUG`	10	Detailed diagnostic info (variable values, flow tracing)
`INFO`	20	Confirmation that things are working (startup, shutdown, milestones)
`WARNING`	30	Something unexpected but not broken (deprecated API, retry, fallback)
`ERROR`	40	Something failed but the app continues (failed request, missing resource)
`CRITICAL`	50	The app cannot continue (out of memory, database down, corrupted state)

Architecture: The logging system has four key components:

Loggers — the API you call (logger.info("msg")). Organized in a dot-separated hierarchy (app.db.queries).
Handlers — where logs go (StreamHandler, FileHandler, RotatingFileHandler, SysLogHandler, etc.).
Formatters — how log messages look (timestamp format, included fields).
Filters — fine-grained control over which records are emitted.

Best practice: Always use logging.getLogger(__name__) to create module-level loggers. This creates a logger hierarchy matching your package structure, allowing fine-grained configuration. Never use the root logger (logging.info()) in library code.

💻 Code Example

codeTap to expand ⛶

1# ============================================================
2# Basic logging setup — the minimum viable configuration
3# ============================================================
4import logging
5
6# BAD — using print for diagnostics
7# print(f"Processing user {user_id}")  # No level, no timestamp, no filtering
8
9# BAD — using root logger in a module/library
10# logging.info("...")  # Pollutes the root logger, hard to configure
11
12# GOOD — module-level logger with __name__
13logger = logging.getLogger(__name__)
14
15# Quick setup for scripts (NOT for libraries)
16logging.basicConfig(
17    level=logging.DEBUG,
18    format="%(asctime)s | %(levelname)-8s | %(name)s | %(message)s",
19    datefmt="%Y-%m-%d %H:%M:%S",
20)
21
22# Using different levels
23logger.debug("Connecting to database at %s:%d", "localhost", 5432)
24logger.info("Application started successfully")
25logger.warning("Cache miss for key %r, falling back to DB", "user:123")
26logger.error("Failed to process payment for order %s", "ORD-456")
27logger.critical("Database connection pool exhausted — shutting down")
28
29
30# ============================================================
31# Production logging configuration — programmatic setup
32# ============================================================
33import logging
34import logging.handlers
35import sys
36from pathlib import Path
37
38
39def setup_logging(
40    log_dir: str = "logs",
41    level: str = "INFO",
42    max_bytes: int = 10 * 1024 * 1024,  # 10 MB
43    backup_count: int = 5,
44):
45    """Configure production-grade logging with console + rotating file."""
46    log_path = Path(log_dir)
47    log_path.mkdir(parents=True, exist_ok=True)
48
49    # Create root logger
50    root_logger = logging.getLogger()
51    root_logger.setLevel(getattr(logging, level.upper()))
52
53    # Clear existing handlers (prevents duplicate logs on re-init)
54    root_logger.handlers.clear()
55
56    # --- Console handler (human-readable) ---
57    console_handler = logging.StreamHandler(sys.stderr)
58    console_handler.setLevel(logging.INFO)
59    console_formatter = logging.Formatter(
60        fmt="%(asctime)s | %(levelname)-8s | %(name)s:%(lineno)d | %(message)s",
61        datefmt="%H:%M:%S",
62    )
63    console_handler.setFormatter(console_formatter)
64
65    # --- Rotating file handler (detailed, for debugging) ---
66    file_handler = logging.handlers.RotatingFileHandler(
67        filename=log_path / "app.log",
68        maxBytes=max_bytes,
69        backupCount=backup_count,
70        encoding="utf-8",
71    )
72    file_handler.setLevel(logging.DEBUG)
73    file_formatter = logging.Formatter(
74        fmt="%(asctime)s | %(levelname)-8s | %(name)s:%(funcName)s:%(lineno)d | %(message)s",
75        datefmt="%Y-%m-%d %H:%M:%S",
76    )
77    file_handler.setFormatter(file_formatter)
78
79    # --- Error-only file handler (for alerts/monitoring) ---
80    error_handler = logging.handlers.RotatingFileHandler(
81        filename=log_path / "errors.log",
82        maxBytes=max_bytes,
83        backupCount=backup_count,
84        encoding="utf-8",
85    )
86    error_handler.setLevel(logging.ERROR)
87    error_handler.setFormatter(file_formatter)
88
89    # Attach all handlers
90    root_logger.addHandler(console_handler)
91    root_logger.addHandler(file_handler)
92    root_logger.addHandler(error_handler)
93
94    # Silence noisy third-party loggers
95    logging.getLogger("urllib3").setLevel(logging.WARNING)
96    logging.getLogger("sqlalchemy.engine").setLevel(logging.WARNING)
97
98    root_logger.info("Logging initialized (level=%s, dir=%s)", level, log_dir)
99
100
101# Initialize once at application startup
102# setup_logging(level="DEBUG")
103
104
105# ============================================================
106# Logging with structured context — the extra parameter
107# ============================================================
108logger = logging.getLogger("app.orders")
109
110def process_order(order_id: str, user_id: str, amount: float):
111    """Use structured logging with extra context."""
112    log = logging.LoggerAdapter(logger, {"order_id": order_id, "user_id": user_id})
113
114    log.info("Processing order for $%.2f", amount)
115
116    try:
117        # Simulate payment
118        if amount > 10000:
119            raise ValueError("Amount exceeds single transaction limit")
120        log.info("Payment processed successfully")
121    except ValueError as e:
122        # exc_info=True includes the full traceback in the log
123        log.error("Payment failed: %s", e, exc_info=True)
124        raise
125
126
127# ============================================================
128# JSON structured logging — for log aggregation systems
129# ============================================================
130import json
131import traceback
132
133class JSONFormatter(logging.Formatter):
134    """Format log records as JSON for ELK/Datadog/CloudWatch."""
135
136    def format(self, record: logging.LogRecord) -> str:
137        log_data = {
138            "timestamp": self.formatTime(record, self.datefmt),
139            "level": record.levelname,
140            "logger": record.name,
141            "message": record.getMessage(),
142            "module": record.module,
143            "function": record.funcName,
144            "line": record.lineno,
145            "process": record.process,
146            "thread": record.thread,
147        }
148
149        # Include exception info if present
150        if record.exc_info and record.exc_info[0] is not None:
151            log_data["exception"] = {
152                "type": record.exc_info[0].__name__,
153                "message": str(record.exc_info[1]),
154                "traceback": traceback.format_exception(*record.exc_info),
155            }
156
157        # Include any extra fields from LoggerAdapter or extra={}
158        for key in ("order_id", "user_id", "request_id", "duration_ms"):
159            if hasattr(record, key):
160                log_data[key] = getattr(record, key)
161
162        return json.dumps(log_data, default=str)
163
164
165# Apply JSON formatter for production
166def setup_json_logging():
167    handler = logging.StreamHandler(sys.stdout)
168    handler.setFormatter(JSONFormatter())
169    root = logging.getLogger()
170    root.handlers.clear()
171    root.addHandler(handler)
172    root.setLevel(logging.INFO)
173
174
175# ============================================================
176# Custom filter — add request context to all log messages
177# ============================================================
178import threading
179
180# Thread-local storage for request context
181_request_context = threading.local()
182
183class RequestContextFilter(logging.Filter):
184    """Inject request_id into every log record automatically."""
185
186    def filter(self, record: logging.LogRecord) -> bool:
187        record.request_id = getattr(_request_context, "request_id", "N/A")
188        record.client_ip = getattr(_request_context, "client_ip", "N/A")
189        return True  # Always pass — we're adding data, not filtering
190
191# Usage in a web framework middleware
192def handle_request(request):
193    """Simulate middleware that sets request context."""
194    import uuid
195    _request_context.request_id = str(uuid.uuid4())[:8]
196    _request_context.client_ip = "192.168.1.100"
197
198    logger = logging.getLogger("app.api")
199    logger.addFilter(RequestContextFilter())
200    logger.info("Handling request to /api/users")
201    # Log output includes: request_id=a1b2c3d4, client_ip=192.168.1.100
202
203
204# ============================================================
205# Dictionary-based configuration (logging.config.dictConfig)
206# ============================================================
207import logging.config
208
209LOGGING_CONFIG = {
210    "version": 1,
211    "disable_existing_loggers": False,
212    "formatters": {
213        "standard": {
214            "format": "%(asctime)s [%(levelname)s] %(name)s: %(message)s"
215        },
216        "json": {
217            "()": "__main__.JSONFormatter",  # Use custom formatter class
218        },
219    },
220    "handlers": {
221        "console": {
222            "class": "logging.StreamHandler",
223            "formatter": "standard",
224            "stream": "ext://sys.stderr",
225        },
226        "file": {
227            "class": "logging.handlers.RotatingFileHandler",
228            "formatter": "standard",
229            "filename": "logs/app.log",
230            "maxBytes": 10485760,
231            "backupCount": 5,
232        },
233    },
234    "loggers": {
235        "app": {
236            "handlers": ["console", "file"],
237            "level": "DEBUG",
238            "propagate": False,
239        },
240        "app.db": {
241            "handlers": ["file"],
242            "level": "WARNING",
243            "propagate": False,
244        },
245    },
246    "root": {
247        "handlers": ["console"],
248        "level": "WARNING",
249    },
250}
251
252# Apply configuration once at startup
253# logging.config.dictConfig(LOGGING_CONFIG)
254
255
256# ============================================================
257# Performance: lazy formatting and guards
258# ============================================================
259logger = logging.getLogger("app.perf")
260
261# GOOD — lazy formatting (string only built if level is enabled)
262logger.debug("Processing %d items: %r", len(items := [1, 2, 3]), items)
263
264# BAD — eager formatting (string always built, even if DEBUG is off)
265# logger.debug(f"Processing {len(items)} items: {items}")
266
267# Guard expensive operations
268if logger.isEnabledFor(logging.DEBUG):
269    # Only compute expensive_debug_info if DEBUG is enabled
270    debug_data = json.dumps(large_object, indent=2)
271    logger.debug("Full state dump:\n%s", debug_data)

🏋️ Practice Exercise

Exercises:

Set up a production logging configuration for a web application with three handlers: console (INFO+, colored), rotating file (DEBUG+, 10MB max, 5 backups), and a separate error file (ERROR+ only). Use dictConfig.
Create a JSONFormatter class that outputs structured JSON log lines with fields: timestamp, level, logger name, message, and any extra context fields. Test it with a LoggerAdapter that adds request_id and user_id.
Implement a custom logging Filter that: (a) redacts sensitive fields like passwords and tokens from log messages, (b) adds the current thread name, and (c) drops log records from a specific noisy logger.
Build a @log_call decorator that logs function entry (with arguments), exit (with return value and duration), and exceptions (with traceback). Use functools.wraps and handle both sync and async functions.
Write a performance benchmark comparing: (a) logger.debug("msg %s", val) (lazy), (b) logger.debug(f"msg {val}") (eager), and (c) guarded if logger.isEnabledFor(DEBUG) for an expensive computation. Measure with timeit at both DEBUG and WARNING levels.
Create a logging setup that sends ERROR+ logs to an external service (simulate with an HTTP POST to a local endpoint) using a QueueHandler + QueueListener pattern so logging never blocks the main application thread.

⚠️ Common Mistakes

Using f-strings in log calls: logger.info(f'User {user_id} logged in'). This eagerly formats the string even if the log level is disabled. Use %-style: logger.info('User %s logged in', user_id) — formatting is deferred until the message is actually emitted.
Calling logging.basicConfig() in library code. basicConfig configures the ROOT logger and should only be called once in the application's entry point. Libraries should only create loggers with getLogger(__name__) and let the application configure handlers.
Not setting propagate = False when adding handlers to child loggers. By default, log records propagate up to parent loggers. If both the child and root logger have handlers, you get duplicate log lines. Set propagate = False on loggers that have their own handlers.
Silencing exceptions with logger.error(str(e)) instead of logger.error('Message', exc_info=True). The former loses the traceback entirely. exc_info=True includes the full stack trace in the log, which is essential for debugging production issues.
Configuring logging after importing other modules. Python's logging configuration should happen as early as possible in the application startup. Modules imported before basicConfig/dictConfig may already have cached logger references with default (WARNING) configuration.

💼 Interview Questions

🎤 Mock Interview

Practice a live interview for Logging: Levels, Handlers, Formatters & Structured Logging

Was this topic helpful?

← PreviousSerialization: JSON, CSV, Pickle, YAML & TOML Next →Decorators