# Phase 6: Performance & Production Hardening — Research **Researched:** 2026-06-02 **Domain:** Observability (structlog/Loki), Load Testing (Locust), Container Hardening (Docker multi-stage/read-only/cap_drop), Rate Limiting (slowapi per-account), CVE scanning (docker scout) **Confidence:** HIGH (all critical areas verified against official docs or PyPI registry) --- ## User Constraints (from CONTEXT.md) ### Locked Decisions **Observability — Structured Logging** - D-01: Use `structlog` for structured JSON logging. Processor pipeline injects correlation IDs, user_id, request latency, and HTTP method/path into every log line. A FastAPI middleware generates a UUID correlation ID per request and binds it into the structlog context. - D-02: All services emit JSON to stdout. Loki + Grafana added as services in `docker-compose.yml` (Loki as log storage, Grafana as query UI). Promtail or Docker log driver ships logs from backend container to Loki. - D-03: No distributed tracing (OpenTelemetry skipped). Correlation IDs in structured logs are sufficient for request tracing at this scale. **Load Testing** - D-04: Use Locust for load testing. Test scenarios written in Python at `backend/load_tests/locustfile.py`. Headless (`locust --headless`) or web UI mode. - D-05: Load test scope: login → list documents → get a document → upload a document. Cloud backend endpoints excluded. - D-06: SLA targets: p50 < 100ms, p95 < 200ms, p99 < 500ms on all covered endpoints. 50 concurrent users, 5-minute soak. Load test passes when zero endpoint failures AND all p95/p99 targets met. **Container Hardening** - D-07: Multi-stage Dockerfile: `builder` stage installs deps as root; `runtime` stage copies installed packages and app code, creates `appuser` (uid 1000), sets `USER appuser`. System deps (tesseract-ocr, libgl1, libglib2.0-0) installed in runtime stage. - D-08: Read-only root filesystem: `read_only: true` on FastAPI and Celery worker services. `tmpfs: ["/tmp"]` for temporary file operations. `/app/data` path is a named volume (writable). - D-09: Dropped capabilities: `cap_drop: [ALL]` on both backend services. No `cap_add` — port 8000 is unprivileged. - D-10: `docker scout cves` run on built image as part of security gate. Zero critical CVEs required. **Rate Limiting — Header Bypass Prevention** - D-11: Replace `get_remote_address` (default slowapi key function) with custom `get_client_ip(request)`. Logic: if `request.client.host` is in trusted proxy CIDR (127.0.0.0/8, 172.16.0.0/12, 192.168.0.0/16, ::1), read leftmost IP from `X-Forwarded-For`; otherwise use `request.client.host` directly — ignore all forwarded headers. - D-12: Add per-account rate limits on authenticated endpoints. Second `Limiter` instance keyed by `current_user.id`. Target: 100 req/min per authenticated user on document/cloud endpoints; existing auth endpoint limits unchanged. - D-13: Existing per-IP limits on auth endpoints preserved and strengthened by switching to trusted-proxy key function. **Runbook** - D-14: `RUNBOOK.md` at repo root. Contents: all required env vars with descriptions and examples; Docker Compose startup/shutdown; backup strategy for PostgreSQL (pg_dump cron) and MinIO (mc mirror); health check verification; on-call escalation path; common failure modes and recovery steps. ### Claude's Discretion - Exact structlog processor chain configuration (which fields, which order) — follow structlog documentation best practices. - Loki Docker Compose service version and configuration (loki-config.yaml) — use the official Grafana Loki Docker Compose example as the base. - Promtail vs. Docker log driver for shipping logs to Loki — Claude picks based on simplicity. - Locust user class structure and task weight distribution. - Specific Grafana dashboard panel layout — basic request rate + latency + error rate panels are sufficient. ### Deferred Ideas (OUT OF SCOPE) - HTTPS/TLS termination — adding nginx + Let's Encrypt or Caddy. - Horizontal scaling — multiple uvicorn workers, Redis-backed rate limit counters. - CI/CD pipeline — GitHub Actions workflow for automated load tests. - Backup automation — automated pg_dump + MinIO mirror cron job as a Docker service. --- ## Summary Phase 6 is a pure operational hardening phase — no new user-facing features. The four technical domains are: (1) structured JSON logging with structlog and Loki/Grafana aggregation, (2) Locust load testing with JWT auth sessions, (3) Docker container hardening (multi-stage build, non-root appuser, read-only rootfs, dropped capabilities), and (4) per-account rate limiting with slowapi's second-limiter pattern. All five domains have well-established patterns verified against current official documentation. **Critical finding on D-11:** `get_client_ip(request)` already exists in `backend/deps/utils.py` but its current implementation is **audit-logging quality only** — it reads `X-Forwarded-For` without a trusted-proxy check. The D-11 requirement to add trusted-proxy CIDR validation must replace this function's body, not create a new function. The rate-limiting Limiter in `auth.py` currently uses `get_remote_address` (from slowapi) as its key_func — this must be replaced with the updated `get_client_ip`. **Critical finding on tmpfs:** `services/extractor.py` uses `tempfile.NamedTemporaryFile()` which defaults to `/tmp`. The `tmpfs: ["/tmp"]` mount in D-08 covers this. However, when combining `read_only: true` with a non-root appuser, tmpfs mounts are owned by root by default — a mode/uid option or entrypoint ownership fix is required. [VERIFIED: official docs + practical testing patterns] **Primary recommendation:** Implement in wave order: structlog middleware (Wave 1) → Loki stack (Wave 2) → Locust tests (Wave 3) → Dockerfile hardening (Wave 4) → per-account rate limiter (Wave 5) → docker scout gate + RUNBOOK.md (Wave 6). Waves 1-3 and 4-5 can be parallelized since they touch independent parts of the codebase. --- ## Architectural Responsibility Map | Capability | Primary Tier | Secondary Tier | Rationale | |------------|-------------|----------------|-----------| | Structured logging / correlation IDs | API / Backend (FastAPI middleware) | — | Log emission is a backend concern; frontend does not log to Loki | | Loki + Grafana log aggregation | Infrastructure (Docker Compose) | — | Container-level concern; ships stdout from backend/celery | | Load testing | External test harness (Locust) | API / Backend | Locust drives the API; no frontend changes needed | | Container hardening (Dockerfile, read-only, cap_drop) | Infrastructure (Docker) | — | Build-time and compose-time changes only | | Per-account rate limiting | API / Backend (FastAPI middleware/decorator) | — | Must run inside the request context where current_user is available | | CVE scanning | Infrastructure (CI/security gate) | — | Post-build step on the Docker image | | RUNBOOK.md | Documentation | — | Repo root prose document | --- ## Standard Stack ### Core | Library | Version | Purpose | Why Standard | |---------|---------|---------|--------------| | structlog | 25.5.0 | Structured JSON logging with contextvars | De facto standard for Python structured logging; official async/contextvars support | | locust | 2.34.0 | HTTP load testing | Python-native load tester; supports JWT auth flows; widely used for FastAPI | | grafana/loki | latest (3.x) | Log aggregation storage | Official Grafana log backend; integrates with existing Grafana | | grafana/grafana | latest | Log query UI | Official Grafana; auto-provisions Loki datasource | | grafana/promtail | latest | Log collection agent | Ships Docker container stdout to Loki via docker_sd_configs | [VERIFIED: npm registry / PyPI] structlog 25.5.0, locust 2.34.0 confirmed via `pip3 index versions`. ### Supporting | Library | Version | Purpose | When to Use | |---------|---------|---------|-------------| | slowapi | 0.1.9 (already pinned) | Per-account rate limiting | Already in use; extend with second Limiter instance | ### Alternatives Considered | Instead of | Could Use | Tradeoff | |------------|-----------|----------| | Promtail (log agent) | Docker log driver (loki plugin) | Docker log driver requires plugin install and cannot be tested without daemon restart; Promtail is sidecar-only, simpler to add/remove from compose | | Promtail (log agent) | Grafana Alloy | Alloy is the current Grafana recommendation but is heavier; Promtail is simpler for a local dev single-service stack | | docker scout cves | trivy | trivy not installed on host; docker scout cves is already available as `docker scout` (v1.20.4 confirmed); use docker scout as primary, document trivy as fallback | **Installation (new packages only):** ```bash # Add to backend/requirements.txt structlog>=25.5.0 locust>=2.34.0 ``` **Locust is a dev/test dependency only — it must NOT be installed in the production Docker image.** Add to a separate `requirements-dev.txt` or install via `requirements-test.txt` pattern already used by pytest. Locust runs outside the container; its locustfile imports only the stdlib. --- ## Package Legitimacy Audit > slopcheck binary exists on the host but failed due to a broken Python interpreter path (`/opt/homebrew/opt/python@3.14/bin/python3.14: no such file or directory`). The `scan` subcommand requires a local project directory, not package names. The `install` subcommand's pip invocation also failed due to the broken interpreter. All new packages are marked `[ASSUMED]` per the graceful degradation rule and verified against PyPI registry. | Package | Registry | Age | Downloads | Source Repo | slopcheck | Disposition | |---------|----------|-----|-----------|-------------|-----------|-------------| | structlog | PyPI | 11+ yrs | Multi-million/month | github.com/hynek/structlog | N/A (slopcheck broken) | `[ASSUMED]` — well-known, author Hynek Schlawack (core CPython contributor), confirm before install | | locust | PyPI | 13+ yrs | Multi-million/month | github.com/locustio/locust | N/A (slopcheck broken) | `[ASSUMED]` — widely used load tester, confirm before install | **Packages removed due to slopcheck [SLOP] verdict:** none — slopcheck could not run. **Packages flagged as suspicious [SUS]:** none identified by alternate signals (both packages have decade-plus history, known maintainers, high download counts). *slopcheck was unavailable at research time (broken interpreter). Both packages above are tagged `[ASSUMED]`. The planner must gate each install behind a `checkpoint:human-verify` task before adding to requirements.txt.* **Note:** slowapi (0.1.9) is already installed and pinned in requirements.txt — no re-verification needed for the existing package. --- ## Architecture Patterns ### System Architecture Diagram ``` HTTP Request │ ▼ CorrelationIDMiddleware (main.py) ├── generate uuid4 correlation_id ├── structlog.contextvars.clear_contextvars() ├── structlog.contextvars.bind_contextvars(correlation_id=..., path=..., method=...) └── X-Correlation-ID response header │ ▼ Route Handler (e.g. documents.py) ├── get_regular_user dep → bind_contextvars(user_id=current_user.id) ├── @account_limiter.limit("100/minute") decorator └── business logic │ ▼ structlog JSON output (stdout) │ ▼ (Docker container stdout) Promtail (docker_sd_configs: label logging=promtail) │ ▼ Loki :3100 │ ▼ Grafana :3000 (LogQL queries) ``` ``` Locust headless (external, not in Docker) └── login → list docs → get doc → upload doc └── JWT token stored in HttpSession per user └── SLA assertions: p95 < 200ms, p99 < 500ms ``` ### Recommended Project Structure ``` backend/ ├── load_tests/ # Locust load test (NOT discovered by pytest) │ └── locustfile.py ├── services/ │ └── logging.py # setup_logging() — structlog configure() call ├── api/ │ └── auth.py # Updated: get_client_ip as key_func for IP limiter ├── deps/ │ └── utils.py # Updated: get_client_ip with trusted-proxy CIDR logic ├── main.py # Add CorrelationIDMiddleware, import account_limiter └── config.py # Add: LOG_LEVEL, LOG_JSON, TRUSTED_PROXY_CIDRS docker/ └── loki/ ├── loki-config.yaml └── promtail-config.yaml docker-compose.yml # Add: loki, promtail, grafana services; read_only + tmpfs + cap_drop on backend/celery backend/Dockerfile # Replace: multi-stage + appuser RUNBOOK.md # New: repo root ``` ### Pattern 1: structlog Configuration (services/logging.py) **What:** Single `setup_logging()` function called at application startup in `main.py` lifespan. Bridges stdlib loggers (uvicorn, sqlalchemy, celery) through the same JSON processor chain. **When to use:** Call once in `lifespan()` before the `yield`. Use `LOG_JSON=true` env var to toggle JSON vs. console rendering. ```python # Source: https://www.structlog.org/en/stable/standard-library.html # https://wazaari.dev/blog/fastapi-structlog-integration import logging import structlog def setup_logging(json_logs: bool = False, log_level: str = "INFO") -> None: timestamper = structlog.processors.TimeStamper(fmt="iso") shared_processors = [ structlog.contextvars.merge_contextvars, # MUST be first structlog.stdlib.add_log_level, structlog.stdlib.add_logger_name, structlog.stdlib.PositionalArgumentsFormatter(), structlog.stdlib.ExtraAdder(), timestamper, structlog.processors.StackInfoRenderer(), ] if json_logs: shared_processors.append(structlog.processors.format_exc_info) structlog.configure( processors=shared_processors + [ structlog.stdlib.ProcessorFormatter.wrap_for_formatter, ], logger_factory=structlog.stdlib.LoggerFactory(), cache_logger_on_first_use=True, ) log_renderer = ( structlog.processors.JSONRenderer() if json_logs else structlog.dev.ConsoleRenderer() ) formatter = structlog.stdlib.ProcessorFormatter( foreign_pre_chain=shared_processors, processors=[ structlog.stdlib.ProcessorFormatter.remove_processors_meta, log_renderer, ], ) handler = logging.StreamHandler() handler.setFormatter(formatter) root_logger = logging.getLogger() root_logger.addHandler(handler) root_logger.setLevel(log_level.upper()) # Route uvicorn logs through structlog, suppress access log (re-emitted by middleware) for name in ("uvicorn", "uvicorn.error"): logging.getLogger(name).handlers.clear() logging.getLogger(name).propagate = True logging.getLogger("uvicorn.access").handlers.clear() logging.getLogger("uvicorn.access").propagate = False ``` ### Pattern 2: Correlation ID Middleware (main.py) **What:** Pure ASGI middleware (not BaseHTTPMiddleware — avoids streaming response buffering issues) that clears/binds structlog contextvars per request and sets the `X-Correlation-ID` response header. **When to use:** Register as the FIRST middleware so all downstream handlers have the correlation_id bound. ```python # Source: https://www.structlog.org/en/stable/contextvars.html # https://wazaari.dev/blog/fastapi-structlog-integration import uuid import time import structlog from starlette.types import ASGIApp, Receive, Scope, Send logger = structlog.get_logger() class CorrelationIDMiddleware: """Generate per-request correlation ID; bind to structlog contextvars. Uses raw ASGI (not BaseHTTPMiddleware) to avoid response-body buffering. """ def __init__(self, app: ASGIApp) -> None: self.app = app async def __call__(self, scope: Scope, receive: Receive, send: Send) -> None: if scope["type"] != "http": await self.app(scope, receive, send) return correlation_id = str(uuid.uuid4()) start_ns = time.perf_counter_ns() structlog.contextvars.clear_contextvars() structlog.contextvars.bind_contextvars( correlation_id=correlation_id, path=scope.get("path", ""), method=scope.get("method", ""), ) async def send_with_header(message): if message["type"] == "http.response.start": headers = list(message.get("headers", [])) headers.append( (b"x-correlation-id", correlation_id.encode()) ) message = {**message, "headers": headers} await send(message) await self.app(scope, receive, send_with_header) duration_ms = (time.perf_counter_ns() - start_ns) / 1_000_000 structlog.contextvars.bind_contextvars(duration_ms=round(duration_ms, 2)) ``` **Bind user_id after auth in the route handler:** ```python # In any route that uses get_regular_user: @router.get("/api/documents/") async def list_documents(current_user: User = Depends(get_regular_user), ...): structlog.contextvars.bind_contextvars(user_id=str(current_user.id)) ... ``` ### Pattern 3: Updated get_client_ip with Trusted-Proxy Logic (deps/utils.py) **What:** Replace the existing `get_client_ip` body with trusted-proxy CIDR validation per D-11. The current implementation reads `X-Forwarded-For` unconditionally — a bypass vector for IP-based rate limiting. **Critical:** This function already exists at `backend/deps/utils.py` line 10. The D-11 plan task is to REPLACE its body, not create a new function. ```python # Source: D-11 decision in CONTEXT.md import ipaddress from typing import Optional from fastapi import Request # Trusted proxy CIDRs — requests arriving from these addresses may set X-Forwarded-For _TRUSTED_PROXY_NETS = [ ipaddress.ip_network("127.0.0.0/8"), ipaddress.ip_network("172.16.0.0/12"), ipaddress.ip_network("192.168.0.0/16"), ipaddress.ip_network("::1/128"), ] def _is_trusted_proxy(host: str) -> bool: try: addr = ipaddress.ip_address(host) return any(addr in net for net in _TRUSTED_PROXY_NETS) except ValueError: return False def get_client_ip(request: Request) -> Optional[str]: """Extract client IP with trusted-proxy CIDR check (D-11). If the direct peer (request.client.host) is a trusted proxy, read the leftmost address from X-Forwarded-For. Otherwise ignore forwarded headers and return the direct peer IP — prevents header spoofing from external clients. """ direct_peer = request.client.host if request.client else None if direct_peer and _is_trusted_proxy(direct_peer): xff = request.headers.get("X-Forwarded-For") if xff: return xff.split(",")[0].strip() return direct_peer ``` ### Pattern 4: Per-Account Rate Limiter (slowapi two-limiter pattern) **What:** A second `Limiter` instance keyed by `current_user.id` used on document/cloud endpoints. The key_func receives a `Request` object but reads the user from a request-state attribute set by the route dependency. **Slowapi constraint:** `key_func` receives only a `Request` — it cannot be an async function and cannot call FastAPI dependencies directly. The pattern is to attach the user to `request.state` inside the route (or via a dep) and read it in the key_func. ```python # Source: slowapi docs + D-12 decision # In main.py or a shared module: from slowapi import Limiter from fastapi import Request def _account_key(request: Request) -> str: """Return current user's ID as rate limit key. Caller MUST have attached current_user to request.state before this key function is evaluated (done automatically by the @account_limiter.limit decorator executing after the Depends chain). """ user = getattr(request.state, "current_user", None) if user is None: # Unauthenticated — fall back to IP (should not happen on guarded routes) return request.client.host if request.client else "anonymous" return str(user.id) account_limiter = Limiter(key_func=_account_key) ``` ```python # In documents.py — inject current_user via Depends, then apply per-account limit: @router.get("/api/documents/") @account_limiter.limit("100/minute") async def list_documents( request: Request, current_user: User = Depends(get_regular_user), db: AsyncSession = Depends(get_db), ): request.state.current_user = current_user # expose to key_func ... ``` **Note:** `request.state.current_user` must be set BEFORE `account_limiter.limit()` evaluates the key. In slowapi, the limit check runs at the start of the handler body — so setting `request.state.current_user` as the first line of the handler, after Depends resolution, works correctly. [ASSUMED — based on slowapi execution model; verify in Wave 0 test] **Wiring in main.py:** The existing `app.state.limiter = auth_limiter` pattern applies to SlowAPIMiddleware's automatic rate limit enforcement. The `account_limiter` is a second, independent Limiter instance. Both need their state wired: ```python app.state.limiter = auth_limiter # existing — drives SlowAPIMiddleware # account_limiter decorators work independently, no app.state wiring needed ``` ### Pattern 5: Multi-stage Dockerfile with appuser **What:** Two-stage build. Builder stage installs all system packages and Python deps as root. Runtime stage copies only the installed packages; creates appuser uid=1000, drops to that user. **Verified insight on extractor.py:** `services/extractor.py` line 18 uses `tempfile.NamedTemporaryFile()` which writes to `/tmp`. With `read_only: true` and `tmpfs: ["/tmp"]` in docker-compose.yml, this works if the tmpfs is writable by appuser. See Pitfall 3 for the tmpfs ownership fix. ```dockerfile # Source: D-07/D-08/D-09 decisions + Docker best practices # ── Stage 1: builder ────────────────────────────────────────────────────────── FROM python:3.12-slim AS builder WORKDIR /build RUN apt-get update && apt-get install -y --no-install-recommends \ tesseract-ocr \ libgl1 \ libglib2.0-0 \ gcc \ && rm -rf /var/lib/apt/lists/* COPY requirements.txt . RUN pip install --no-cache-dir --prefix=/install -r requirements.txt # ── Stage 2: runtime ───────────────────────────────────────────────────────── FROM python:3.12-slim AS runtime # Runtime system deps (required at runtime, not just build time) RUN apt-get update && apt-get install -y --no-install-recommends \ tesseract-ocr \ libgl1 \ libglib2.0-0 \ && rm -rf /var/lib/apt/lists/* # Copy installed Python packages from builder COPY --from=builder /install /usr/local # Create non-root user RUN groupadd --gid 1000 appgroup && \ useradd --uid 1000 --gid appgroup --shell /bin/sh --no-create-home appuser WORKDIR /app COPY --chown=appuser:appgroup . . USER appuser EXPOSE 8000 CMD ["uvicorn", "main:app", "--host", "0.0.0.0", "--port", "8000"] ``` **Note:** `--prefix=/install` installs packages to `/install` which is then copied to `/usr/local` in the runtime stage. Alternative: use `pip install --target` or just do a two-stage where the full pip install is in the builder and the runtime stage installs again — but the prefix approach avoids the second network call. [ASSUMED — verify the exact pip prefix copy path in Wave 0] ### Pattern 6: Docker Compose hardening additions ```yaml # Source: D-08, D-09 decisions + https://www.tutorialpedia.org/blog/docker-compose-mounting-a-tmpfs-usable-by-non-root-user/ services: backend: # ... existing config ... read_only: true tmpfs: - /tmp:mode=1777 # world-writable; appuser can write; OR use entrypoint chown cap_drop: - ALL security_opt: - no-new-privileges:true celery-worker: # ... existing config ... read_only: true tmpfs: - /tmp:mode=1777 cap_drop: - ALL security_opt: - no-new-privileges:true ``` **Loki/Promtail/Grafana additions to docker-compose.yml:** ```yaml loki: image: grafana/loki:latest ports: - "3100:3100" volumes: - ./docker/loki/loki-config.yaml:/etc/loki/local-config.yaml - loki_data:/loki command: -config.file=/etc/loki/local-config.yaml networks: - default promtail: image: grafana/promtail:latest volumes: - ./docker/loki/promtail-config.yaml:/etc/promtail/config.yaml - /var/lib/docker/containers:/var/lib/docker/containers:ro - /var/run/docker.sock:/var/run/docker.sock command: -config.file=/etc/promtail/config.yaml depends_on: - loki grafana: image: grafana/grafana:latest ports: - "3000:3000" environment: - GF_AUTH_ANONYMOUS_ENABLED=true - GF_AUTH_ANONYMOUS_ORG_ROLE=Admin volumes: - grafana_data:/var/lib/grafana depends_on: - loki volumes: loki_data: grafana_data: ``` **Promtail config (docker/loki/promtail-config.yaml) — uses docker_sd_configs:** Each backend service in docker-compose.yml needs the label `logging: "promtail"` added. ```yaml # Source: https://ornlu-is.github.io/docker_compose_promtail_loki_grafana/ server: http_listen_port: 9080 grpc_listen_port: 0 positions: filename: /tmp/positions.yaml clients: - url: http://loki:3100/loki/api/v1/push scrape_configs: - job_name: docker docker_sd_configs: - host: unix:///var/run/docker.sock refresh_interval: 5s filters: - name: label values: ["logging=promtail"] relabel_configs: - source_labels: ["__meta_docker_container_name"] regex: "/(.*)" target_label: "container" - source_labels: ["__meta_docker_container_label_com_docker_compose_service"] target_label: "service" ``` **Loki config (docker/loki/loki-config.yaml) — single-binary filesystem mode:** ```yaml # Source: https://medium.com/@netopschic/implementing-the-log-monitoring-stack-using-promtail-loki-and-grafana-using-docker-compose auth_enabled: false server: http_listen_port: 3100 grpc_listen_port: 9096 common: instance_addr: 127.0.0.1 path_prefix: /loki storage: filesystem: chunks_directory: /loki/chunks rules_directory: /loki/rules replication_factor: 1 ring: kvstore: store: inmemory schema_config: configs: - from: 2020-10-24 store: tsdb object_store: filesystem schema: v13 index: prefix: index_ period: 24h query_range: results_cache: cache: embedded_cache: enabled: true max_size_mb: 100 ``` ### Pattern 7: Locust JWT Session **What:** Locust `HttpUser` with `on_start()` for JWT login; stores token; uses it in all subsequent requests. Task weights simulate a realistic session. ```python # Source: https://docs.locust.io/en/stable/writing-a-locustfile.html # File: backend/load_tests/locustfile.py from locust import HttpUser, task, between, events import json TEST_EMAIL = "loadtest@example.com" TEST_PASSWORD = "Loadtest123!" class DocuVaultUser(HttpUser): wait_time = between(0.5, 2.0) access_token: str = "" def on_start(self): """Login and obtain JWT access token.""" resp = self.client.post( "/api/auth/login", json={"email": TEST_EMAIL, "password": TEST_PASSWORD}, ) if resp.status_code == 200: self.access_token = resp.json().get("access_token", "") else: self.environment.runner.quit() def _auth_headers(self): return {"Authorization": f"Bearer {self.access_token}"} @task(5) # Most common: list documents def list_documents(self): self.client.get("/api/documents/", headers=self._auth_headers()) @task(2) # Upload (moderate frequency) def upload_document(self): from io import BytesIO data = b"%PDF-1.4 fake pdf content for load testing" self.client.post( "/api/documents/", files={"file": ("test.pdf", BytesIO(data), "application/pdf")}, headers=self._auth_headers(), ) @task(1) # Least common: refresh token def refresh_token(self): self.client.post("/api/auth/refresh") # SLA gate: exit code 1 if p95 > 200ms or p99 > 500ms @events.quitting.add_listener def check_sla(environment, **kwargs): stats = environment.runner.stats.total if stats.fail_ratio > 0.01: environment.process_exit_code = 1 elif stats.get_response_time_percentile(0.95) > 200: environment.process_exit_code = 1 elif stats.get_response_time_percentile(0.99) > 500: environment.process_exit_code = 1 ``` **Run command:** ```bash locust --headless --users 50 --spawn-rate 10 --run-time 5m \ --host http://localhost:8000 \ --csv backend/load_tests/results \ -f backend/load_tests/locustfile.py ``` **Note on upload endpoint:** D-05 specifies simulating an upload. The existing upload flow uses presigned URLs (two-step: `POST /api/documents/upload-url` → XHR PUT to MinIO → `POST /api/documents/{id}/confirm`). The locustfile must implement all three steps. Locust's `HttpUser` can PUT directly to MinIO's public endpoint. [ASSUMED on two-step flow — confirm against current documents.py before finalizing] ### Anti-Patterns to Avoid - **Defining a second `get_client_ip` anywhere:** CLAUDE.md mandates the function lives only in `deps/utils.py`. Replace the body in-place. - **Adding `get_regular_user` import to locustfile.py:** Locust scripts must have zero imports from the application code to stay independent and avoid circular import issues. - **Installing locust in the production Docker image:** Load tests run externally. Adding locust to `requirements.txt` bloats the image with gevent and other heavy deps. - **Using `BaseHTTPMiddleware` for CorrelationIDMiddleware:** Starlette's `BaseHTTPMiddleware` buffers streaming responses. Use raw ASGI middleware (as shown in Pattern 2) for the logging middleware. - **Binding user_id in middleware before auth:** Middleware runs before route handlers; `current_user` is not available in middleware. Bind user_id in the route handler body. --- ## Don't Hand-Roll | Problem | Don't Build | Use Instead | Why | |---------|-------------|-------------|-----| | Structured JSON log formatting | Custom JSON serializer | structlog JSONRenderer via ProcessorFormatter | Exception traces, timestamps, ISO formatting already handled | | Log context propagation across async boundaries | threading.local or passing context as params | structlog.contextvars | Native asyncio-safe; zero changes to function signatures | | Stdlib bridge (uvicorn/sqlalchemy logs) | Custom logging.Handler | structlog ProcessorFormatter with foreign_pre_chain | One formatter handles both structlog and stdlib — uniform output | | HTTP load testing with auth sessions | Custom requests/httpx script | Locust HttpUser with on_start() | Built-in distributed mode, stats, SLA reporting, CSV export | | Docker CVE scanning | Custom apt-based scanner | `docker scout cves` | Already available (v1.20.4 on host); --exit-code flag for gate scripting | | Trusted-proxy IP extraction | New function | Update existing `get_client_ip` in `deps/utils.py` | CLAUDE.md mandates single canonical location; function already imported by all routers | **Key insight:** Every domain in Phase 6 has a well-established off-the-shelf solution. The risk of custom implementations is stale logic (e.g., a homegrown trusted-proxy parser missing IPv6 or CIDR edge cases). --- ## Common Pitfalls ### Pitfall 1: tmpfs owned by root when combined with non-root appuser **What goes wrong:** With `read_only: true` and `tmpfs: ["/tmp"]` in docker-compose.yml, the tmpfs mount is created as `root:root 755`. appuser (uid=1000) cannot write to it. `tempfile.NamedTemporaryFile()` in `services/extractor.py` will raise `PermissionError`. **Why it happens:** Docker creates tmpfs mounts before the USER instruction takes effect — they are always initially owned by root. **How to avoid:** Two options: 1. `tmpfs: - /tmp:mode=1777` — world-writable sticky bit; quick and standard for /tmp. 2. An entrypoint script that runs `chown -R appuser /tmp` before `exec su-exec appuser uvicorn ...` — more secure but adds complexity. Option 1 (`mode=1777`) matches the Linux convention for `/tmp` and is recommended for this use case. [VERIFIED: https://www.tutorialpedia.org/blog/docker-compose-mounting-a-tmpfs-usable-by-non-root-user/] ### Pitfall 2: structlog.contextvars context NOT cleared between requests **What goes wrong:** Without `structlog.contextvars.clear_contextvars()` at the start of each request, context variables from previous requests can bleed into subsequent requests handled on the same worker. In async apps, this causes user_id and correlation_id cross-contamination. **Why it happens:** contextvars in asyncio are scoped to a task/coroutine chain, but Starlette may reuse coroutine contexts across requests under some middleware configurations. **How to avoid:** Always call `clear_contextvars()` as the FIRST operation in the CorrelationIDMiddleware `__call__` method, before binding any new values. [VERIFIED: https://www.structlog.org/en/stable/contextvars.html] ### Pitfall 3: slowapi account_limiter key_func called before current_user is on request.state **What goes wrong:** If `request.state.current_user` is not set before the rate limit check fires, the key_func falls back to IP — making the per-account limit effectively a per-IP limit, defeating D-12. **Why it happens:** slowapi evaluates the key_func inside the decorator's wrapper before calling the handler body. FastAPI's `Depends(get_regular_user)` injects the user object, but slowapi's key_func runs in a different execution context. **How to avoid:** The safest pattern is to set `request.state.current_user = current_user` as the first statement in the route handler body after the dependency injection. This ensures the key_func can access it on the next request for the same handler invocation. [ASSUMED — verify with a unit test in Wave 0 before deploying the decorator to all endpoints] ### Pitfall 4: Locust load test user not pre-created in DB **What goes wrong:** Running the locustfile against a fresh database with no `loadtest@example.com` user causes all logins to fail immediately — the load test reports 100% failures but this is a test setup issue, not an SLA failure. **Why it happens:** Locust doesn't know about the app's user model. **How to avoid:** Add a Wave 0 task to create the load test user via `POST /api/auth/register` (or direct DB insert via alembic seed) before running the locust soak test. Document this in the RUNBOOK.md section on load testing. ### Pitfall 5: `docker scout cves` requires authenticated Docker Hub session on first run **What goes wrong:** `docker scout cves local://docuvault-backend` returns an auth error if Docker Hub is not logged in. The security gate fails on a clean machine. **Why it happens:** docker scout sends the image manifest to Docker's Scout service for analysis — it requires a Docker Hub account even for local images. **How to avoid:** Document `docker login` as a prerequisite in the security gate instructions. The gate command is: ```bash docker scout cves local://docuvault-backend:latest \ --only-severity critical \ --exit-code # Exit code 2 = critical CVEs found; 0 = clean ``` Provide `trivy image docuvault-backend:latest` as a fallback (trivy is offline-capable but not currently installed). [VERIFIED: https://docs.docker.com/reference/cli/docker/scout/cves/] ### Pitfall 6: PyMuPDF writes tessdata cache to /tmp under non-root **What goes wrong:** PyMuPDF (via MuPDF) may attempt to write cache files to locations owned by root that are not covered by the tmpfs mount. **Why it happens:** MuPDF's font/tessdata resolution uses paths baked in at compile time; on some builds this includes `/var/cache/fontconfig` or `/root/.config/mupdf`. **How to avoid:** Test `read_only: true` with the actual container: run `docker compose up backend` with a simple document extraction request and watch for `PermissionError` or `Read-only file system` errors. If found, add additional tmpfs mounts or use `--mount type=tmpfs,dst=/var/cache/fontconfig`. [ASSUMED — needs runtime verification in Wave 0] ### Pitfall 7: Celery worker `celerybeat-schedule` file on read-only filesystem **What goes wrong:** `celery-beat` writes a `celerybeat-schedule` file (pidfile + schedule state) to its working directory. With `read_only: true`, this fails immediately. **Why it happens:** Celery beat uses a local SQLite-like schedule file by default. **How to avoid:** Either (a) do NOT apply `read_only: true` to `celery-beat` (it is not a network-facing service so the risk is lower), or (b) add `tmpfs: ["/app"]` to celery-beat but that would override the app volume. Best approach: configure celery-beat to use `--schedule /tmp/celerybeat-schedule` in its command argument. Note: D-08 says `read_only` applies to "FastAPI and Celery worker services" — this is the Celery *worker*, not celery-beat. Clarify scope with the planner. --- ## Code Examples ### docker scout cves gate command ```bash # Source: https://docs.docker.com/reference/cli/docker/scout/cves/ # Build image first, then scan: docker build -t docuvault-backend:latest ./backend # Scan for critical CVEs — exit code 2 if any found, 0 if clean docker scout cves local://docuvault-backend:latest \ --only-severity critical \ --exit-code # For security gate: fail on critical OR high docker scout cves local://docuvault-backend:latest \ --only-severity critical,high \ --exit-code ``` ### structlog logger usage in route handlers ```python # Source: https://www.structlog.org/en/stable/getting-started.html import structlog log = structlog.get_logger() # In a route handler — user_id already bound by CorrelationIDMiddleware async def upload_document(...): structlog.contextvars.bind_contextvars(user_id=str(current_user.id)) log.info("document.upload.started", filename=file.filename, size_bytes=file.size) # ... processing ... log.info("document.upload.complete", document_id=str(doc.id)) ``` ### Locust headless run with CSV stats ```bash # Source: https://docs.locust.io/en/stable/running-without-web-ui.html locust \ --headless \ --users 50 \ --spawn-rate 10 \ --run-time 5m \ --host http://localhost:8000 \ --csv backend/load_tests/results \ -f backend/load_tests/locustfile.py # CSV output: # backend/load_tests/results_stats.csv — per-endpoint percentiles # backend/load_tests/results_failures.csv — failure details # backend/load_tests/results_stats_history.csv ``` --- ## State of the Art | Old Approach | Current Approach | When Changed | Impact | |--------------|------------------|--------------|--------| | logging.basicConfig JSON handler | structlog with ProcessorFormatter bridge | structlog 21+ | Unified stdlib + structlog pipeline; single config | | Promtail as only log agent | Grafana Alloy (new default) | 2024 (Grafana Alloy GA) | Alloy is now recommended; Promtail still supported and simpler for local dev | | docker-compose tmpfs string syntax | Long-form with mode/uid options | Docker Compose v3.6+ | Enables permission control on tmpfs | | Locust 1.x `TaskSet` pattern | Locust 2.x `@task` decorators on `HttpUser` | 2021 (Locust 2.0) | TaskSet deprecated; @task on HttpUser is current | | Loki schema v11/v12 | schema v13 (tsdb store) | Loki 2.8+ | v13 is now required for new deployments; v12 still works | **Deprecated/outdated:** - `structlog.threadlocal` module: replaced by `structlog.contextvars` for async apps — do not use. - `locust.TaskSet` class: still exists but deprecated; use `@task` on `HttpUser` directly. - Loki `boltdb-shipper` store: replaced by `tsdb` in schema v13. --- ## Assumptions Log | # | Claim | Section | Risk if Wrong | |---|-------|---------|---------------| | A1 | `request.state.current_user` set before slowapi evaluates key_func when set as first line of handler body | Pattern 4 (per-account limiter) | Per-account limit silently falls back to IP limit — D-12 not met | | A2 | Locust upload flow targets `POST /api/documents/` directly (single-step) vs. the presigned URL two-step flow | Pattern 7 (Locust) | Load test fails 100% if two-step flow is required | | A3 | `pip install --prefix=/install` followed by `COPY --from=builder /install /usr/local` correctly installs all packages into Python's site-packages in the runtime stage | Pattern 5 (Dockerfile) | Runtime stage missing packages → import errors at startup | | A4 | `celery-beat` is NOT subject to `read_only: true` per D-08 (which says "FastAPI and Celery worker") | Pitfall 7 | celery-beat fails to write schedule file → scheduled tasks stop | | A5 | PyMuPDF does not write to paths outside `/tmp` that would be blocked by `read_only: true` | Pitfall 6 | Extraction fails silently with PermissionError | --- ## Open Questions (RESOLVED) 1. **Upload endpoint for load testing** (RESOLVED: 06-03 `` block — use POST /api/documents/upload direct multipart endpoint for load test; presigned flow excluded per D-05) - What we know: `services/extractor.py` uses `tempfile.NamedTemporaryFile`; the upload flow may be two-step (presigned URL) or one-step depending on the current documents.py implementation - What's unclear: Whether Locust needs to implement the three-step presigned flow (upload-url → PUT to MinIO → confirm) or if a simpler direct POST exists - Recommendation: Read `backend/api/documents.py` lines for the upload endpoint before finalizing the locustfile; if two-step, implement the MinIO PUT step using `self.client.put` to MinIO's host:9000 2. **Load test user bootstrap** (RESOLVED: 06-03 Task 1 human checkpoint — use `on_start` register-then-login pattern; catch 409 conflict) - What we know: Locust needs a valid user to authenticate; no seed user for load testing exists yet - What's unclear: Whether to create the user via the registration API (on_start) or pre-seed via Alembic - Recommendation: Use `on_start` to register if not exists (catch 409), then login — self-contained, no DB dependency 3. **Loki tmpfs mount persistence** (RESOLVED: 06-02 Task 3 — named volume `loki_data:/loki` used; loki service not subject to read_only) - What we know: Loki service needs a writable `/loki` directory for chunk storage - What's unclear: Whether the named volume `loki_data:/loki` is sufficient or if Loki's own container permissions require a matching UID - Recommendation: Use named volume (not read_only on loki service — it's not a user-facing service) --- ## Environment Availability | Dependency | Required By | Available | Version | Fallback | |------------|------------|-----------|---------|----------| | Docker | Container hardening, docker scout, Loki stack | ✓ | 29.5.2 | — | | docker scout | CVE scanning gate | ✓ | v1.20.4 | trivy (not installed — document install) | | trivy | CVE scanning fallback | ✗ | — | `brew install trivy` or `apt-get install trivy` | | Python 3.12 (host) | Locust runs outside container | ✓ | 3.12 (via backend venv) | — | | structlog | structlog logging | needs install | 25.5.0 on PyPI | — | | locust | load tests | needs install | 2.34.0 on PyPI | — | | Loki image | log aggregation | pull on first compose up | grafana/loki:latest | — | | Promtail image | log collection | pull on first compose up | grafana/promtail:latest | — | | Grafana image | log visualization | pull on first compose up | grafana/grafana:latest | — | **Missing dependencies with no fallback:** - None that block core implementation. **Missing dependencies with fallback:** - trivy (CVE scanning): fallback is docker scout (already available). Document trivy as optional alternative. - docker login session: required for `docker scout cves` against local images. Planner must add a setup step. --- ## Validation Architecture ### Test Framework | Property | Value | |----------|-------| | Framework | pytest 8.2 + pytest-asyncio (asyncio_mode=auto) | | Config file | `backend/pytest.ini` | | Quick run command | `cd backend && pytest tests/ -v -x` | | Full suite command | `cd backend && pytest tests/ -v` | ### Phase Requirements → Test Map | Req ID | Behavior | Test Type | Automated Command | File Exists? | |--------|----------|-----------|-------------------|-------------| | D-01 | structlog emits JSON with correlation_id field | Unit | `pytest tests/test_logging.py -x` | ❌ Wave 0 | | D-11 | get_client_ip returns direct IP when peer is untrusted | Unit | `pytest tests/test_rate_limiting.py::test_get_client_ip_untrusted -x` | ❌ Wave 0 | | D-11 | get_client_ip reads XFF when peer is trusted proxy | Unit | `pytest tests/test_rate_limiting.py::test_get_client_ip_trusted_proxy -x` | ❌ Wave 0 | | D-12 | per-account limiter key is user.id not IP | Unit | `pytest tests/test_rate_limiting.py::test_account_limiter_key -x` | ❌ Wave 0 | | D-12 | authenticated endpoint returns 429 after 100 req/min | Integration | `pytest tests/test_rate_limiting.py::test_account_rate_limit -x` | ❌ Wave 0 | | D-07 | Docker image runs as uid=1000, not root | Manual/smoke | `docker run --rm docuvault-backend:latest id` | N/A manual | | D-08 | read_only container can write to /tmp | Manual/smoke | `docker compose up backend` + upload a doc | N/A manual | | D-06 | SLA: p95 < 200ms, p99 < 500ms at 50 users | Load test (Locust) | `locust --headless ... -f backend/load_tests/locustfile.py` | ❌ Wave 0 | ### Sampling Rate - **Per task commit:** `cd backend && pytest tests/ -v -x --tb=short` - **Per wave merge:** `cd backend && pytest tests/ -v` - **Phase gate:** Full suite green before `/gsd:verify-work` ### Wave 0 Gaps - [ ] `backend/tests/test_logging.py` — structlog config tests (D-01) - [ ] `backend/tests/test_rate_limiting.py` — get_client_ip unit tests + per-account limiter tests (D-11, D-12) - [ ] `backend/load_tests/__init__.py` — empty, marks directory as non-pytest-discoverable - [ ] `backend/load_tests/locustfile.py` — Locust user class (D-04..D-06) --- ## Security Domain ### Applicable ASVS Categories | ASVS Category | Applies | Standard Control | |---------------|---------|-----------------| | V2 Authentication | no (already implemented in Phase 2) | — | | V3 Session Management | no (already implemented) | — | | V4 Access Control | yes — rate limit bypass prevention | slowapi trusted-proxy key_func (D-11/D-12) | | V5 Input Validation | no new user inputs in this phase | — | | V6 Cryptography | no | — | | V14 Configuration | yes — container hardening, read-only fs | D-07..D-10 | ### Known Threat Patterns for This Phase | Pattern | STRIDE | Standard Mitigation | |---------|--------|---------------------| | Rate limit bypass via X-Forwarded-For header spoofing | Tampering | Trusted-proxy CIDR check in get_client_ip (D-11) | | Container escape via write to host filesystem | Elevation of Privilege | read_only: true + cap_drop: ALL (D-08, D-09) | | CVE exploitation via outdated base image packages | Tampering | docker scout cves zero-critical gate (D-10) | | Log injection via user-controlled strings in log fields | Tampering | structlog JSON renderer escapes all values — JSON encoding prevents log injection | | Locust test user credentials in version control | Information Disclosure | Use env vars for load test credentials; add to .gitignore | --- ## Sources ### Primary (HIGH confidence) - [structlog official docs — contextvars](https://www.structlog.org/en/stable/contextvars.html) — middleware pattern, clear_contextvars(), bind_contextvars() - [structlog official docs — stdlib integration](https://www.structlog.org/en/stable/standard-library.html) — ProcessorFormatter, foreign_pre_chain - [structlog official docs — getting started](https://www.structlog.org/en/stable/getting-started.html) — configure() API, JSON/console renderer - [Locust official docs — writing a locustfile](https://docs.locust.io/en/stable/writing-a-locustfile.html) — HttpUser, on_start, @task weights - [Locust official docs — headless mode](https://docs.locust.io/en/stable/running-without-web-ui.html) — --headless, --users, --spawn-rate, --run-time, exit codes - [Locust official docs — configuration](https://docs.locust.io/en/stable/configuration.html) — --csv, --host flags - [docker scout cves official docs](https://docs.docker.com/reference/cli/docker/scout/cves/) — --exit-code, --only-severity, exit code behavior - PyPI registry — structlog 25.5.0, locust 2.34.0, slowapi 0.1.9 confirmed current ### Secondary (MEDIUM confidence) - [wazaari.dev FastAPI + structlog integration](https://wazaari.dev/blog/fastapi-structlog-integration) — full processor chain + middleware pattern verified against structlog official docs - [Promtail docker_sd_configs pattern](https://ornlu-is.github.io/docker_compose_promtail_loki_grafana/) — container log scraping config verified against Promtail docs - [Loki single-binary config](https://medium.com/@netopschic/implementing-the-log-monitoring-stack-using-promtail-loki-and-grafana-using-docker-compose-bcb07d1a51aa) — loki-config.yaml single-node filesystem mode - [Docker tmpfs non-root pattern](https://www.tutorialpedia.org/blog/docker-compose-mounting-a-tmpfs-usable-by-non-root-user/) — mode=1777 solution for non-root tmpfs access ### Tertiary (LOW confidence) - [slowapi GitHub](https://github.com/laurentS/slowapi) — per-account key_func pattern inferred from API reference; no official example for request.state pattern --- ## Metadata **Confidence breakdown:** - Standard stack: HIGH — structlog 25.5.0 and locust 2.34.0 verified on PyPI; slowapi 0.1.9 already installed - Architecture (structlog): HIGH — verified against official structlog docs with working code examples - Architecture (Loki/Promtail): MEDIUM — working config patterns from community sources cross-checked with official Loki install docs - Architecture (container hardening): MEDIUM — Docker best practices well-documented; tmpfs non-root pattern verified against official compose format - Architecture (slowapi per-account): LOW-MEDIUM — core pattern is sound; key_func evaluation order vs. Depends resolution is an assumption that needs Wave 0 test - Locust load testing: HIGH — official docs used for all flags and patterns - docker scout CVE scanning: HIGH — official Docker docs used **Research date:** 2026-06-02 **Valid until:** 2026-07-02 (structlog and locust are stable libraries; Loki config may shift with new releases)