diff --git a/docs/known-issues/2026-07-20-cached-telemetry-drain-hot-loop.md b/docs/known-issues/2026-07-20-cached-telemetry-drain-hot-loop.md new file mode 100644 index 00000000..d44037a5 --- /dev/null +++ b/docs/known-issues/2026-07-20-cached-telemetry-drain-hot-loop.md @@ -0,0 +1,92 @@ +# Cached-telemetry drain hot-loops forever on a row whose tracking snapshot is gone + +**Date:** 2026-07-20 · **Status:** OPEN · **Severity:** Medium (log flood + wasted I/O; no data loss) +· **Area:** AuditLog / Site Telemetry + +## Summary + +`SiteAuditTelemetryActor`'s cached-telemetry drain reads Pending audit rows, looks up each row's +tracking snapshot by `CorrelationId`, and pushes the combined packet to central. When the lookup +returns `null` the row is **skipped and deliberately left Pending** +(`SiteAuditTelemetryActor.cs:307`), on the reasoning that "central reconciliation will pick it up". + +Nothing ever removes such a row from the local drain queue. The next tick re-reads it, fails the +same lookup, logs the same warning, and leaves it Pending again — **forever**. With a batch of +unresolvable rows the actor spins at its non-idle rate and emits one warning per row per pass. + +Measured on the docker rig: **~2 800 warnings/minute, sustained**, surviving both a process restart +and a container restart, until the audit database itself was discarded. + +``` +[09:57:41 WRN] [Site/scadabridge-site-a-a] Cached-telemetry drain: no tracking snapshot for + a5392796-291f-4f5b-9fbf-5817c1ec76c7 (TrackedOperationId 59bd4bf8-…); skipping. +``` + +## Why the rows became unresolvable + +Two independent stores must agree: + +- the **audit** rows live in `auditlog.db` (site-local, and on the docker rig **inside the + container at `/app/auditlog.db`**, not on the bind-mounted data volume); +- the **tracking** rows live in `OperationTracking`, which LocalDb Phase 1 moved into the + consolidated `LocalDb:Path` database (bind-mounted). + +Anything that resets one without the other strands every audit row that referenced it. The code +comment already anticipates the cause — *"possible if the audit row is older than the tracking +retention window, or the tracking store was reset"* — so this is a known-and-accepted input, not an +exotic one. + +**Two realistic production triggers, neither requiring operator error:** + +1. **Tracking retention expiry.** If the tracking retention window elapses before the audit drain + catches up — a long central outage, a large backlog — the snapshots are pruned out from under + still-Pending audit rows and every one of them becomes a permanent hot-loop entry. +2. **Restoring or resetting one store independently of the other**, e.g. rebuilding a node's + LocalDb file from its peer while its container-local `auditlog.db` survives. + +It was hit here by (2): the two site-a LocalDb databases were dropped during a rig cleanup while +`auditlog.db` — being inside the container — survived. + +## Why the current handling is not enough + +Skipping the row is correct; **leaving it Pending with no other state change is not**. The row is +now in a state it can never leave: + +- no attempt counter, so an unresolvable row is indistinguishable from a transiently-failing one; +- no backoff, so the actor runs at full non-idle rate against a queue that can never shrink; +- no terminal state, so it is retried for the life of the database; +- one Warning per row per pass, which buries every other log line on the node. + +The "central reconciliation will pick it up" comment is about the **audit half** reaching central by +another path. That may well be true — but it does not release the row from the local drain queue, +which is what actually loops. + +## Suggested fix + +Give an unresolvable row somewhere to go. Roughly, in increasing order of effort: + +1. **Bound the retries.** Add an attempt count; past a threshold mark the row terminal + (`TrackingUnavailable`) and stop re-reading it. Emit a single summary Warning with the count + rather than one per row per pass. +2. **Rate-limit the warning** to one per drain episode regardless of row count — the same pattern + `MaintenanceBackgroundService` already uses for the oplog caps-exceeded warning (`_snapshotFlagWarned`). +3. **Push the audit half alone** when the tracking snapshot is missing, rather than skipping the row + entirely, so the row can be marked emitted and leave the queue. Needs a decision on whether + central accepts a packet with no tracking half. + +(2) alone would remove the operational damage; (1) or (3) is needed to stop the wasted I/O. + +## Reproduction + +1. Run a site node until it has cached-call audit rows with tracking correlations. +2. Stop the node; delete its consolidated LocalDb database (which holds `OperationTracking`); + leave `auditlog.db` in place. +3. Start the node. The drain warning repeats indefinitely; the rate does not decay. + +## Notes + +- **No data loss.** The audit rows are intact and still reach central by the reconciliation path; + what is broken is the local drain's ability to ever finish. +- Discovered while cleaning the rig after the LocalDb Phase 2 live gate + (`docs/plans/2026-07-19-localdb-phase2-live-gate.md`), which is also where the related + "deleting an instance orphans its buffered messages" observation is recorded.