fix: /status off the spool walk, and trim drained queue files as they are processed

[Diego Colombo (colombod)]

Two problems, one root: unbounded spool work on a hot path

PR #99 stopped crash recovery blocking the HTTP surface at startup. This finishes the job for
the request path, and stops the spool growing in the first place.

1. /status walks the entire queue directory, per request

Measured on team-shared today, on a healthy replica running #99:

GET /version  →  200 in 0s
GET /status   →  times out at 180s (also failed 3× at 120s)

/status calls spool_stats(), which scanned inline (queue_manager.py):

for entry in self._dir.iterdir():        # every file in queues/  → ~5000 entries
    size = entry.stat().st_size          # one SMB round trip each
    if entry.suffix == ".log":
        committed = self._read_committed_offset(entry.stem)   # open+read+close, per .log

~5000 stat() calls plus ~1700 file opens over Azure Files SMB, on the request. The existing
_spool_cache_ttl = 5.0 only helped the second caller — the first caller after every expiry paid
the full walk.

So the health endpoint's cost scaled with the backlog, and became unusable at exactly the moment you
needed to look at it. Same inversion as the outage itself, one layer up.

2. Queue files are never trimmed as they're processed

commit() writes only the .offset; the .log is untouched. The only reclaim is
delete_drained(), called from exactly one place — _finalize_session. So a session that never
finalizes cleanly (crash, orphan, indefinite idle) keeps its .log/.offset forever, and every
subsequent boot's recovery re-walks them.

That is the ratchet behind today's incident: the more the server failed to start, the more files it
left behind, the slower the next start. Local evidence on a developer box: spool_bytes_total
1.69 GiB with pending_sessions: 1 — nearly all of it drained and never reclaimed.

Fix

/status off the spool walk

• spool_stats() is now synchronous and cache-only — it never touches the filesystem and never
  raises. Returns the last snapshot, or the existing {-1,-1} "temporarily unavailable" sentinel.
• New refresh_spool_stats() performs the scan (the previous body, verbatim, including its
  fault-isolation) and updates the cache.
• New _spool_stats_refresher(app) background task in main.py runs the refresh on its own
  cadence, following the exact create_task / cancel-in-finally pattern fix: crash recovery must not block the HTTP surface at startup #99 established for
  _startup_recovery. It is fail-loud but self-healing: a failed refresh is logged via
  logger.exception and the loop continues, so the snapshot goes stale rather than the refresher
  dying silently.
• New setting spool_stats_refresh_interval_seconds (default 60.0, validated > 0).
• /status's spool block gains as_of_seconds — how old the snapshot is, None before the
  first refresh. Staleness is stated, never presented as live.
• The dead _spool_cache_ttl read-gate is removed; the refresher owns the cadence.

/status is now O(1) regardless of spool size.

Trim as processing proceeds

In the drain loop's existing idle branch (the idle_elapsed >= flush_timeout block that already
holds the stale-session reap check), after that check and without altering it, attempt reclaim:

if await qm.delete_drained(session_id):
    logger.debug("spool_trimmed session=%s", session_id, ...)

This is the same call _finalize_session already makes — just triggered earlier and
repeatedly. It is safe by construction: delete_drained is idempotent, takes the key's
file_lock, refuses cheaply (returns False) while any uncommitted bytes remain, keeps
.dead.jsonl, and explicitly anticipates recreation — it unlinks a stale .offset so a log
recreated by a later append cannot read past its own end.

Conservation accounting is preserved. I checked the arithmetic in recovery_seed_counts: for a
trimmed key whose .dead.jsonl survives, committed→0, before→0, pending→0, dead→D, so
written_seed = max(0, 0-D) = 0, accepted += D, written += 0 → residual D - 0 - 0 - D = 0.
Clean. queue_manager.py already documents this case ("a .log deleted by delete_drained has no
log to reconcile").

Tests

Test	Guards
test_spool_stats_is_synchronous_read_only_and_never_scans	spool_stats() performs no filesystem access even with iterdir patched to raise
test_spool_stats_age_seconds_none_before_any_refresh / ..._reflects_time_since_refresh	the staleness signal
test_status_spool_as_of_seconds_none_before_any_refresh	/status before the first refresh returns the sentinel, not a scan
test_status_spool_block_reflects_real_backlog_after_refresh	real numbers once refreshed
test_spool_stats_refresher_survives_a_failing_refresh	a raising refresh is logged at ERROR and the loop continues
test_spool_stats_refresher_task_is_cancelled_on_shutdown	no task survives lifespan exit
TestDurableSpoolTrim::test_idle_drained_session_trims_log_and_offset_keeps_dead_letters	trim happens; .dead.jsonl survives
TestDurableSpoolTrim::test_idle_uncommitted_bytes_are_never_trimmed	pending data is never discarded
test_recovery_seed_counts_residual_zero_after_trimming_dead_letter_session	conservation across a trim

Plus the pre-existing spool_stats tests updated to call refresh_spool_stats() where they
exercise the scan.

24 tests verified RED against main (source reverted, tests kept).

Results: pytest -m "not neo4j" → 1999 passed, 7 skipped, 92 deselected.
pytest -m neo4j (live containers) → 92 passed. ruff format --check clean on all 7 files.

Version bumped 6.7.4 → 6.7.5.

Deliberately NOT in this PR

Dead-letter files are not auto-purged. The request mentioned trimming dead letters too, and I
have not done it. They are the record of what failed — and after the derive_labels incident
(#100) they are currently the only trace of the events that were destroyed. Auto-deletion would
destroy evidence on a timer. purge_dead_letters() stays operator-invoked. If retention is wanted,
it should be age-based and off by default — a design decision, not a patch.

Boot-time recounting is untouched. recovery_seed_counts still streams every byte from 0 to
committed, per key, on every boot — the real cost behind the 91-second phase-2 stall. Persisting
the committed line count beside the offset would turn that into a small file read, but it changes
the on-disk offset format on the hottest write path and deserves its own PR and its own review.

The batch amplifier is untouched. A per-row failure inside _write_batch still fails the whole
chunk, and _handle_exhausted_batch still dead-letters healthy neighbours and commits past them.
Quarantining the offending row is the durable fix and touches queue-commit semantics.

---

Addendum — two additions after running it on a real spool

The first version of this PR was tested but never run. Deploying it to a live server with a
2.12 GiB spool found a real limitation, which these two additions close.

What running it revealed

The per-session trim fires in the drain loop's idle branch — so it only ever reaches a session
that currently has a live drain worker. Crash recovery respawns a worker only for a session
with undrained data. A session that fully drained and then went away therefore gets no worker,
never reaches the idle branch, and keeps its files forever — and every later boot's recovery
re-walks them.

Measured on the local box, after the per-session trim had already run and reclaimed everything it
could reach:

25 of 25 .log files fully drained (committed == size), 1,539,537,213 bytes (1.43 GiB)
    691,381,772 bytes  committed=691,381,772  drained=YES
    599,990,355 bytes  committed=599,990,355  drained=YES
     68,951,948 bytes  committed=68,951,948   drained=YES

The largest files on disk were precisely the ones the trim could not see.

Addition 1 — QueueManager.reclaim_drained_orphans()

Called from _startup_recovery_body, immediately after the respawn loop. Iterates every worker
key and delegates to delete_drained, which is what makes it safe: idempotent, takes the key's
file_lock, refuses cheaply while any uncommitted byte remains, keeps .dead.jsonl, and
unlinks a stale .offset so a log recreated later cannot read past its own end. A key whose
drainer is mid-drain is skipped by delete_drained itself — no exclusion list, and no way to race
a drainer into losing data.

Ordering is deliberate: it runs after recovery_seed_counts, so the conservation baseline is
read from disk before anything is removed, and after the respawn loop, so a session with
pending data already has its drainer. Cost is O(keys), never O(bytes) — one stat for the
reclaimed size plus delete_drained's own stat and offset read. Wrapped in try/except: a disk
reclaim must never fail a boot.

Addition 2 — spool_trimmed raised from DEBUG to INFO

On the live box, 16 files were trimmed and the journal showed nothing — the log sat at DEBUG
while the server ran at INFO. A reclaim an operator cannot confirm is happening may as well not be
instrumented.

Evidence from the live deploy

Installed on the local server (systemd unit, real 1.43 GiB spool):

BEFORE   .log files: 25     du: 1,539,538,176 bytes (1.43 GiB)   [all 25 fully drained]

23:57:12  Application startup complete.
23:57:24  startup_recovery: crash recovery respawned 0/0 drainers
23:57:25  startup_recovery: reclaimed 25 fully-drained session file(s), ... byte(s) of spool

AFTER    .log files: 1      du: 796 bytes

1.43 GiB → 796 bytes, with recovery_complete: True, recovery_error: None, and zero
Traceback / dead_letter / flush_chunk_failed / level=ERROR lines.

The /status snapshot converging afterwards is itself a demonstration of as_of_seconds working
as intended — a stale snapshot is labelled stale rather than presented as live:

t+ 15s  bytes=1,530,951,126  as_of=47.7   ← pre-reclaim snapshot, honestly aged
t+ 30s  bytes=    1,478,695  as_of= 2.7   ← refresher ran
t+ 90s  bytes=          796  as_of= 2.9   ← matches `du` exactly

Tests for the additions

Nine new tests, all nine verified RED against the previous commit (e58bbcd):

Test	Guards
test_reclaim_drained_orphans_removes_fully_drained_key	exact (1, log_size) return
test_reclaim_drained_orphans_keeps_dead_letters	.dead.jsonl survives and stays readable
test_reclaim_drained_orphans_skips_key_with_uncommitted_bytes	pending data never discarded
test_reclaim_drained_orphans_ignores_dead_letter_only_key	a keyless-log reclaims nothing, isn't counted
test_reclaim_drained_orphans_mixed_directory	2 drained + 1 pending → (2, sum), pending untouched
test_reclaim_drained_orphans_per_key_failure_does_not_abort_pass	one OSError key doesn't stop the pass
test_startup_recovery_logs_reclaimed_orphans	the INFO line, with both counts
test_startup_recovery_orphan_reclaim_failure_does_not_fail_boot	a raising reclaim logs ERROR, boot completes
test_idle_drained_session_trim_logs_at_info	asserts levelno == INFO, not merely present

The last one went red for exactly the right reason on the old source: no INFO spool_trimmed
record existed, only drain_worker_cancelled — confirming the trim really was invisible at INFO.

Final: pytest -m "not neo4j" → 2008 passed, 7 skipped, 92 deselected.
pytest -m neo4j (live containers) → 92 passed. Version stays 6.7.5.