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

---
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]]