import json import logging import pytest from pydantic import BaseModel from app.config import get_settings from app.llm.client import chat_json from app.log import ( JsonFormatter, apply_content_log_guard, correlation_id, safe_error, ) from app.metrics import MetricsRegistry from tests.fake_openai import FakeOpenAI def test_metrics_registry_roundtrip() -> None: registry = MetricsRegistry() registry.inc("calls", {"role": "chat"}) registry.inc("calls", {"role": "chat"}, value=2) registry.set_gauge("depth", 4.0) registry.observe("seconds", 1.0, {"kind": "x"}) registry.observe("seconds", 3.0, {"kind": "x"}) snapshot = registry.snapshot() assert snapshot["counters"]["calls"] == [{"labels": {"role": "chat"}, "value": 3.0}] assert snapshot["gauges"]["depth"] == [{"labels": {}, "value": 4.0}] hist = snapshot["histograms"]["seconds"][0] assert hist == { "labels": {"kind": "x"}, "count": 2, "sum": 4.0, "min": 1.0, "max": 3.0, "avg": 2.0, } registry.reset() assert registry.snapshot() == {"counters": {}, "gauges": {}, "histograms": {}} def _format(record: logging.LogRecord) -> dict: return json.loads(JsonFormatter().format(record)) def test_json_formatter_includes_extras_and_correlation_id() -> None: token = correlation_id.set("req-123") try: record = logging.LogRecord( name="pablan.test", level=logging.INFO, pathname=__file__, lineno=1, msg="llm call", args=(), exc_info=None, ) record.role = "chat" record.duration_ms = 42 payload = _format(record) finally: correlation_id.reset(token) assert payload["message"] == "llm call" assert payload["level"] == "INFO" assert payload["correlation_id"] == "req-123" assert payload["role"] == "chat" assert payload["duration_ms"] == 42 assert "ts" in payload def test_safe_error_strips_sql_parameters() -> None: error = ValueError( "insert failed [SQL: INSERT INTO messages ...] [parameters: ('secret content',)]" ) sanitized = safe_error(error) assert sanitized == "ValueError: insert failed" assert "secret content" not in sanitized def test_safe_error_truncates() -> None: sanitized = safe_error(RuntimeError("x" * 1000), limit=50) assert len(sanitized) <= len("RuntimeError: ") + 50 class Verdict(BaseModel): done: bool async def test_llm_logs_contain_no_content( fake_llm: FakeOpenAI, caplog: pytest.LogCaptureFixture ) -> None: """CLAUDE.md rule 12: with debug logging off (the default), neither the prompt nor the model response may appear in any rendered log line.""" secret_prompt = "GEHEIM-PROMPT-77" secret_response = '{"done": true, "leak": "GEHEIM-ANTWORT-88"}' fake_llm.chat_responses.append({"content": secret_response}) # As in production: third-party SDK loggers are capped so they cannot # dump request bodies even at global DEBUG level. apply_content_log_guard() with caplog.at_level(logging.DEBUG): await chat_json([{"role": "user", "content": secret_prompt}], Verdict) formatter = JsonFormatter() rendered = "\n".join(formatter.format(record) for record in caplog.records) assert "llm call" in rendered assert "GEHEIM-PROMPT-77" not in rendered assert "GEHEIM-ANTWORT-88" not in rendered async def test_debug_flag_enables_content_logging( fake_llm: FakeOpenAI, caplog: pytest.LogCaptureFixture, monkeypatch: pytest.MonkeyPatch, ) -> None: """The documented never-in-production escape hatch actually works.""" monkeypatch.setenv("PABLAN_DEBUG_LOG_PROMPTS", "true") get_settings.cache_clear() try: fake_llm.chat_responses.append({"content": '{"done": true}'}) with caplog.at_level(logging.DEBUG): await chat_json([{"role": "user", "content": "SICHTBAR-99"}], Verdict) formatter = JsonFormatter() rendered = "\n".join(formatter.format(record) for record in caplog.records) assert "SICHTBAR-99" in rendered finally: get_settings.cache_clear()