A cached-telemetry audit row whose OperationTracking snapshot could not be
resolved was skipped and left Pending. Nothing ever removed it, so the next
drain re-read it, failed identically, and logged again — forever.
The severity was worse than the original write-up said. The queue is read
oldest-first with a fixed BatchSize (default 256), so once a batch's worth of
permanently-unresolvable rows collected at the head, every drain re-read
exactly those rows and NEVER REACHED the newer rows behind them. That is a
permanent stall of the cached-telemetry path, not the "log flood, no data loss"
the issue was first filed as. Measured on the rig at ~2,800 warnings/minute,
surviving both a process restart and a container restart.
Fix: after a grace period (CachedTrackingGraceSeconds, default 300 s) the
operational half is abandoned and the row marked Forwarded. A row with no
CorrelationId is abandoned immediately — it can never resolve.
Marking Forwarded does not drop audit data. That state means "no longer owed by
the drain, still eligible for reconciliation", which is exactly this situation:
ReadPendingSinceAsync covers Forwarded as well as Pending and central dedups on
EventId, so the reconciliation pull still delivers the audit half. What is lost
is the operational (SiteCalls) half, which is unrecoverable anyway once the
tracking row is gone.
Three deliberate boundaries:
- Inside the grace window the row is still retried — a missing snapshot is
normally a brief write race, and abandoning on the first failed lookup would
discard the operational half of every cached call that lost that race.
- A tracking-store THROW never abandons, however old the row: a throw is a
store fault (locked, corrupt, mid-restore), not a verdict about the row.
- Logging is per drain pass, not per row. Deferred rows dropped to Debug —
being inside the grace window is normal operation, not a warning.
CachedDrain_OrphanRow_NoTrackingSnapshot_IsSkipped_DoesNotCrash was RETARGETED
rather than deleted: it pinned the defect ("skipped and stays Pending"), so its
orphan assertion is inverted and the half that still holds is kept verbatim.
Three tests added, including the starvation regression. Both "must NOT abandon"
tests carry a positive control on the read count, so they cannot pass by virtue
of a drain that never ran.
Verified non-vacuous: with abandonment disabled the two abandonment tests go
red and the two guards stay green. Build 0 warnings; AuditLog 358, Host 330,
SiteRuntime 512, StoreAndForward 130, Communication 312, Commons 684,
Integration 94 — all pass.
Claude-Session: https://claude.ai/code/session_01BL2Vu1ESDQ9SCN4gVKkdts
The Phase 2 soak's "LocalDb fails under load" blocker is NOT a product defect.
Root cause: host-side (macOS) sqlite3 reads of the live, bind-mounted WAL
databases. POSIX advisory locks do not propagate across the virtiofs boundary,
so the host reader believes it is the only connection, checkpoints on close and
resets the WAL to 0 bytes under the container. The container's still-mapped
WAL index then references frames that no longer exist and every subsequent
statement fails SQLITE_IOERR_SHORT_READ (522) -> primary code 10, permanently
until the process reopens the database.
Reproduced on demand both on the rig (one sqlite3 SELECT reset a 4.6 MiB WAL and
produced the first error one second later) and in a minimal python:3.12-alpine
repro with no LocalDb or .NET involved. Refuted the converse: a freshly-reopened
node sustained the full soak load 10+ minutes with zero errors.
The original brief's isolation was confounded - both nodes had been poisoned by
the same sampling pass, and a poisoned standby looks healthy only because it
issues almost no statements. Corrections annotated in place.
Hardening shipped alongside:
- SqliteErrorCodes.Describe: log SQLite primary AND extended codes at the
LocalDb-adjacent catch sites (the missing extended code is what made the
original diagnosis so slow).
- SiteAuditTelemetryActor: stop touching ActorContext across an await
(NotSupportedException), with regression coverage.
- infra/reseed.sh: apply the MSSQL init scripts explicitly. The official
mssql/server image does not implement /docker-entrypoint-initdb.d, so a fresh
volume hung the reseed forever; compose mounts annotated as informational.
Deliberately NOT done: detect-and-reopen self-heal in SqliteLocalDb. It defends
only against external interference, which is now prevented at the source, and
same-kernel production readers see the locks correctly.
Build 0 warnings; SiteAuditTelemetryActorTests 9/9, SiteEventLogging 70/70.
Claude-Session: https://claude.ai/code/session_01BL2Vu1ESDQ9SCN4gVKkdts
Joseph Doherty