Skip to content

fix(brain,mic,ops): contain operator Claude memory, extend PSI/cgroup observability - #286

Merged
adrianwedd merged 2 commits into
masterfrom
fix-219-resource-containment
Aug 23, 2026
Merged

adrianwedd merged 2 commits into
masterfrom
fix-219-resource-containment

Conversation

@adrianwedd

@adrianwedd adrianwedd commented Aug 23, 2026 •

Copy link
Copy Markdown
Owner

Summary

2026-08-23 live memory-pressure investigation found the uncontained
interactive/operator Claude session was the single largest memory consumer
on the host (~862 MiB PSS for claude alone, ~1.43 GiB current / 1.67 GiB
peak for the whole session-N.scope, no MemoryHigh/MemoryMax at all) —
docs/operations/resource-containment.md had already flagged this class of
session as deliberately-deferred follow-up work from #217/#218/#219. This PR
is that follow-up, the observability extension needed to see memory/IO
pressure (not just CPU) in existing #270/#283 logging, and — following two
further live wedges observed mid-investigation — a fix for px-wake-listen's
own allocator-retention defect and a bounded startup contract.

  • Track A — bin/px-claude-dev wraps operator claude invocations in a
    dedicated systemd-run --user --scope (MemoryHigh=1024M,
    MemoryMax=2048M by default, both overridable). Confirmed via live cgroup
    inspection that PulseAudio/PipeWire sit under user@1000.service, a
    sibling of the raw SSH session scope — not a child of user-1000.slice as
    a whole — so this cannot throttle audio infrastructure. Does not touch
    spark-brain (contained separately, unaffected). Only affects future
    sessions launched through the wrapper.

  • Track C — src/pxh/hostload.py adds memory/IO PSI (some+full avg10),
    SwapFree, and per-unit cgroup pressure (mem_ratio, events_high,
    events_high_rate) for px-brain/px-wake-listen. The prior CPU-only PSI
    sampling read 0 throughout the pressure episode that motivated this, while
    memory/IO PSI reached 46%/65% full avg10 — none of brain: voice_turn tail latency exceeds its own 45s declared budget (up to 86.5s observed) #270/voice: arecord ALSA-level overruns (up to 56.8s) during live capture — likely a major no-transcript contributor #283's existing
    events could be correlated against the real bottleneck. Wired into the
    same call sites host_load_fields() already used; no new high-frequency
    logging; existing load1_/psi_cpu_avg10_ keys unchanged.

  • Track B — allocator retention fix + bounded startup contract.
    bin/px-wake-memprofile (repeated-cycle mode, PX_MEMPROFILE_CYCLES=8)
    isolated the two components of this service's memory: model load plus one
    untrimmed inference legitimately costs 707-730M PSS/RSS (Vosk grammar +
    SenseVoice's onnxruntime session — inference itself adds only ~12M) — but
    that figure never fell back down on its own. gc.collect() alone (Python-
    level references only) recovers little of it; malloc_trim(0) via
    ctypes.CDLL("libc.so.6"), run without unloading either model, is
    what returns the freed-but-retained glibc arena memory to the OS:

    Stage PSS RSS
    after both models load, before any inference 707-718M 718-730M
    after one untrimmed inference 719M 729M (+~12M)
    after the first malloc_trim(0) call 449M 460M
    after 7 further inference+trim cycles 449M (±70K noise) 460M exactly, zero drift

    _release_transient_memory() (that same gc.collect() + malloc_trim(0)
    pair) now runs from bin/px-wake-listen's _do_transcribe() — the single
    chokepoint every STT fallback path returns through, including a full
    fall-through to Vosk — pinned by tests/test_wake_memory_containment.py.

    MemoryHigh/MemoryMax recalibrated 640M/1024M → 896M/1280M
    from that evidence, not a round number: malloc_trim can't reach the
    load-time peak (it only runs after a completed transcription, so the
    707-730M figure happens once per process lifetime before any trim call
    exists to catch it). Sizing MemoryHigh to the post-trim floor (460M)
    would throw the ceiling straight back below the unavoidable load peak —
    reproducing the exact failure the old 640M value already had. 896M clears
    the measured peak with ~25-27% headroom; 1280M keeps ~43% margin above
    that and stays above the historical 900-924M pre-fix VmHWM peak.

    px-wake-listen.service converts Type=simple → Type=notify
    (NotifyAccess=main, TimeoutStartSec=900): under Type=simple the unit
    is "started" the instant it exec()s, so TimeoutStartSec never actually
    gated model-load time — which is why a live incident on 2026-08-23 sat
    wedged in mem_cgroup_handle_over_high (synchronous reclaim under the old
    MemoryHigh) for 47.9 minutes with systemd having no idea anything
    was wrong. notify_ready() (mirroring bin/px-alive's helper) now fires
    only after STT backend selection completes, or from the duplicate-instance
    guard's clean exit — never before the daemon can do its job.

    Live redeploy, 2026-08-23T19:45 AEST, under real host I/O contention
    (load1=6.2, psi_io_full_avg10=32.9-76.45, memory PSI at 0 — this was
    I/O, not memory, pressure): cold start completed in 44.7s, versus the
    prior 47.9-minute wedge (and a second ~4m54s wedge, observed mid-session,
    before this fix shipped). systemctl start correctly blocked on
    READY=1 rather than returning early. memory.events:high rose from 0 to
    96 during the load window itself, then froze — no wedge, no OOM, no max
    events. Resting floor post-load: VmRSS=683.9M/Pss=673.1M, comfortably
    under the new MemoryHigh=896M.

    What remains unverified: an actual spoken "Hey Spark" wake word was
    not exercised this session — that needs a human voice at the physical
    mic, which cannot be manufactured. The identical
    gc.collect()/malloc_trim(0) logic was verified 8 times over against
    the same live model objects (flat 460M, no drift); the first genuine
    memtrim(post_transcribe) log line from real usage should be checked
    after the fact (journalctl -u px-wake-listen | grep memtrim).

Test plan

  • pytest tests/test_hostload.py — 11 tests, all pass
  • pytest tests/test_brain.py tests/test_brain_daemon.py tests/test_brain_envelope.py tests/test_mic_stream.py — 212 passed (2 pre-existing/unrelated flaky-under-load failures in test_brain.py, documented in project memory, pass cleanly in isolation)
  • bin/px-claude-dev smoke-tested live (PX_CLAUDE_BIN=/bin/true, 100M/150M scope, exit 0, args passed through)
  • bin/px-wake-memprofile run live twice, px-wake-listen stopped — repeated-cycle evidence above
  • pytest tests/test_wake_memory_containment.py — 5 new tests, all pass
  • pytest tests/test_systemd_containment.py — 50 tests, all pass (recalibrated 896M/1280M pair verified against every pinned constraint)
  • pytest -k wake -m "not live" — 41 passed, 1 skipped
  • Live redeploy: systemctl daemon-reload + systemctl start px-wake-listen, cold start timed and confirmed bounded (44.7s) under real host I/O contention
  • Deliberately not run: a full non-live suite on the production Pi itself, mid-fix, against the exact host whose resource envelope this PR is correcting — CI is the full-suite gate for this PR
  • A genuine spoken wake-word interaction in production, confirmed via journalctl -u px-wake-listen | grep memtrim after next natural use — not manufactured

🤖 Generated with Claude Code

https://claude.ai/code/session_01HnKHd6i8Et8i8A4X7geMT3

… observability (#219)

Track A: bin/px-claude-dev wraps interactive/operator `claude` sessions in a
dedicated systemd-run --user --scope with MemoryHigh/MemoryMax (defaults
1024M/2048M), instead of the uncontained ~1.43GiB current / 1.67GiB peak
session-2.scope the 2026-08-23 live capture found as the largest single
memory consumer on the host. Confirmed via live cgroup inspection that this
cannot throttle PulseAudio/PipeWire (they sit under user@1000.service, a
sibling of the raw SSH session scope, not user-1000.slice as a whole) and
does not touch spark-brain (px-brain.service is contained separately).

Track C: src/pxh/hostload.py adds memory/IO PSI (some+full avg10), SwapFree,
and per-unit cgroup containment pressure (mem_ratio, events_high,
events_high_rate) for px-brain and px-wake-listen — the prior CPU-only PSI
sampling stayed at 0 throughout the pressure episode this investigated,
while memory/IO PSI reached 46%/65% full avg10, so none of #270/#283's
existing logged events could be correlated against the real bottleneck.
Wired into the same brain.py/mic_stream.py call sites host_load_fields()
already used (voice_turn start/end, arecord overrun detection) — no new
high-frequency logging. Existing load1_/psi_cpu_avg10_ keys are unchanged.

bin/px-wake-memprofile (Track B tooling, not yet run live): stage-by-stage
RSS/PSS profiler mirroring px-wake-listen's Vosk+SenseVoice loading path, to
characterize what actually fills the ~709MiB observed working set beyond the
documented ~228MB SenseVoice int8 weights. Requires stopping the live
px-wake-listen.service first (loads a second copy of both models) — left as
an explicit next step rather than run against the currently-pressured host.

docs/operations/resource-containment.md documents both, closing the gap the
#217/#218/#219 doc already flagged as deliberately deferred follow-up work.

Test plan:
- pytest tests/test_hostload.py (11 new tests, all pass)
- pytest tests/test_brain.py tests/test_brain_daemon.py
  tests/test_brain_envelope.py tests/test_mic_stream.py (212 passed; 2
  failures on the full run were background-thread inbox-visibility races in
  test_brain.py, confirmed pre-existing/unrelated by passing in isolation —
  known flaky-under-load pattern, not caused by this change)
- bin/px-claude-dev smoke-tested live with PX_CLAUDE_BIN=/bin/true under a
  100M/150M scope (exit 0, args passed through)
- bin/px-wake-memprofile: bash + embedded Python syntax verified; not yet
  run live (see above)

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HnKHd6i8Et8i8A4X7geMT3
@adrianwedd

Copy link
Copy Markdown
Owner Author

Track B live characterization — executed 2026-08-23 18:24–18:52 AEST

Ran the controlled Track B procedure against the real px-wake-listen.service per the authorised plan: baseline capture → clean stop → mic-release confirmation → single bin/px-wake-memprofile run → restart → verification.

Baseline (before stopping, 3.5h uptime)

memory.current      736,595,968 B  (702.6 MiB)
memory.peak         750,026,752 B  (715.2 MiB, this boot)
memory.high         671,088,640 B  (640 MiB)  — already exceeded, throttling active
memory.max        1,073,741,824 B  (1024 MiB)
memory.swap.current  222,064,640 B  (211.8 MiB)
memory.events        high=878370 (cumulative this boot)  oom=0
anon                 721,072,128 B  (100% of RSS — no file-backed pages)

Host at that moment: PSI memory some avg10=45.61 full avg10=31.39; swap 511.8/512 MiB (99.9% full); 51 MiB free.

Stage-by-stage profiler results (bin/px-wake-memprofile, single instance, service stopped, mic confirmed released via pactl/fuser before running)

stage RSS Δ
0 interpreter baseline 10.2 MB —
1 after vosk import 32.3 MB +22.1 MB
2 after sherpa_onnx import 40.0 MB +7.8 MB
3 after Vosk model loaded 160.6 MB +120.6 MB
4 after SenseVoice model loaded 654.6 MB +494.0 MB
5 after one transcription 666.6 MB +12.0 MB
6 after del + gc.collect() 585.1 MB −81.5 MB freed
7 after malloc_trim(0) 85.5 MB −499.6 MB freed

Script note: its own final json.dumps() crashes with NameError: name 'sensevoice' is not defined — it references sensevoice in the summary dict after del sensevoice a few lines earlier, which unbinds the name entirely. Harmless to the measurement (all 8 stage snapshots print to stderr before that line runs, captured above), but worth a one-line fix (cache sensevoice_loaded = sensevoice is not None before the del) alongside the Track B fix.

Answering A/B/C/D

D — combination of A and B, C ruled out as a major factor.

  • A (two-model resident working set) is the dominant, unavoidable floor. One load-both-models-and-transcribe-once cycle already costs ~666 MB RSS — matching the live cgroup baseline (~702 MB current) almost exactly. SenseVoice int8 alone is ~494 MB, more than double the ~228 MB the existing containment drop-in comment estimates from the model's on-disk footprint. onnxruntime's arena allocator plus int8→working-precision buffers cost far more resident memory than the quantized file size implies. This matches the drop-in's own note about "a single unreclaimable ~446M anonymous heap, byte-identical across 73 samples — a static allocation, not a leak."
  • B (allocator/heap retention) is real and is the likely reason MemoryHigh is chronically breached rather than touched once. After del-ing both models and gc.collect(), RSS dropped only ~82 MB (666.6→585.1 MB) — Python's GC returns almost nothing to the OS. It took an explicit malloc_trim(0) to release the other ~500 MB. Production code never calls del/malloc_trim — models stay resident and referenced for the service's life — so this retention shows up instead as every onnxruntime arena-growth event (real, variable-length utterances vs. the profiler's single 1s-silence warm-up) being a one-way ratchet glibc's malloc never gives back mid-process. Plausible mechanism for the drop-in's documented "climbing" behavior on top of A's static floor.
  • C (transient load peak) is not significant. Stage 4→5 (loaded → after first real inference) only adds ~12 MB; the load path itself doesn't spike meaningfully above resting size.

Unplanned findings surfaced during this run (pre-existing, not caused by the characterization)

  1. Stop always times out and SIGKILLs. TimeoutStopUSec=5s; journal shows State 'stop-sigterm' timed out. Killing on every stop this boot (including the one this characterization performed) — service lands in failed (Result: timeout) rather than clean inactive. Restart=always covers it operationally, but 5s may be too short for a process unwinding an arecord reader thread + onnxruntime thread pool across ~700 MB. Worth a look independent of Track B.

  2. SenseVoice cold-start load time is extremely variable and directly coupled to host memory pressure — from this boot's own journal:

    • low contention: 15–70s (several Aug 19–20 boots)
    • moderate: 3m34s, 5m57s (Aug 19 20:19, Aug 23 12:31)
    • severe: 5h15m43s (Aug 23 04:22→09:37, earlier today, before this characterization started)
    • this restart: still loading after 18+ min when this comment was written; cgroup memory.current ~723 MB (near resting size), growth down to ~1 KB/s, process alive in D-state (disk sleep), not wedged — PSI has begun easing (some avg10 peaked at 63.08, now 28.84) so it's expected to complete per the pattern above.

    This means MemoryHigh throttling, under real host contention, does not fail safely — it can turn a normally sub-minute cold start into a multi-hour state where systemd reports the unit active while it isn't actually listening yet. Likely root-cause candidate for silent wake-word unresponsiveness episodes that wouldn't surface via systemctl is-active monitoring alone.

  3. During the slow reload, host PSI peaked at some avg10=63.08/full avg10=55.17 with swap fully saturated again (511.8/512 MiB) — worse than the pre-stop baseline. No dmesg/brcmfmac symptoms observed in this window, but the shape (severe memory pressure + swap saturation) matches incident: resource starvation correlated with brcmfmac SDIO control timeout — Wi-Fi dies with no self-recovery (2 reproductions) #217's SDIO-wedge-under-load description closely enough to be worth a cross-check next time it recurs.

Verification checklist status

  • service active (systemd sees PID 86220 running, not failed)
  • wake model loaded — SenseVoice still loading at time of writing (finding CRITICAL: px-diagnostics uses relative paths for all child tool calls - silent failure when CWD != project root #2)
  • mic capture healthy — can't confirm until load completes; capture source correctly SUSPENDED (not falsely held open) throughout
  • spark-brain unaffected — stayed validated throughout, turns_total unchanged, no interruption
  • no unexpected px-alive/GPIO disturbance — px-alive active, PID unchanged, no gpio_lease.json (expected, idle), no OOM/PSI events attributable to it
  • memory/IO PSI after restart — still elevated but trending down; expect settle once load completes, per historical precedent above
  • exactly one profiler instance run, never concurrent
  • [~] robot left in original operational state — in progress; service was never left down (Restart=always guarantees no permanent loss even if this load attempt is killed and retried)

Will follow up once SenseVoice finishes loading to close out the remaining checklist items. No model, MemoryHigh/MemoryMax, or service-architecture changes were made during this characterization, per the constraint.

…p contract (#219 Track B)

bin/px-wake-memprofile (repeated-cycle mode) isolated the ~707-730M model-load
footprint from a separate, fixable defect: neither `del` nor gc.collect() on
Python-level references reclaimed retained onnxruntime/glibc arena memory
after a transcription cycle, so RSS ratcheted upward across hours of
operation. malloc_trim(0) via ctypes, run without unloading either resident
model, drops the post-inference floor from 729M to 460M and holds it flat
across 8 repeated cycles with zero drift.

- _release_transient_memory() (gc.collect + malloc_trim(0)) now runs from
  _do_transcribe()'s single exit point, on every STT fallback path.
- px-wake-listen.service converts Type=simple -> Type=notify (NotifyAccess=
  main, TimeoutStartSec=900): under Type=simple TimeoutStartSec never gated
  model-load time at all, which is why a live incident sat wedged in
  mem_cgroup_handle_over_high for 47.9 minutes with systemd unaware anything
  was wrong. notify_ready() now fires only after STT backend selection (or
  the duplicate-instance guard's clean exit).
- MemoryHigh/MemoryMax recalibrated 640M/1024M -> 896M/1280M from the
  measured load-time peak (707-730M), not the lower post-trim steady state
  (460M) -- trimming can't reach the one-time load peak, so sizing the
  ceiling to the trimmed floor would reproduce the original throttle-on-
  every-start failure.

Live redeploy under real host I/O contention (psi_io_full_avg10=32.9-76.45):
cold start completed in 44.7s, versus the prior 47.9-minute wedge and a
second ~4m54s wedge observed mid-session before this fix.

Unverified by this session: a genuine spoken wake-word cycle in production,
which needs a human voice at the physical mic. The profiler exercises the
identical gc.collect()/malloc_trim(0) logic against the same live model
objects across 8 cycles; the first real memtrim(post_transcribe) log line
should be checked once the robot is next used.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HnKHd6i8Et8i8A4X7geMT3
@cloudflare-workers-and-pages

Copy link
Copy Markdown

Deploying spark with  Cloudflare Pages  Cloudflare Pages

Latest commit: 2e7b280
Status: ✅  Deploy successful!
Preview URL: https://f709ad9d.spark-e11.pages.dev
Branch Preview URL: https://fix-219-resource-containment.spark-e11.pages.dev

View logs

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

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant