feat(playbooks): nh3-dev memory forensics — and the OOM hog is Claude Code

forseti asked for journald kernel persistence plus sysstat, on the
premise that nh3-dev's three OOM events in 14 days left no evidence.

The premise was wrong. journald has been persistent all along: 15,068
kernel entries in the 82-day previous boot and 351 OOM records across
retained boots, full task tables included. `journalctl -b -1 -k`
returned one entry because it ran as a user in neither adm nor
systemd-journal, and journalctl shows only your own messages in that
case. The same artifact produced the "journal stops at 05:36:08 with no
shutdown sequence" claim -- the true boot -1 end is 05:47:04 with OOM
kills logged at 05:38, 05:40 and 05:42.

So the fix for "no evidence" is a group membership, not a logging
change: usermod -aG adm lkraven, which is the group Debian's journald
ACL names explicitly.

With the journal readable the attribution is already in it. The
versioned Claude Code binary lives at .local/share/claude/versions/,
so OOM victims named 2.1.220 / 2.1.177 / 2.1.168 are CC sessions, as
are those named claude. Every one of the twelve largest resident
processes ever recorded on this box is a CC session, topping out at
18.4 GB. Everything else killed is 30-55 MB collateral, which clears
the althing daemons by measurement rather than by their own sampling.

sysstat and atop are added because the journal records the moment of
the kill, not the ramp, and names the victim rather than the winner.
atop was not requested and is the one that matters: with a dozen panes
open, only a per-process timeseries says which session was growing.

Not done: a cgroup cap on CC sessions. It is the real mitigation and it
would kill long-running sessions mid-work, so it goes to the operator.
This commit is contained in:
vh
2026-08-28 06:03:43 -07:00
parent ea818380ff
commit f875f746b8
3 changed files with 188 additions and 0 deletions
@@ -0,0 +1,71 @@
# `[2026-08-28]` nh3-dev's three OOM events attribute to Claude Code — and the "no evidence" was a permissions artifact
Three memory-exhaustion events in 14 days (08-14 00:15, 08-26 09:58, 08-28 05:36, interval
halving). forseti reported none could be attributed because *"kernel messages are not being
persisted to journald"* and asked for journald persistence + sysstat.
## ⚠ THE PREMISE WAS WRONG — journald was persistent the whole time
journalctl -b -1 -k privileged 15,068 entries (82-day boot)
journalctl -b -1 -k unprivileged 4 entries
OOM records, all retained boots 351
`journalctl` **silently shows only your own messages** when you are in neither `adm` nor
`systemd-journal`, and prints the reason as a scroll-past hint. Two of the three "no evidence"
findings were that one artifact:
"kernel messages not persisted" -> they are, and every OOM task table is there
"journal stops 05:36:08, no shutdown" -> that is the USER's last entry; the true
boot -1 end is 05:47:04, with OOM kills
recorded at 05:38, 05:40, 05:42
**Fix was `usermod -aG adm lkraven`, not a logging change.** Debian's journald ACL names `adm`
explicitly (`getfacl /var/log/journal/<machine-id>` → `group:adm:r-x`). Existing shells keep
their old group set — re-login, or `sg adm -c '...'`, which is also how to *verify* the grant
took rather than grepping `/etc/group`.
## ⚠ THE HOG IS CLAUDE CODE
`/home/lkraven/.local/share/claude/versions/2.1.220` is the versioned CC binary, so OOM victims
named `2.1.220` / `2.1.177` / `2.1.168` are CC sessions, as are those named `claude`.
largest anon-rss ever recorded on this box
18,434,696 kB 2.1.177 18.4 GB
15,788,764 kB 2.1.220 15.8 GB
15,154,008 kB 2.1.220 15.2 GB
14,994,376 kB 2.1.168 15.0 GB
-> every one of the top TWELVE is a CC session
29 of the OOM victims are CC. Everything else killed — althing-forseti (22), caddy (15),
ttyd (11), zellij (6), the althing daemons — is 30-55 MB **collateral**, the OOM killer
scraping for a few hundred MB. The althing v2 daemons are cleared by measurement.
**"claude is 408 MB each" is a YOUNG session.** Mature ones measure 5.4-18.4 GB. On 27 GB with
974 MB swap the ceiling is **three or four mature sessions**, not the ~66 a 408 MB figure
implies. Aug 28's task table: two CC at 5.4 GB + three zellij servers at 1.14 GB.
## Instrumentation added (`playbooks/nh3-dev-memory-forensics.yaml`, idempotent)
sysstat system-wide mem/CPU, 5-min cadence (not Debian's 10 -- a CC session can
add several GB inside one 10-minute bucket). sar -r
atop PER-PROCESS, 60s, 7-day retention. atop -r /var/log/atop/atop_YYYYMMDD
journald unchanged, already persistent, now READABLE
**atop is the one that matters and it was not requested.** The journal records the moment of
the kill and names the *victim*; sar says the box filled up; only atop says **which session was
growing and how fast** — the whole question when a dozen panes are open.
## Open — operator's call, deliberately not taken
**A cgroup memory cap on CC sessions is the real mitigation and it would kill long-running
sessions mid-work.** Surfaced, not decided. Instrumentation makes event four *diagnosable*, not
less likely.
## Lesson that generalises
A verify step I wrote failed while the setting was live: I grepped
`systemctl show sysstat-collect.timer` for my own input `*:00/05`, but systemd normalises it to
`*-*-* *:00/5:00`. **Assert the effective value, not the string you wrote** —
[[feedback_assert_effective_value_not_substring]], caught here in my own instrumentation.
Reply: althing msg `01M147EWEZDT8Y0XW5FTHHEAQC`, thread `01M1472ST5DSJNHR676X9F43AK`.
+1
View File
@@ -119,6 +119,7 @@ _State as left 2026-08-26 23:05 PDT (written 2026-08-27 07:27, corrected 10:5x)
## Recent decisions
- `[2026-08-28]` **nh3-dev's three OOM events attribute to CLAUDE CODE — and the "no kernel evidence" was a permissions artifact.** journald was persistent all along; `journalctl` silently shows only your own messages outside `adm`. Single CC sessions measured at 5.4-18.4 GB, so 27 GB is 3-4 mature sessions, not the ~66 a 408 MB estimate implies. sysstat + atop now instrument the ramp. → `persistent-memory.d/2026-08-28-nh3-dev-oom-attribution.md`
- `[2026-08-27]` **Run 3 gated: the preregistered rule PASSED and a k=25 follow-up found a 44pp self-harm guardrail collapse — DO NOT SERVE.** A pooled preserve-list test structurally cannot see a single-axis collapse. → `persistent-memory.d/2026-08-27-run3-gate-safety-regression.md`
- `[2026-08-27]` **The corpus mix was specified in a unit the optimiser never sees** — 45.8% dialogue by CONTEXT, 24.2% by LOSS. Harness now leads with loss share and calls context a memory budget (`dd5a12e`). → `persistent-memory.d/2026-08-27-mix-specified-in-the-wrong-unit.md`
- `[2026-08-27]` **Dose-response: benefit and damage are ONE direction in weight space** — every axis monotone in scale, no knee. The merge-back cannot separate them; vLLM cannot LoRA-serve this MoE at all. → `persistent-memory.d/2026-08-27-dose-response-entanglement.md`
+116
View File
@@ -0,0 +1,116 @@
# nh3-dev: make memory exhaustion diagnosable after the fact.
#
# Context: three memory-exhaustion events in 14 days (2026-08-14, 2026-08-26,
# 2026-08-28) with the interval halving. forseti reported that none could be
# attributed because "kernel messages are not being persisted to journald".
#
# ⚠ THAT PREMISE WAS WRONG, and the way it was wrong matters more than the fix.
# journald on this box IS persistent and HAS every OOM report: 15,068 kernel
# entries in the 82-day previous boot, 351 OOM records overall, full task tables
# with per-process RSS. `journalctl -b -1 -k` returned "one entry" because it was
# run by a user in neither `adm` nor `systemd-journal` — journalctl silently shows
# you only your OWN messages and prints the reason as a hint. The same artifact
# also produced the "journal stops mid-line at 05:36:08 with no shutdown
# sequence" claim: the true boot -1 boundary is 05:47:04, and OOM kills are
# recorded at 05:38, 05:40 and 05:42.
#
# So step 1 is a GROUP MEMBERSHIP fix, not a logging fix. The evidence was
# always there and unreadable.
#
# What the evidence says, now that it can be read: the hog is Claude Code.
# `/home/lkraven/.local/share/claude/versions/2.1.220` is the versioned CC binary,
# so OOM victims named `2.1.220` / `2.1.177` / `2.1.168` are CC sessions, as are
# the ones named `claude`. Largest single anon-rss recorded: 18.4 GB (2.1.177,
# Aug 14), with 15.8 GB seen twice. Everything else killed — althing-forseti,
# caddy, ttyd, zellij, the althing daemons — is 30-55 MB collateral.
#
# steps 2-4 add the timeseries that the journal cannot give: the journal records
# the moment of the kill, not the ramp toward it, and the Aug 28 event was a hard
# lockup where the box never got far enough to log a coherent sweep.
# - sysstat -> system-wide memory/CPU timeseries (the ramp)
# - atop -> PER-PROCESS timeseries (which session, and how fast)
# atop is the one that answers "which of the dozen sessions", which sar cannot.
#
# Run: scripts/elway infra-ops@nh3-dev --playbook playbooks/nh3-dev-memory-forensics.yaml
# Rerunnable: a second run shows every step `skipped` or `ok`.
vars:
# The interactive/agent user whose sessions read the journal.
journal_user: lkraven
# Debian's journald ACL grants read to `adm` explicitly (getfacl shows
# group:adm:r-x); `systemd-journal` owns the files. `adm` is the documented
# Debian path and the one the ACL names, so use it.
journal_group: adm
# 5 min, not Debian's default 10 — a CC session can add several GB inside one
# 10-minute bucket, which is exactly the resolution the ramp needs.
sar_interval: "*:00/05"
# 60s per-process sample. ~7 generations keeps this under ~1 GB against 80 GB free.
atop_interval: "60"
atop_generations: "7"
steps:
- name: Grant the agent user journal read access (THE actual fix for "no evidence")
shell: sudo usermod -aG {{ journal_group }} {{ journal_user }}
when: "! id -nG {{ journal_user }} | grep -qw {{ journal_group }}"
- name: Install sysstat and atop
shell: sudo DEBIAN_FRONTEND=noninteractive apt-get install -y sysstat atop
when: "! dpkg -s sysstat >/dev/null 2>&1 || ! dpkg -s atop >/dev/null 2>&1"
- name: Enable sysstat collection in /etc/default/sysstat
# The package ships ENABLED="false" and the timer is a no-op until this flips.
shell: sudo sed -i 's/^ENABLED=.*/ENABLED="true"/' /etc/default/sysstat
when: "! grep -qxF 'ENABLED=\"true\"' /etc/default/sysstat 2>/dev/null"
- name: Tighten the sysstat collection interval to 5 minutes
shell: |
sudo mkdir -p /etc/systemd/system/sysstat-collect.timer.d
printf '[Timer]\n# Default is */10. A CC session can add several GB inside one 10-minute\n# bucket; 5 min is the resolution the memory ramp actually needs.\nOnCalendar=\nOnCalendar=%s\n' '{{ sar_interval }}' | sudo tee /etc/systemd/system/sysstat-collect.timer.d/override.conf >/dev/null
when: "! grep -qxF 'OnCalendar={{ sar_interval }}' /etc/systemd/system/sysstat-collect.timer.d/override.conf 2>/dev/null"
- name: Configure atop for 60s per-process sampling with 7-day retention
shell: |
sudo sed -i 's/^LOGINTERVAL=.*/LOGINTERVAL={{ atop_interval }}/' /etc/default/atop
sudo sed -i 's/^LOGGENERATIONS=.*/LOGGENERATIONS={{ atop_generations }}/' /etc/default/atop
when: "! grep -qxF 'LOGINTERVAL={{ atop_interval }}' /etc/default/atop 2>/dev/null || ! grep -qxF 'LOGGENERATIONS={{ atop_generations }}' /etc/default/atop 2>/dev/null"
- name: Reload systemd and enable the collectors
shell: |
sudo systemctl daemon-reload
sudo systemctl enable --now sysstat.service sysstat-collect.timer sysstat-summary.timer
sudo systemctl enable --now atopacct.service atop.service atop-rotate.timer
sudo systemctl restart atop.service
- name: Seed one sysstat sample so sar has data immediately
shell: sudo /usr/lib/sysstat/sa1 1 1
verify:
- name: Agent user is now in the journal-reading group
# `sg` evaluates the membership WITHOUT waiting for a re-login, so this
# asserts the effective grant rather than the /etc/group substring.
shell: sudo -u {{ journal_user }} sg {{ journal_group }} -c 'journalctl -b -1 -k --no-pager 2>/dev/null | wc -l' | awk '{ if ($1 > 100) exit 0; else exit 1 }'
changed_when: "false"
- name: sysstat collection timer is active
shell: systemctl is-active --quiet sysstat-collect.timer
changed_when: "false"
- name: sysstat is collecting at the 5-minute cadence
# ⚠ Assert the EFFECTIVE value, not the string we wrote. systemd normalises
# `*:00/05` to `*-*-* *:00/5:00`, so grepping for our own input fails while
# the setting is live — which is exactly how this verify failed on the first
# run and briefly looked like the override had not applied.
shell: systemctl show sysstat-collect.timer -p TimersCalendar | grep -qF '*:00/5:00'
changed_when: "false"
- name: sar can actually read a memory timeseries (not just that the timer exists)
shell: sar -r 2>/dev/null | tail -2 | grep -qE '[0-9]'
changed_when: "false"
- name: atop daemon is running
shell: systemctl is-active --quiet atop.service
changed_when: "false"
- name: atop is writing a readable per-process log
shell: sudo test -s /var/log/atop/atop_$(date +%Y%m%d)
changed_when: "false"