Surface LLM correlation fields in debug view; fix unit-continuity path
/admin/debug/correlation stripped corr_consensus and the corr_llm_* fields
that upload.py's consensus correlator writes onto the call doc, making it
the one tool built to answer "is the LLM correlation tier alive" unable to
answer it (2026-08-19 dump had to infer LLM state from commit dates instead
of reading it off the data). admin.py's _call_summary() now includes
corr_consensus, corr_llm_reasoning, corr_llm_action, corr_rules_action.
The unit-continuity correlation path never wrote corr_matched_units, unlike
fast/single and fast/disambig, so the debug view showed null for a match
that was in fact unit-driven by construction. Now populated unconditionally
on that path (server-26#16).
Also traced the negative corr_incident_idle_min (-4.1 observed) to its root
cause: the re-correlation sweep anchors `now` to the linking call's own
started_at, and that back-dated value was being written straight into the
incident's updated_at, letting it land before the incident's own
started_at. Added _floor_at_started_at() so updated_at can never precede
started_at. (commit 33a247d already fixed the recency *gates* misreading
that negative value; this fixes the write that produced it.) Verified the
skip_reason filter in recorrelation_sweep.py:63 is already correct, no
change needed there.
Added tests for the debug endpoint's LLM field passthrough, the
unit-continuity corr_matched_units fix, and the updated_at floor — each
confirmed to fail when its fix is reverted. 148 passed, 0 failed.
Closes logan/server-26#24
Closes logan/server-26#16
This commit is contained in:
@@ -278,6 +278,32 @@ def _idle_gate_minutes(inc: dict, now: datetime) -> float:
|
||||
return abs(_incident_idle_minutes(inc, now))
|
||||
|
||||
|
||||
def _floor_at_started_at(inc: dict, when: datetime) -> datetime:
|
||||
"""
|
||||
Clamp a candidate `updated_at` timestamp so it can never land before the
|
||||
incident's own `started_at`.
|
||||
|
||||
The re-correlation sweep anchors `now` to the linking call's own
|
||||
`started_at` (server-26#24 / recorrelation_sweep.py) so that its window
|
||||
math is correct regardless of when the sweep happens to run. But that
|
||||
same back-dated `now` was also being written straight into `updated_at`
|
||||
here — so an orphan whose real-world `started_at` predates the incident's
|
||||
own `started_at` could set `updated_at` earlier than `started_at`,
|
||||
producing the negative `corr_incident_idle_min` observed on 2026-08-19
|
||||
(commit 33a247d fixed the *gates* misreading that negative value, not
|
||||
this write). `started_at` is never rewritten after creation, so it's a
|
||||
safe floor: activity can never honestly be older than the incident itself.
|
||||
"""
|
||||
try:
|
||||
raw = inc.get("started_at") or ""
|
||||
started = datetime.fromisoformat(str(raw).replace("Z", "+00:00"))
|
||||
if started.tzinfo is None:
|
||||
started = started.replace(tzinfo=timezone.utc)
|
||||
except Exception:
|
||||
return when
|
||||
return max(when, started)
|
||||
|
||||
|
||||
def _incident_span_minutes(inc: dict, now: datetime) -> float:
|
||||
"""
|
||||
Wall-clock minutes the incident has been open: from its `started_at` to the
|
||||
@@ -849,6 +875,11 @@ def _run_decision(ctx: dict) -> dict:
|
||||
corr_debug = {
|
||||
"corr_path": "unit-continuity",
|
||||
"corr_incident_idle_min": round(_incident_idle_minutes(best_unit_inc, now), 1),
|
||||
# Unlike this file's other two paths (fast/single, fast/disambig),
|
||||
# a match here is unit-driven by construction (call_unit_set &
|
||||
# _unit_keys(...) is what built unit_candidates), so this is
|
||||
# always populated rather than gated on fit_signal (server-26#16).
|
||||
"corr_matched_units": _matching_units(call_units, best_unit_inc.get("units")),
|
||||
}
|
||||
logger.info(
|
||||
f"Correlator unit-continuity: call {call_id} → "
|
||||
@@ -1531,7 +1562,7 @@ async def _update_incident(
|
||||
# acknowledging. The incident now ages from its last SUBSTANTIVE call, and
|
||||
# thin traffic rides along without extending its life.
|
||||
if refresh_activity:
|
||||
updates["updated_at"] = now.isoformat()
|
||||
updates["updated_at"] = _floor_at_started_at(inc, now).isoformat()
|
||||
else:
|
||||
updates["last_thin_at"] = now.isoformat()
|
||||
if best_location:
|
||||
|
||||
@@ -91,6 +91,14 @@ async def debug_correlation(
|
||||
"corr_matched_units": call.get("corr_matched_units"),
|
||||
"corr_sweep_count": call.get("corr_sweep_count"),
|
||||
"skip_reason": call.get("skip_reason"),
|
||||
# LLM consensus tier fields — written by upload.py's
|
||||
# _correlate_with_consensus / llm_correlator.py, but previously
|
||||
# dropped here, making it impossible to tell from this endpoint
|
||||
# whether the LLM correlation tier is actually running (server-26#24).
|
||||
"corr_consensus": call.get("corr_consensus"),
|
||||
"corr_llm_reasoning": call.get("corr_llm_reasoning"),
|
||||
"corr_llm_action": call.get("corr_llm_action"),
|
||||
"corr_rules_action": call.get("corr_rules_action"),
|
||||
}
|
||||
|
||||
# ── Determine which systems have AI active ────────────────────────────────
|
||||
|
||||
@@ -0,0 +1,91 @@
|
||||
"""
|
||||
Unit tests for /admin/debug/correlation (server-26#24).
|
||||
|
||||
The endpoint used to strip the LLM consensus tier's fields (corr_consensus,
|
||||
corr_llm_reasoning, corr_llm_action, corr_rules_action) out of its response
|
||||
even though upload.py / llm_correlator.py write them straight onto the call
|
||||
doc via corr_debug — making this endpoint unable to answer "is the LLM
|
||||
correlation tier actually running", the one thing it exists to answer.
|
||||
|
||||
Firestore is fully mocked (patch app.routers.admin.fstore); the route
|
||||
function is called directly, bypassing FastAPI's dependency injection, so
|
||||
Query/Depends defaults are supplied explicitly.
|
||||
"""
|
||||
import pytest
|
||||
from datetime import datetime, timezone
|
||||
from unittest.mock import AsyncMock, patch
|
||||
from app.routers import admin
|
||||
|
||||
NOW = datetime(2026, 8, 20, 12, 0, 0, tzinfo=timezone.utc)
|
||||
|
||||
|
||||
def _incident(call_ids):
|
||||
return {
|
||||
"incident_id": "inc-1",
|
||||
"system_ids": ["sys-1"],
|
||||
"call_ids": call_ids,
|
||||
"updated_at": NOW.isoformat(),
|
||||
"started_at": NOW.isoformat(),
|
||||
"status": "active",
|
||||
}
|
||||
|
||||
|
||||
async def _run(incidents, calls_by_id, orphan_calls=None):
|
||||
"""Drive debug_correlation() with fstore fully mocked."""
|
||||
system = {"system_id": "sys-1", "ai_flags": {}}
|
||||
|
||||
async def fake_collection_where(collection, conditions, order_by=None, limit_to=None, start_after=None):
|
||||
if collection == "incidents":
|
||||
return incidents
|
||||
if collection == "calls":
|
||||
return orphan_calls or []
|
||||
return []
|
||||
|
||||
async def fake_doc_get(collection, doc_id):
|
||||
return calls_by_id.get(doc_id)
|
||||
|
||||
with patch(
|
||||
"app.routers.admin.get_flags",
|
||||
new=AsyncMock(return_value={"stt_enabled": True, "correlation_enabled": True}),
|
||||
), patch("app.routers.admin.fstore") as mock_fstore:
|
||||
mock_fstore.collection_list = AsyncMock(return_value=[system])
|
||||
mock_fstore.collection_where = AsyncMock(side_effect=fake_collection_where)
|
||||
mock_fstore.doc_get = AsyncMock(side_effect=fake_doc_get)
|
||||
return await admin.debug_correlation(limit=20, orphan_hours=48, _=None)
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_debug_correlation_surfaces_llm_consensus_fields():
|
||||
"""A call that went through the tiebreaker must show all four LLM fields."""
|
||||
call = {
|
||||
"call_id": "call-1",
|
||||
"corr_path": "fast/single",
|
||||
"corr_consensus": "tiebreak",
|
||||
"corr_llm_reasoning": "Same units on scene as the anchor call.",
|
||||
"corr_llm_action": "link",
|
||||
"corr_rules_action": "orphan",
|
||||
}
|
||||
result = await _run([_incident(["call-1"])], {"call-1": call})
|
||||
|
||||
detail = result["incidents"][0]["calls_detail"][0]
|
||||
assert detail["corr_consensus"] == "tiebreak"
|
||||
assert detail["corr_llm_reasoning"] == "Same units on scene as the anchor call."
|
||||
assert detail["corr_llm_action"] == "link"
|
||||
assert detail["corr_rules_action"] == "orphan"
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_debug_correlation_llm_fields_absent_when_rules_only():
|
||||
"""
|
||||
A call that never reached the LLM (GEMINI_API_KEY unset, thin call, or LLM
|
||||
error) has corr_consensus == "rules_only" and no corr_llm_* fields — the
|
||||
endpoint must pass that through as None rather than erroring, since this
|
||||
is the normal/expected state whenever the tier is legitimately idle.
|
||||
"""
|
||||
call = {"call_id": "call-2", "corr_path": "fast/single", "corr_consensus": "rules_only"}
|
||||
result = await _run([_incident(["call-2"])], {"call-2": call})
|
||||
|
||||
detail = result["incidents"][0]["calls_detail"][0]
|
||||
assert detail["corr_consensus"] == "rules_only"
|
||||
assert detail["corr_llm_reasoning"] is None
|
||||
assert detail["corr_llm_action"] is None
|
||||
@@ -333,6 +333,79 @@ async def test_signal_resolve_stamps_resolved_at():
|
||||
assert updates["resolved_at"] == NOW.isoformat()
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# Issue #16 — unit-continuity path must populate corr_matched_units
|
||||
#
|
||||
# fast/single and fast/disambig only set corr_matched_units when
|
||||
# fit_signal == "unit_overlap"; unit-continuity has no such gate because a
|
||||
# match there is unit-driven by construction (call_unit_set intersects the
|
||||
# incident's units is literally how unit_candidates gets built) — so it must
|
||||
# always populate the field, not conditionally.
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
def test_unit_continuity_link_reports_matched_units():
|
||||
"""
|
||||
Reproduces the server-26#16 production example: call units=["Post 1-2"]
|
||||
should match an incident with units=["5-4", "9-0-8", "1-2"] via the
|
||||
normalizer collapsing "Post 1-2" and "1-2" to the same key, on a
|
||||
DIFFERENT talkgroup than the incident (so the fast/talkgroup path can't
|
||||
fire first and this falls through to unit-continuity).
|
||||
"""
|
||||
inc = _incident(10.0) # idle 10min, within unit_continuity_max_idle_minutes (20)
|
||||
inc["talkgroup_ids"] = ["1234"]
|
||||
inc["units"] = ["5-4", "9-0-8", "1-2"]
|
||||
decision = _run_decision(_ctx(
|
||||
talkgroup_id=9999, # not in inc["talkgroup_ids"] — fast path can't match
|
||||
all_active=[inc], recent=[],
|
||||
call_units=["Post 1-2"], is_thin_call=False, call_severity="routine",
|
||||
))
|
||||
assert decision["action"] == "link"
|
||||
assert decision["corr_debug"]["corr_path"] == "unit-continuity"
|
||||
assert decision["corr_debug"]["corr_matched_units"] == ["Post 1-2"]
|
||||
|
||||
|
||||
# ---------------------------------------------------------------------------
|
||||
# server-26#24 — updated_at must never precede started_at
|
||||
#
|
||||
# The re-correlation sweep anchors `now` to the linking call's own
|
||||
# started_at, which can be earlier than the incident's own started_at. Left
|
||||
# unclamped that produces updated_at < started_at on the incident doc, which
|
||||
# is what caused corr_incident_idle_min: -4.1 in production (commit 33a247d
|
||||
# fixed the gates reading that negative value, not this write).
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_updated_at_never_precedes_started_at():
|
||||
inc = _incident(5) # started_at == updated_at == NOW - 5min
|
||||
inc["started_at"] = NOW.isoformat() # incident "started" at NOW
|
||||
back_dated_now = NOW - timedelta(minutes=30) # a much older orphan call links in
|
||||
with patch("app.internal.incident_correlator.fstore") as mock_fstore:
|
||||
mock_fstore.doc_set = AsyncMock()
|
||||
await _update_incident(
|
||||
inc, "call-1", 9048, "sys-1", [], None, None, ["6-Adam"], [], None,
|
||||
back_dated_now,
|
||||
)
|
||||
updates = mock_fstore.doc_set.await_args.args[2]
|
||||
assert updates["updated_at"] == NOW.isoformat(), (
|
||||
"updated_at must be floored at started_at, not the back-dated `now`"
|
||||
)
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_updated_at_uses_now_when_now_is_later_than_started_at():
|
||||
"""The normal case (now is not back-dated before started_at) is unaffected."""
|
||||
inc = _incident(5)
|
||||
later_now = NOW + timedelta(minutes=1)
|
||||
with patch("app.internal.incident_correlator.fstore") as mock_fstore:
|
||||
mock_fstore.doc_set = AsyncMock()
|
||||
await _update_incident(
|
||||
inc, "call-1", 9048, "sys-1", [], None, None, ["6-Adam"], [], None,
|
||||
later_now,
|
||||
)
|
||||
updates = mock_fstore.doc_set.await_args.args[2]
|
||||
assert updates["updated_at"] == later_now.isoformat()
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_master_auto_resolve_stamps_resolved_at():
|
||||
"""maybe_resolve_parent closes a master once every child has resolved."""
|
||||
|
||||
Reference in New Issue
Block a user