6a8f374678
Operability: - Correlation IDs end-to-end: shared dispatch_id between log lines and EventLog rows (event/watcher/scheduled/deferred/action/HA/command paths) and a new X-Request-Id middleware that normalizes inbound ids and binds request_id into log context. - dispatch_summary block merged into EventLog.details: per-target success/failure counts plus Telegram media delivered/skipped/failed and truncated error lists, so partial outcomes surface in the UI. - Diagnostic mode: admin can flip one module to DEBUG for a bounded window with auto-revert (in-memory only; setup_logging() resets on boot, lifespan reverts on shutdown). New /diagnostic-mode endpoints plus DiagnosticsCassette UI on the settings page. Telegram: - Per-receiver options: disable_notification (silent send) and message_thread_id (forum-topic routing), wired through the dispatcher via a ContextVar so all four send sites (sendMessage / sendPhoto-Video- Document / sendMediaGroup / cache-hit POST) pick them up. - send_large_videos_as_documents target setting: bypass the 50 MB sendVideo cap by falling back to sendDocument for oversized videos. - sendMediaGroup byte-budget enforcement (TELEGRAM_MAX_GROUP_TOTAL_BYTES, 45 MB) with per-item fallback on chunk failure so a stale file_id no longer silently drops a cached asset. Tests: - New: diagnostic_mode, dispatch_summary, request_correlation, telegram_media_group_partial, telegram_per_send_options. Docs: - .claude/reviews/: six-axis production-readiness review of v0.8.1. - .claude/docs/functional-review-2026-05-28.md: focused review of Telegram/Immich/logging subsystems.
159 lines
5.4 KiB
Python
159 lines
5.4 KiB
Python
"""Request-ID middleware + EventLog dispatch_id correlation.
|
|
|
|
Covers two halves of the same correlation story:
|
|
|
|
* ``RequestContextMiddleware`` generates / accepts an inbound request id,
|
|
binds it onto the log-context ContextVar for the duration of the request,
|
|
and echoes it back as the ``X-Request-Id`` response header.
|
|
* ``enrich_details_with_correlation`` merges the active ``dispatch_id`` and
|
|
``request_id`` into an ``EventLog.details`` dict so the persisted row can
|
|
be cross-referenced with the stderr log lines emitted during the same
|
|
dispatch.
|
|
"""
|
|
|
|
from __future__ import annotations
|
|
|
|
import re
|
|
|
|
import pytest
|
|
from fastapi.testclient import TestClient
|
|
|
|
|
|
_REQ_ID_PATTERN = re.compile(r"^req:[0-9a-f]{12}$")
|
|
|
|
|
|
def test_response_carries_generated_request_id(tmp_data_dir) -> None: # noqa: ARG001
|
|
"""No inbound header → server generates ``req:<12 hex>`` and echoes it."""
|
|
from notify_bridge_server.main import app
|
|
|
|
with TestClient(app) as client:
|
|
resp = client.get("/api/health")
|
|
assert resp.status_code == 200
|
|
req_id = resp.headers.get("X-Request-Id")
|
|
assert req_id is not None
|
|
assert _REQ_ID_PATTERN.match(req_id), (
|
|
f"generated id {req_id!r} should match req:<12 hex>"
|
|
)
|
|
|
|
|
|
def test_response_echoes_safe_inbound_request_id(tmp_data_dir) -> None: # noqa: ARG001
|
|
"""A well-formed inbound ``X-Request-Id`` is preserved unchanged."""
|
|
from notify_bridge_server.main import app
|
|
|
|
inbound = "abc-123_XYZ_trace"
|
|
with TestClient(app) as client:
|
|
resp = client.get("/api/health", headers={"X-Request-Id": inbound})
|
|
assert resp.status_code == 200
|
|
assert resp.headers.get("X-Request-Id") == inbound
|
|
|
|
|
|
def test_colon_prefixed_inbound_id_is_replaced(tmp_data_dir) -> None: # noqa: ARG001
|
|
"""``:`` is reserved for server-minted ids — a colon in the inbound value
|
|
must trigger replacement so a client can't masquerade as ``disp:...``."""
|
|
from notify_bridge_server.main import app
|
|
|
|
with TestClient(app) as client:
|
|
resp = client.get(
|
|
"/api/health", headers={"X-Request-Id": "disp:fake12345678"},
|
|
)
|
|
assert resp.status_code == 200
|
|
echoed = resp.headers.get("X-Request-Id", "")
|
|
assert echoed != "disp:fake12345678"
|
|
assert _REQ_ID_PATTERN.match(echoed)
|
|
|
|
|
|
@pytest.mark.parametrize(
|
|
"bad_value",
|
|
[
|
|
# CRLF injection attempt — would split log lines / inject headers.
|
|
"abc\r\ninjected: yes",
|
|
# Way too long.
|
|
"x" * 256,
|
|
# Disallowed characters.
|
|
"<script>alert(1)</script>",
|
|
# Empty after stripping.
|
|
" ",
|
|
],
|
|
)
|
|
def test_unsafe_inbound_request_id_is_replaced(
|
|
tmp_data_dir, bad_value: str, # noqa: ARG001
|
|
) -> None:
|
|
"""An attacker-controlled id must not flow into logs verbatim."""
|
|
from notify_bridge_server.main import app
|
|
|
|
with TestClient(app) as client:
|
|
resp = client.get("/api/health", headers={"X-Request-Id": bad_value})
|
|
assert resp.status_code == 200
|
|
echoed = resp.headers.get("X-Request-Id", "")
|
|
assert echoed != bad_value, "unsafe id was passed through unchanged"
|
|
assert _REQ_ID_PATTERN.match(echoed), (
|
|
f"replacement id {echoed!r} should match req:<12 hex>"
|
|
)
|
|
|
|
|
|
def test_enrich_details_merges_active_correlation_ids() -> None:
|
|
"""Within a ``bind_log_context`` block, the helper copies the active ids."""
|
|
from notify_bridge_core.log_context import (
|
|
bind_log_context,
|
|
enrich_details_with_correlation,
|
|
)
|
|
|
|
with bind_log_context(
|
|
dispatch_id="disp:deadbeef0001",
|
|
request_id="req:cafecafe0002",
|
|
):
|
|
result = enrich_details_with_correlation({"existing": "value"})
|
|
|
|
assert result == {
|
|
"existing": "value",
|
|
"dispatch_id": "disp:deadbeef0001",
|
|
"request_id": "req:cafecafe0002",
|
|
}
|
|
|
|
|
|
def test_enrich_details_does_not_overwrite_explicit_keys() -> None:
|
|
"""If the caller pre-set a correlation key, the helper leaves it alone."""
|
|
from notify_bridge_core.log_context import (
|
|
bind_log_context,
|
|
enrich_details_with_correlation,
|
|
)
|
|
|
|
with bind_log_context(dispatch_id="disp:newvalue00001"):
|
|
result = enrich_details_with_correlation({"dispatch_id": "disp:pinned"})
|
|
|
|
assert result["dispatch_id"] == "disp:pinned"
|
|
|
|
|
|
def test_enrich_details_no_context_returns_copy() -> None:
|
|
"""Outside any binding, the helper returns the dict unchanged but copied."""
|
|
from notify_bridge_core.log_context import enrich_details_with_correlation
|
|
|
|
original = {"key": "value"}
|
|
result = enrich_details_with_correlation(original)
|
|
assert result == original
|
|
# Mutating the result must not leak into the caller's dict.
|
|
result["extra"] = "added"
|
|
assert "extra" not in original
|
|
|
|
|
|
def test_enrich_details_handles_none() -> None:
|
|
"""``None`` is accepted (callers may build details lazily)."""
|
|
from notify_bridge_core.log_context import enrich_details_with_correlation
|
|
|
|
assert enrich_details_with_correlation(None) == {}
|
|
|
|
|
|
def test_ensure_dispatch_id_generates_or_reuses() -> None:
|
|
"""Fresh call produces a new id; inside a bind it returns the bound one."""
|
|
from notify_bridge_core.log_context import (
|
|
bind_log_context,
|
|
ensure_dispatch_id,
|
|
)
|
|
|
|
fresh = ensure_dispatch_id()
|
|
assert fresh.startswith("disp:")
|
|
assert len(fresh) == len("disp:") + 12
|
|
|
|
with bind_log_context(dispatch_id="disp:bound00000001"):
|
|
assert ensure_dispatch_id() == "disp:bound00000001"
|