diff --git a/persistent-memory.d/2026-08-28-nh3-dev-oom-attribution.md b/persistent-memory.d/2026-08-28-nh3-dev-oom-attribution.md new file mode 100644 index 0000000..8e26c5b --- /dev/null +++ b/persistent-memory.d/2026-08-28-nh3-dev-oom-attribution.md @@ -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/` → `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`. diff --git a/persistent-memory.md b/persistent-memory.md index 9b06489..10fc7d1 100644 --- a/persistent-memory.md +++ b/persistent-memory.md @@ -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` diff --git a/playbooks/nh3-dev-memory-forensics.yaml b/playbooks/nh3-dev-memory-forensics.yaml new file mode 100644 index 0000000..5c21ded --- /dev/null +++ b/playbooks/nh3-dev-memory-forensics.yaml @@ -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"