Add structured logging with request ID correlation

- Add LOG_FORMAT setting ("text" or "json", default: text)
- Add request ID middleware: reads x-request-id from upstream
  (nginx/LiteLLM) or generates UUID, echoes in response header
- Store request ID in contextvars.ContextVar for async propagation
- Custom logging.Filter injects request_id into every log record
- JSON formatter for production log aggregation
- Text format now includes [request_id] field
- Add PLAYWRIGHT_CONTEXT_RECYCLE_PAGES and PLAYWRIGHT_MAX_HTML_BYTES
  config settings (used in upcoming Playwright hardening commit)

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>

Author: SkylarKelty

artemis/config.py

@@ -221,6 +221,28 @@ def _parse_log_level(name: str, default: str = "INFO") -> str:
     return raw_value
 
 
+_LOG_FORMATS = {"text", "json"}
+
+
+def _parse_log_format(name: str, default: str = "text") -> str:
+    """Parse log format from environment variable.
+
+    Args:
+        name: Environment variable name
+        default: Default format if variable is not set (default: text)
+
+    Returns:
+        Validated log format string ("text" or "json")
+
+    Raises:
+        ConfigError: If the value is not a valid log format
+    """
+    raw_value = os.getenv(name, default).strip().lower()
+    if raw_value not in _LOG_FORMATS:
+        raise ConfigError(f"{name} must be one of: text, json.")
+    return raw_value
+
+
 @dataclass(frozen=True)
 class Settings:
     """Immutable configuration container for Artemis.
@@ -263,6 +285,9 @@ class Settings:
         cache_max_entries: Maximum entries per cache before oldest are evicted
         embedding_model: Model for query embeddings (enables semantic dedup when set)
         semantic_similarity_threshold: Cosine similarity threshold for semantic cache hits
+        log_format: Log output format ("text" or "json")
+        playwright_context_recycle_pages: Recycle Playwright context after this many pages
+        playwright_max_html_bytes: Maximum HTML bytes to extract per page
     """
 
     searxng_api_base: str
@@ -298,6 +323,9 @@ class Settings:
     cache_max_entries: int
     embedding_model: str | None
     semantic_similarity_threshold: float
+    log_format: str
+    playwright_context_recycle_pages: int
+    playwright_max_html_bytes: int
 
 
 @lru_cache(maxsize=1)
@@ -402,6 +430,13 @@ def get_settings() -> Settings:
         semantic_similarity_threshold=_parse_float(
             "SEMANTIC_SIMILARITY_THRESHOLD", 0.92, minimum=0.5, maximum=1.0
         ),
+        log_format=_parse_log_format("LOG_FORMAT"),
+        playwright_context_recycle_pages=_parse_int(
+            "PLAYWRIGHT_CONTEXT_RECYCLE_PAGES", 50, minimum=1, maximum=10000
+        ),
+        playwright_max_html_bytes=_parse_int(
+            "PLAYWRIGHT_MAX_HTML_BYTES", 5 * 1024 * 1024, minimum=65536, maximum=50 * 1024 * 1024
+        ),
     )
 
 

artemis/main.py

@@ -14,14 +14,16 @@
 
 from dataclasses import dataclass
 import asyncio
+import contextvars
+import json as _json
 import logging
 import secrets
 import time
 import uuid
 from collections.abc import AsyncGenerator
 from contextlib import asynccontextmanager
 
-from fastapi import Depends, FastAPI, HTTPException, status
+from fastapi import Depends, FastAPI, HTTPException, Request, status
 from fastapi.middleware.cors import CORSMiddleware
 from fastapi.responses import JSONResponse, StreamingResponse
 from fastapi.security import HTTPAuthorizationCredentials, HTTPBearer
@@ -50,14 +52,61 @@
 from artemis.searcher import close_client as close_searxng_client
 from artemis.summarizer import summarize_results
 
+# ---------------------------------------------------------------------------
+# Request ID context variable — set by middleware, read by log formatter
+# ---------------------------------------------------------------------------
+request_id_ctx: contextvars.ContextVar[str] = contextvars.ContextVar(
+    "request_id", default="-"
+)
+
+
+class _RequestIdFilter(logging.Filter):
+    """Inject request_id from context into every log record."""
+
+    def filter(self, record: logging.LogRecord) -> bool:
+        record.request_id = request_id_ctx.get("-")  # type: ignore[attr-defined]
+        return True
+
+
+class _JsonFormatter(logging.Formatter):
+    """Emit log records as single-line JSON objects."""
+
+    def format(self, record: logging.LogRecord) -> str:
+        obj = {
+            "ts": self.formatTime(record),
+            "level": record.levelname,
+            "logger": record.name,
+            "request_id": getattr(record, "request_id", "-"),
+            "msg": record.getMessage(),
+        }
+        if record.exc_info and record.exc_info[1]:
+            obj["exception"] = self.formatException(record.exc_info)
+        return _json.dumps(obj)
+
+
+def _configure_logging(settings_obj: Settings) -> None:
+    """Configure root logger with request ID support."""
+    root = logging.getLogger()
+    root.setLevel(getattr(logging, settings_obj.log_level, logging.INFO))
+    root.handlers.clear()
+
+    handler = logging.StreamHandler()
+    handler.addFilter(_RequestIdFilter())
+
+    if settings_obj.log_format == "json":
+        handler.setFormatter(_JsonFormatter())
+    else:
+        handler.setFormatter(logging.Formatter(
+            "%(asctime)s %(levelname)s [%(name)s] [%(request_id)s] %(message)s"
+        ))
+    root.addHandler(handler)
+
+
 # Load settings at module import time to fail fast on config errors
 initial_settings = get_settings()
 
-# Configure logging based on settings
-logging.basicConfig(
-    level=getattr(logging, initial_settings.log_level, logging.INFO),
-    format="%(asctime)s %(levelname)s [%(name)s] %(message)s",
-)
+# Configure structured logging
+_configure_logging(initial_settings)
 logger = logging.getLogger(__name__)
 
 # Log security warnings at startup
@@ -157,6 +206,19 @@ def _research_preset_config(settings: Settings, preset: str) -> ResearchPresetCo
 )
 
 
+@app.middleware("http")
+async def request_id_middleware(request: Request, call_next):
+    """Attach a unique request ID to every request for log correlation."""
+    rid = request.headers.get("x-request-id") or str(uuid.uuid4())
+    token = request_id_ctx.set(rid)
+    try:
+        response = await call_next(request)
+        response.headers["x-request-id"] = rid
+        return response
+    finally:
+        request_id_ctx.reset(token)
+
+
 @app.exception_handler(UpstreamServiceError)
 async def upstream_service_error_handler(_, exc: UpstreamServiceError) -> JSONResponse:
     logger.error("Upstream service failure: %s", exc)

tests/test_api.py

@@ -66,6 +66,9 @@ def test_search_requires_api_key_when_configured(
                 cache_max_entries=1000,
                 embedding_model=None,
                 semantic_similarity_threshold=0.92,
+                log_format="text",
+                playwright_context_recycle_pages=50,
+                playwright_max_html_bytes=5242880,
             ),
         ):
             unauthorized = self.client.post("/search", json={"query": "fastapi"})
@@ -130,6 +133,9 @@ def test_deep_research_uses_requested_max_steps(
             cache_max_entries=1000,
             embedding_model=None,
             semantic_similarity_threshold=0.92,
+            log_format="text",
+            playwright_context_recycle_pages=50,
+            playwright_max_html_bytes=5242880,
         )
 
         with patch("artemis.main.get_settings", return_value=settings):
@@ -201,6 +207,9 @@ def test_shallow_research_uses_shallow_settings(
                 cache_max_entries=1000,
                 embedding_model=None,
                 semantic_similarity_threshold=0.92,
+                log_format="text",
+                playwright_context_recycle_pages=50,
+                playwright_max_html_bytes=5242880,
             ),
         ):
             response = self.client.post(

tests/test_api_extended.py

@@ -58,6 +58,9 @@ def _default_settings(**overrides) -> Settings:
         cache_max_entries=1000,
         embedding_model=None,
         semantic_similarity_threshold=0.92,
+        log_format="text",
+        playwright_context_recycle_pages=50,
+        playwright_max_html_bytes=5242880,
     )
     defaults.update(overrides)
     return Settings(**defaults)

tests/test_cache.py

@@ -457,6 +457,9 @@ async def test_semantic_hit_skips_search(
             cache_max_entries=1000,
             embedding_model="text-embedding-3-small",
             semantic_similarity_threshold=0.90,
+            log_format="text",
+            playwright_context_recycle_pages=50,
+            playwright_max_html_bytes=5242880,
         )
         mock_settings.return_value = settings
 
@@ -528,6 +531,9 @@ async def test_dissimilar_queries_no_semantic_hit(
             cache_max_entries=1000,
             embedding_model="text-embedding-3-small",
             semantic_similarity_threshold=0.90,
+            log_format="text",
+            playwright_context_recycle_pages=50,
+            playwright_max_html_bytes=5242880,
         )
         mock_settings.return_value = settings
 
@@ -593,6 +599,9 @@ async def test_no_embedding_model_skips_semantic(
             cache_max_entries=1000,
             embedding_model=None,  # Disabled
             semantic_similarity_threshold=0.92,
+            log_format="text",
+            playwright_context_recycle_pages=50,
+            playwright_max_html_bytes=5242880,
         )
         mock_settings.return_value = settings