obsidian/wiki/shared-patterns/structlog-setup.md

title	aliases	tags	sources	created	updated
structlog Setup — Oliver Standard	structlog pattern structured logging	python structlog shared-pattern oliver	cc-dashboard/src/main.py cc-dashboard/src/middleware/logging.py ac-tool/backend/server/app.py ac-helper/backend/server/app.py	2026-05-15	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:

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:

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):

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:

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):

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:

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:

# 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