--- title: structlog Setup — Oliver Standard aliases: - structlog pattern - structured logging tags: - python - structlog - shared-pattern - oliver sources: - cc-dashboard/src/main.py - cc-dashboard/src/middleware/logging.py - ac-tool/backend/server/app.py - ac-helper/backend/server/app.py created: 2026-05-15 updated: 2026-05-15 --- ## Key Takeaways - Two distinct `structlog.configure()` styles coexist across Oliver projects: a **modern** one (cc-dashboard, FastAPI) using `make_filtering_bound_logger` + `PrintLoggerFactory`, and a **stdlib-bridge** one (ac-tool / ac-helper, Quart) using `stdlib.LoggerFactory` + `stdlib.BoundLogger`. - The modern FastAPI pattern switches renderer based on a `LOG_FORMAT` env var (`json` → `JSONRenderer`, anything else → `ConsoleRenderer` with colors). - Request-scoped context (`request_id`, `method`, `path`) is injected via `structlog.contextvars` in a Starlette middleware and cleaned up in `finally`. - `cache_logger_on_first_use=True` is set in all projects — mandatory for production performance. - `structlog.configure()` is called inside the FastAPI `lifespan` function, not at module import time. ## Standard Setup ### Modern pattern (cc-dashboard / FastAPI) From `cc-dashboard/src/main.py` — the canonical Oliver FastAPI setup: ```python import logging import structlog def _configure_logging() -> None: shared_processors = [ structlog.contextvars.merge_contextvars, structlog.stdlib.add_log_level, structlog.processors.TimeStamper(fmt="iso"), ] if settings.LOG_FORMAT == "json": renderer = structlog.processors.JSONRenderer() else: renderer = structlog.dev.ConsoleRenderer(colors=True) structlog.configure( processors=shared_processors + [renderer], wrapper_class=structlog.make_filtering_bound_logger(logging.INFO), context_class=dict, logger_factory=structlog.PrintLoggerFactory(), cache_logger_on_first_use=True, ) ``` Called in the lifespan: ```python from contextlib import asynccontextmanager from fastapi import FastAPI @asynccontextmanager async def lifespan(app: FastAPI): _configure_logging() # ... other startup yield # ... shutdown app = FastAPI(lifespan=lifespan) ``` ### Stdlib-bridge pattern (ac-tool / ac-helper / Quart) From `ac-tool/backend/server/app.py` and `ac-helper/backend/server/app.py` (identical): ```python import structlog structlog.configure( processors=[ structlog.stdlib.filter_by_level, structlog.stdlib.add_logger_name, structlog.stdlib.add_log_level, structlog.stdlib.PositionalArgumentsFormatter(), structlog.processors.TimeStamper(fmt="ISO"), structlog.processors.StackInfoRenderer(), structlog.processors.format_exc_info, structlog.processors.JSONRenderer(), ], context_class=dict, logger_factory=structlog.stdlib.LoggerFactory(), wrapper_class=structlog.stdlib.BoundLogger, cache_logger_on_first_use=True, ) logger = structlog.get_logger(__name__) ``` This pattern always outputs JSON (no dev/prod switch). The `format_exc_info` processor formats exception tracebacks into the JSON log entry. ## Usage Pattern Getting a logger and using it in FastAPI: ```python import structlog # Module level — fine with cache_logger_on_first_use=True log = structlog.get_logger() # In a route or service log.info("work_item_fetched", work_item_id=work_item_id, project=project) log.warning("rate_limit_approaching", remaining=remaining, endpoint=url) log.error("ado_api_error", status=resp.status_code, url=url) ``` Request context middleware (from `cc-dashboard/src/middleware/logging.py`): ```python import time import uuid import structlog from fastapi import Request, Response from starlette.middleware.base import BaseHTTPMiddleware log = structlog.get_logger() class LoggingMiddleware(BaseHTTPMiddleware): async def dispatch(self, request: Request, call_next) -> Response: request_id = str(uuid.uuid4())[:8] start = time.perf_counter() structlog.contextvars.bind_contextvars( request_id=request_id, method=request.method, path=request.url.path, ) try: response = await call_next(request) duration = round((time.perf_counter() - start) * 1000, 1) log.info("request", status=response.status_code, duration_ms=duration) return response finally: structlog.contextvars.unbind_contextvars("request_id", "method", "path") ``` Register in app: ```python app.add_middleware(LoggingMiddleware) ``` ## JSON vs Console Output Controlled by `settings.LOG_FORMAT` in cc-dashboard: | `LOG_FORMAT` value | Renderer | Use | |-------------------|----------|-----| | `"json"` | `structlog.processors.JSONRenderer()` | Production (Docker, GCP Logging) | | anything else (e.g. `"text"`) | `structlog.dev.ConsoleRenderer(colors=True)` | Local dev | Typical `.env` entries: ```env # dev LOG_FORMAT=text # prod / docker-compose.prod.yml LOG_FORMAT=json ``` The Quart projects (ac-tool, ac-helper) always use `JSONRenderer` — no switch; they were designed for server-only deployment from the start. ## Gotchas **1. `_configure_logging()` must be called before any logger is used.** If `structlog.get_logger()` is called at module import time and `structlog.configure()` runs later (e.g. on first request), the logger uses structlog defaults (no processors, no renderer). Always call `configure()` in `lifespan` startup, before importing routers that create module-level loggers. cc-dashboard works around this by delaying imports of routers until after configure is called. **2. `contextvars.unbind_contextvars` must be in `finally`.** If an unhandled exception escapes `call_next`, the bound context (`request_id`, etc.) leaks into subsequent requests on the same event-loop task. The `finally` block in `LoggingMiddleware` ensures cleanup even on 500 errors. **3. `make_filtering_bound_logger(logging.INFO)` vs `stdlib.BoundLogger`.** The modern pattern uses `make_filtering_bound_logger` which compiles level checks at bind time — faster. The stdlib-bridge pattern uses `stdlib.BoundLogger` which integrates with Python's `logging` module (needed for third-party libraries that use `logging.getLogger`). Don't mix them in the same app. **4. `cache_logger_on_first_use=True` is required in production.** Without it, structlog rebuilds the processor chain on every log call. With it, the chain is compiled after the first call. This flag must be set; it's present in all Oliver projects. ## Related - [[wiki/shared-patterns/httpx-async-client]] - [[wiki/tech-patterns/fastapi-python-docker]] - [[wiki/tech-patterns/cost-tracker-integration]]