From 9fa74a91f5e759ce47d408dba8126d7affa3c4da Mon Sep 17 00:00:00 2001
From: curo1305 <curo1305@proton.me>
Date: Wed, 3 Jun 2026 18:44:37 +0200
Subject: [PATCH] feat(06-02): add structlog dependency + create
 services/logging.py
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

- Append structlog>=25.5.0 to requirements.txt under Phase 6 D-01 comment
- Create backend/services/logging.py with setup_logging(json_logs, log_level)
- shared_processors: merge_contextvars first, then add_log_level, add_logger_name,
  PositionalArgumentsFormatter, ExtraAdder, TimeStamper(iso), StackInfoRenderer
- JSON branch appends format_exc_info to shared_processors
- JSONRenderer when json_logs=True, ConsoleRenderer when False
- ProcessorFormatter bridges uvicorn/stdlib loggers through same chain
- Idempotent: clears root handlers before installing new one
- uvicorn.access propagate=False — middleware owns request logging
---
 backend/requirements.txt    |   3 +
 backend/services/logging.py | 106 ++++++++++++++++++++++++++++++++++++
 2 files changed, 109 insertions(+)
 create mode 100644 backend/services/logging.py

diff --git a/backend/requirements.txt b/backend/requirements.txt
index eaf23cc..269dd5c 100644
--- a/backend/requirements.txt
+++ b/backend/requirements.txt
@@ -32,3 +32,6 @@ google-api-python-client>=2.196.0
 msal>=1.36.0
 webdavclient3>=3.14.7
 cachetools>=5.3.0
+
+# Observability (Phase 6 — D-01)
+structlog>=25.5.0
diff --git a/backend/services/logging.py b/backend/services/logging.py
new file mode 100644
index 0000000..f27ac7e
--- /dev/null
+++ b/backend/services/logging.py
@@ -0,0 +1,106 @@
+"""
+Structured logging service — D-01.
+
+Single entry-point for structlog + stdlib bridge.
+
+Bridges stdlib loggers (uvicorn, sqlalchemy, celery) through the same
+structured JSON processor chain.
+
+Security invariants:
+  - No function raises HTTPException — pure Python, no FastAPI coupling.
+  - merge_contextvars is FIRST in the processor chain — correlation_id and
+    other contextvar-bound fields appear in every log line.
+  - Calling setup_logging twice is idempotent — existing root handlers are
+    cleared before adding the new handler.
+  - uvicorn.access propagate is False — CorrelationIDMiddleware in main.py
+    owns request-level logging; access log lines are not doubled.
+"""
+from __future__ import annotations
+
+import logging
+
+import structlog
+
+
+def setup_logging(json_logs: bool = False, log_level: str = "INFO") -> None:
+    """Configure structlog + stdlib logging bridge.
+
+    Args:
+        json_logs: If True, render logs as JSON (production). If False, use
+                   ConsoleRenderer with colours (development default).
+        log_level: Root logger level string, e.g. "INFO", "DEBUG", "WARNING".
+                   Case-insensitive.
+
+    Idempotent: clears existing root handlers before installing the new one so
+    calling this function multiple times in tests does not duplicate output.
+    """
+    timestamper = structlog.processors.TimeStamper(fmt="iso")
+
+    # shared_processors: applied by BOTH structlog native loggers and stdlib
+    # loggers bridged through ProcessorFormatter (foreign_pre_chain).
+    # merge_contextvars MUST be first — ensures correlation_id, user_id, etc.
+    # bound via structlog.contextvars.bind_contextvars() appear in every line.
+    shared_processors: list = [
+        structlog.contextvars.merge_contextvars,
+        structlog.stdlib.add_log_level,
+        structlog.stdlib.add_logger_name,
+        structlog.stdlib.PositionalArgumentsFormatter(),
+        structlog.stdlib.ExtraAdder(),
+        timestamper,
+        structlog.processors.StackInfoRenderer(),
+    ]
+    if json_logs:
+        # format_exc_info renders exception tracebacks as a JSON string field
+        # rather than a multi-line text block.
+        shared_processors.append(structlog.processors.format_exc_info)
+
+    # Configure structlog itself — processors for native structlog log calls.
+    structlog.configure(
+        processors=shared_processors + [
+            structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
+        ],
+        logger_factory=structlog.stdlib.LoggerFactory(),
+        cache_logger_on_first_use=True,
+    )
+
+    # Pick renderer based on mode.
+    log_renderer = (
+        structlog.processors.JSONRenderer()
+        if json_logs
+        else structlog.dev.ConsoleRenderer()
+    )
+
+    # ProcessorFormatter bridges stdlib loggers (uvicorn, sqlalchemy, celery)
+    # through the same processor chain.  foreign_pre_chain handles records
+    # that arrive from stdlib; processors runs after that.
+    formatter = structlog.stdlib.ProcessorFormatter(
+        foreign_pre_chain=shared_processors,
+        processors=[
+            structlog.stdlib.ProcessorFormatter.remove_processors_meta,
+            log_renderer,
+        ],
+    )
+
+    handler = logging.StreamHandler()
+    handler.setFormatter(formatter)
+
+    # Idempotency: clear existing handlers before adding ours.
+    root_logger = logging.getLogger()
+    root_logger.handlers.clear()
+    root_logger.addHandler(handler)
+    root_logger.setLevel(log_level.upper())
+
+    # Route uvicorn logs through structlog.
+    # uvicorn and uvicorn.error: propagate to root so they pass through
+    # the ProcessorFormatter and emit in the same JSON format.
+    for name in ("uvicorn", "uvicorn.error"):
+        _log = logging.getLogger(name)
+        _log.handlers.clear()
+        _log.propagate = True
+
+    # uvicorn.access: suppress — CorrelationIDMiddleware in main.py owns
+    # request-level logging, so the default uvicorn access lines must NOT
+    # be duplicated.
+    _access = logging.getLogger("uvicorn.access")
+    _access.handlers.clear()
+    _access.propagate = False