Skip to content

sessions: admission refusal storm (observation_retrieval_anchor_alias_collision, ~68k WARNs, ~640 sessions) pins daemon at ~180% CPU #4564

Closed

Description

@spa5k

Summary

The daemon pins ~180% CPU indefinitely after each Pi session discovery pass. The log shows a large admission-refusal storm with a single reason — observation_retrieval_anchor_alias_collision — affecting ~640 distinct Pi sessions, repeating for 2+ days. The affected session files themselves look valid.

This is related to #4481 (same machine, same CPU signature) but names a different, much more numerous failure than the InvalidSessionHeader discovery failures discussed there.

Environment

  • tracedecay 1.0.0-beta.92+c443aaa71d48457d07faa2737fac42164255371a.dirty (locally built, beta channel)
  • macOS 27.0.1 (26A434), Apple M4 (10 CPUs), 32 GB RAM
  • Daemon as launchd user service, 8 registered projects
  • Pi sessions directory: 1,029 .jsonl files, 713 MB total

The refusal storm

Across the current and one rotated daemon.err.log:

Log Refusals Distinct sessions First Last
daemon.err.log.1 59,347 599 2026-10-24T15:58:33Z 2026-10-26T04:47:36Z
daemon.err.log 9,055 45 2026-10-26T04:47:37Z 2026-10-26T11:52:04Z

Total 68,402 WARN lines, all with the same shape:

WARN tracedecay_sessions::runtime::observation::jsonl_observation_admission: admission refused a record; covering past it provider="pi" session="019fc6b9-2a6a-77a6-8d5c-4371b234bd0a" offset=196568 reason="observation_retrieval_anchor_alias_collision" cause="unspecified"
  • 100% of the refusals carry reason="observation_retrieval_anchor_alias_collision".
  • ~644 distinct session IDs; top offenders get 1,000–3,500 refusals each; a long tail gets 5–100.
  • Refusals arrive ~1.7/s in bursts, then pause, then resume — consistent with a pass that never converges and is re-run.

The session files are not obviously malformed

I validated every Pi session file myself (Python, first line must be JSON with type == "session" and an id): all 1,029 files pass. So unlike the 176 InvalidSessionHeader files from #4481, these ~644 sessions have readable headers; the collision appears to be internal to the observation/anchor admission layer (two records mapping to one retrieval anchor alias, presumably across sessions or re-admissions).

Reproduction timeline (observed twice today)

  1. tracedecay daemon restart.
  2. Daemon idle for ~13 minutes: 0.0–0.1% CPU, ~200 MB RSS, 57 threads. Scheduler ticks show only skipped tasks.
  3. A Pi discovery pass runs (log: 16 bounded InvalidSessionHeader lines + additional Pi discovery failures were bounded failure_count=176).
  4. In the same second as that burst, CPU jumps to ~180% and stays there. Over the next minutes RSS climbs 211 → 670+ MB and threads 57 → 65.
  5. The burn persists for hours (earlier daemon run: from start until we restarted it ~45 min later; the run before that burned for hours overnight).

Resource capture (30 s interval, ps-based):

2026-10-26T18:20:48  cpu=0.0%    rss=212MB  threads=58
2026-10-26T18:21:18  cpu=181.8%  rss=649MB  threads=65   <- discovery burst in log
2026-10-26T18:21:54  cpu=179.8%  rss=666MB  threads=65
2026-10-26T18:22:24  cpu=178.4%  rss=670MB  threads=65
2026-10-26T18:23:24  cpu=178.4%  rss=707MB  threads=65   (cpu time 4:33 in ~3 min)

What did not help / what I tried

  • Restarting the daemon clears the burn only until the next discovery pass (~13 min in the observed case).
  • sample (3 s and 8 s) shows all named worker threads parked in __psynch_cvwait/kevent while the process burns ~2 cores (verified by cputime deltas: +9.2 s CPU over 5 s wall). Per-thread ps -M during the burn showed two threads at ~90%/~81% in one capture, but stacks stay unsymbolized. The burn looks spread over many short-lived spawned tasks.
  • Quarantining the single worst session file (019fc6b9-…, 3,511 refusals in the current log era) — verdict pending, but given ~644 affected sessions a per-file workaround cannot scale.

Suggestion

The admission layer appears to re-attempt the same colliding records every pass without either (a) resolving/renaming the colliding anchor alias, or (b) quarantining the record after N failures. Either behavior would stop the permanent re-work; a source_digest-keyed skip list (as suggested for #4481's discovery failures) would also cap the per-pass cost.

Happy to provide the full CSV monitor data, per-session refusal counts, or the session files involved.

Activity

  1. ScriptedAlchemy commented on Nov 3, 2026

    @ScriptedAlchemy
    Owner

    Closing the repeated admission-refusal storm as addressed by merged #4567 and its canonical-evidence correction #4577. Rechecked on master 106e54df81ef640894138100d4ca5b0f9a8370dc: deterministic refusal and covered cursor state are committed together through record_refusal_with_coverage; replay cannot use a stale refusal memo to skip uncovered bytes, and unchanged admitted Pi inputs converge across fresh sweeps. The maintained provider regressions cover EOF refusal replay, retention, changed generations, restart, and same-length source rewrites.

    This closes the permanent re-admission/logging loop described here. Alias collisions still produce typed refusals; it does not claim that all causes of idle CPU, corrupt-store recovery, or storage growth are fixed. Those remaining problems stay tracked in #4481, #4569, and #4616.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions