Structured Logging with `structlog`Structured logging is a modern approach to logging where log events are emitted in a machine-readable format, typically JSON, rather than as free-form text strings. Each log entry consists of key-value pairs, providing explicit context about the event. This makes logs significantly easier to search, filter, aggregate, and analyze using log management systems like ELK Stack (Elasticsearch, Logstash, Kibana), Splunk, Grafana Loki, etc.
`structlog` is a powerful, flexible, and fast Python library designed specifically for structured logging. It doesn't replace Python's standard `logging` module but rather acts as a sophisticated frontend or wrapper around it (though it can also be used independently). `structlog` excels at attaching rich, contextual data to log events in an immutable, pipeline-driven manner.
Key Concepts of `structlog`:
1. Processors: `structlog` operates using a pipeline of 'processors'. Each processor is a function that takes a logger instance, event name, and an event dictionary, and transforms them. These processors are chained together to build the final log entry. Examples include `add_logger_name`, `add_timestamp`, `format_exc_info` (for exception details), and renderers like `JSONRenderer` or `ConsoleRenderer`.
2. Contextual Logging: The core strength of `structlog` is its ability to easily attach context (key-value pairs) to log events. This context can be bound to a logger instance (creating a new, immutable logger with the added context) or passed directly with individual log calls.
3. Logger Factories: These determine how logger instances are created. `structlog.stdlib.LoggerFactory` is commonly used to integrate with the standard `logging` module, allowing `structlog` to leverage `logging`'s handlers and formatters. `structlog.PrintLoggerFactory` can be used for simpler direct output.
4. Wrapper Class: `structlog.stdlib.BoundLogger` is often used when integrating with the standard library, providing methods like `.info()`, `.error()`, etc., that accept key-value arguments.
5. Immutability: When you bind context to a `structlog` logger (e.g., `log.bind(user_id=123)`), it returns a -new- logger instance with the added context. The original logger remains unchanged, promoting thread-safety and predictability.
Benefits of `structlog`:
- Rich Context: Easily add relevant data (e.g., `user_id`, `request_id`, `transaction_id`) to every log entry, making debugging and analysis much more effective.
- Machine-Readable Output: Out-of-the-box support for JSON output, which is ideal for modern log aggregation systems.
- Highly Customizable: The processor pipeline offers immense flexibility to transform log data exactly as needed.
- Separation of Concerns: `structlog` handles the -what- to log (context and event) and the -transformation-, while standard `logging` (when used as a backend) handles the -where- to log (handlers).
- Improved Developer Experience: Encourages consistent and structured logging practices across an application.
Example Code
import logging
import structlog
import sys
--- 1. Configure structlog's processor pipeline ---
These processors transform the event dictionary into the final log entry.
The order of processors matters.
structlog.configure(
processors=[
structlog.stdlib.add_logger_name, Adds "logger" field (e.g., "my_app.service")
structlog.stdlib.add_log_level, Adds "level" field (e.g., "info", "error")
structlog.processors.TimeStamper(fmt="iso"), Adds "timestamp" field in ISO format
structlog.processors.StackInfoRenderer(), Adds stack info for errors
structlog.dev.set_exc_info, Catches exc_info for exceptions
Conditionally render to console-friendly or JSON based on stdout being a TTY
structlog.dev.ConsoleRenderer() if sys.stdout.isatty() else structlog.processors.JSONRenderer(),
For sending to standard logging, this processor wraps the event dict
so that it can be handled by standard logging formatters.
structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
],
logger_factory=structlog.stdlib.LoggerFactory(), Uses standard logging loggers as backend
wrapper_class=structlog.stdlib.BoundLogger, Wrapper for contextual logging
cache_logger_on_first_use=True,
)
--- 2. Configure standard logging (if using structlog as a frontend to logging) ---
This setup demonstrates routing structlog output through stdlib logging handlers.
If you just want structlog to print directly, you might skip or simplify this.
handler = logging.StreamHandler(sys.stdout)
ProcessorFormatter allows structlog's processors to prepare the log message
before it reaches a standard logging handler. The foreign_pre_chain defines
which processors run -before- the message is passed to the formatter.
formatter = structlog.stdlib.ProcessorFormatter(
processor=structlog.dev.ConsoleRenderer() if sys.stdout.isatty() else structlog.processors.JSONRenderer(),
foreign_pre_chain=[
structlog.stdlib.add_logger_name,
structlog.stdlib.add_log_level,
structlog.processors.TimeStamper(fmt="iso"),
structlog.processors.StackInfoRenderer(),
structlog.dev.set_exc_info,
]
)
handler.setFormatter(formatter)
root_logger = logging.getLogger()
root_logger.addHandler(handler)
root_logger.setLevel(logging.INFO) Set the minimum logging level
Set propagate to False to prevent duplicate logs if other handlers (like default root handler)
are also processing messages from this logger.
root_logger.propagate = False
--- 3. Get a structlog logger instance ---
log = structlog.get_logger("my_app.service")
--- 4. Basic logging ---
print("\n--- Basic Logging ---")
log.info("Application started")
log.debug("This won't be shown because the root_logger level is INFO")
log.warning("Something potentially bad happened", event_id="E001", component="setup")
--- 5. Adding context for a specific log call ---
print("\n--- Logging with Inline Context ---")
user_id = "user123"
log.info("User logged in", user_id=user_id, source_ip="192.168.1.10")
--- 6. Binding context to a logger for subsequent calls (immutable) ---
print("\n--- Logging with Bound Context ---")
request_id = "req_abc456"
transaction_log = log.bind(request_id=request_id)
transaction_log.info("Processing request", data_size=1024)
transaction_log.error("Failed to process part of request", error_code="P500", exception_details="Timeout")
The original 'log' logger is unaffected by the .bind() call
log.info("Another general event, without request context (original logger)")
--- 7. Error logging with exception info ---
print("\n--- Exception Logging ---")
try:
1 / 0
except ZeroDivisionError as e:
structlog.dev.set_exc_info and structlog.processors.StackInfoRenderer
in the processors list handle formatting exception details.
log.exception("An error occurred during calculation", operation="divide", details=str(e))
--- 8. Chaining binds (adds more context incrementally) ---
print("\n--- Chained Bound Context ---")
user_log = log.bind(user_id="another_user")
specific_request_log = user_log.bind(request_id="req_xyz789", endpoint="/api/data")
specific_request_log.info("Data fetched successfully", records=100)
This debug log won't show due to root_logger level being INFO
specific_request_log.debug("Detailed debug info for data fetch, hidden by log level")
--- Example using a logger directly without the standard 'logging' backend ---
This demonstrates structlog printing directly to stdout/stderr without involving
the standard 'logging' module or its handlers/levels for this specific logger.
print("\n--- Direct structlog output (no stdlib logging backend) ---")
structlog.configure(
processors=[
structlog.stdlib.add_logger_name,
structlog.stdlib.add_log_level,
structlog.processors.TimeStamper(fmt="iso"),
structlog.dev.ConsoleRenderer() Only console rendering for this example
],
logger_factory=structlog.PrintLoggerFactory(), Direct print to stdout/stderr
wrapper_class=structlog.PrintLogger, Corresponding wrapper for PrintLoggerFactory
cache_logger_on_first_use=False Set to False for demonstration isolation if needed
)
direct_log = structlog.get_logger("my_app.direct_printer")
direct_log.info("This log goes directly to stdout via PrintLoggerFactory")
direct_log.warning("It can also include context", additional_key="value", source="direct_example")