supervisor: bounded per-module stderr tail, so a crash cause outlives the log

[iceteaSA]

Implements #7, to your spec on that thread. Stderr is piped per child into a bounded in-memory ring the supervisor owns, and every line is forwarded on so the daemon log keeps its current content.

$ ck module stderr claustrum
... 143 earlier line(s) dropped
config error: missing top-level `storage`
--- process start ---
config error: missing top-level `storage`

What's here

The ring (crates/subc-core/src/stderr_tail.rs, new). Three bounds, not two: total lines, total bytes, and per-line truncation — without the third, one enormous line evicts the whole tail while being unreadable itself. Truncation is carried as a truncated boolean so a consumer can branch without string-matching. dropped_lines is reported because a tail that silently starts mid-history reads as a module that never explained itself.

Capture state is typed, per your second design point. Captured and NotCaptured { reason } are distinct, so "the module printed nothing" and "nobody was listening" don't render alike. That's the detail - shape from #3, and reproducing it inside the fix for it would have been a poor outcome.

Restart boundaries are in-band. TailEntry::ProcessStart sits between the lines it separates, because which side of a restart a line falls on is unanswerable from a count. The ring outlives the process — a ring recreated per spawn would be empty exactly when asked. The first boundary is suppressed: one with nothing before it divides nothing, and emitting it would make a silent module render as a lone marker.

The tap forwards (supervise.rs). Your 4727-of-5000 measurement is why this isn't optional — a tap that captured without forwarding would leave the daemon log nearly empty and every existing reader would report clean on nothing. An absence that reads as calm is worse than the interleaving it replaces.

Line atomicity became this daemon's problem, so it's handled here rather than left to emitters. Previously a module's own write reached the fd in one syscall; reading a pipe and re-emitting can split a line that was atomic. The reader reassembles and writes each complete line in a single call, and the test asserts one write per line rather than merely correct bytes. A pending-line ceiling bounds reassembly, because a module writing without newlines must not grow the daemon's memory — a module fault becoming a daemon fault is what supervision exists to prevent.

Stdout stays inherited. Modules use it for ordinary output rather than diagnostics, so piping it would double the reader tasks for no diagnostic gain.

supervisor.stderr_tail is a separate op rather than a field on supervisor.list — per your first design point, the tail is kilobytes per module and list renders every module. Caps ride on the request.

Review

I wrote the first version and it was not good enough to ship. An independent reviewer returned REVISE with four blocking findings, all real:

• max_lines counted restart boundaries as lines, so -n 20 on a crash-looping module could return a screen of markers and zero output — the exact failure this feature exists to fix, reintroduced inside the fix. All eleven of my tests passed around it; it took a probe to surface.
• The op was implemented but never added to SUBC_CONTROL_OPS, so server.describe clients couldn't discover it.
• Truncation was encoded three times: a marker inside the text, the boolean, and a suffix appended by ck.
• cargo fmt had never been run.

Worth flagging one of those specifically, since it's about the fixture rather than the code: my golden fixture hid the truncation bug. I built it by constructing the wire type directly, so it never passed through truncate_line — it encoded what I intended rather than what the code produced, and stayed green while the code was wrong. The added test goes through the real ring→wire path via the control handler. The fixture itself is unchanged across all three commits, which is what makes the fix demonstrably at the source rather than papered over by regenerating it.

A follow-up round closed a config-coherence edge: max_line_bytes > max_bytes let a boundary be evicted before the oversized line it attributed. Fixed by making that config unconstructible — fields are private behind StderrTailConfig::new, which clamps — rather than teaching eviction to tolerate a configuration nobody can sensibly want.

Verification

cargo test --workspace     31 test binaries, 0 failures
cargo clippy --workspace --all-targets     no warnings
cargo fmt --check     clean

Note for anyone running these on a box where the harness is itself a supervised module: 1b5d8f2's trap is live and cost me an hour. env -u SUBC_MODULE_ID -u SUBC_LAUNCH_NONCE is required or five real_daemon tests fail with bad_consumer_identity against unmodified upstream. Your note in that file is accurate; I read the reds as mine before checking the baseline.

Two things for you

Absent vs empty, resolved opposite ways in two PRs. Here the states are genuinely different and stay distinct. In #8 I collapsed absent to 0 for restart_count because both cases mean no restarts to report. I think that's right in each case rather than inconsistent, but they're adjacent enough that you may want them to match.

An unrelated flake, seen once during this work and not reproduced on retry or a full rerun: a forwarding test got Goodbye where it expected Response. Not touched by this change and I can't reproduce it, so it's a report rather than a claim — but a flake in route teardown ordering seemed worth naming rather than dropping.

---

^{Need help on this PR? Tag @codesmith with what you need. Autofix is disabled.}

---

Summary by cubic

Adds bounded per-module stderr capture with restart markers and per-line truncation, exposed via supervisor.stderr_tail and ck module stderr, so crash causes persist beyond log rotation while still forwarding lines to the daemon log. This preserves line atomicity on forward and keeps stdout inherited.

• New Features

  • Per-module stderr ring in subc-core with caps: max lines, max bytes, and per-line byte limit; reports dropped_lines and in-band ProcessStart markers.
  • Typed capture state: Captured vs NotCaptured { reason }.
  • New control op supervisor.stderr_tail in subc-control with request caps (max_lines, max_bytes) and wire types (StderrTail, StderrTailEntry).
  • CLI: ck module stderr <id> [-n <count>] prints tail, shows dropped count and restart markers; supports --json.
  • Stderr pump reads child pipe, reassembles full lines, forwards each line in a single write to the daemon’s stderr; ring survives restarts; pending-line ceiling prevents unbounded memory; stdout stays inherited.

• Bug Fixes

  • max_lines counts only stderr lines (not restart markers).
  • Advertised supervisor.stderr_tail in server.describe and golden tests.
  • Single source of truncation truth (boolean on entries; no duplicated markers).
  • Clamp incoherent configs (max_line_bytes > max_bytes) at construction to keep boundaries consistent.

^{Written for commit cef61ff. Summary will update on new commits.}

[cubic-dev-ai]

1 issue found across 14 files

Prompt for AI agents (unresolved issues)

Check if these issues are valid — if so, understand the root cause of each and fix them. If appropriate, use sub-agents to investigate and fix each issue separately.


<file name="crates/subc-control/src/lib.rs">

<violation number="1" location="crates/subc-control/src/lib.rs:243">
P2: A stderr read failure after lines were retained is encoded as `not_captured`, causing `ck module stderr` to discard those valid preceding diagnostics rather than show them with an incomplete-capture warning. Represent partial capture separately, or change the CLI/state contract so existing entries remain visible.</violation>
</file>

<sub>You're on the cubic free plan with 16 free PR reviews remaining this month. Upgrade for unlimited reviews.

Re-trigger cubic</sub>

[cubic-dev-ai]

P2: A stderr read failure after lines were retained is encoded as not_captured, causing ck module stderr to discard those valid preceding diagnostics rather than show them with an incomplete-capture warning. Represent partial capture separately, or change the CLI/state contract so existing entries remain visible.

Prompt for AI agents

Check if this issue is valid — if so, understand the root cause and fix it. At crates/subc-control/src/lib.rs, line 243:

<comment>A stderr read failure after lines were retained is encoded as `not_captured`, causing `ck module stderr` to discard those valid preceding diagnostics rather than show them with an incomplete-capture warning. Represent partial capture separately, or change the CLI/state contract so existing entries remain visible.</comment>

<file context>
@@ -186,6 +202,68 @@ pub enum ClientControlResponse {
+    /// `entries` under this state means the module genuinely wrote nothing.
+    Captured,
+    /// No reader was attached. `entries` says nothing about what the module wrote.
+    NotCaptured { reason: String },
+}
+
</file context>

[iceteaSA]

Pushed 9886d1e. All five cubic findings were real; three were mine, and one of them was the issue's own defect reproduced inside its fix.

The restart boundary could be crossed by the output it separates. push_process_start() ran synchronously in spawn_child while the previous child's pump was still draining its pipe — same ring, same lock — so the old process's trailing lines could land after the marker attributing them to the new one. Worse than having no boundary, because it reads as authoritative. Now the previous pump is retained and drained to EOF before the boundary is recorded, bounded at 250ms so a wedged child holding its write end open can't stall a restart. On timeout the pump is aborted and the tail is marked incomplete rather than silently accepting misattributed lines.

A read failure discarded the lines already captured. mark_not_captured on a mid-stream read error, and ck returned early printing only the reason — so a module that logged its crash cause and then hit a read error showed the operator nothing. My own comment at that site said "the tail up to this point stays valid and readable"; the code disagreed with it.

The fix isn't a patch, it's a missing state. There are three situations and only two were expressible: complete, valid-but-ended-early, and never-attached. Collapsing the middle into "not captured" is the same absent-vs-empty collapse this issue was filed about, one layer in. Added Incomplete, rendered as the retained lines plus a warning.

A forced flush invented a newline. emit_line appended \n unconditionally, so a pending-ceiling flush or an unterminated final fragment gained a byte the module never wrote — into a log other tools parse. Delimiter presence is now preserved, still one write per emission.

Two flaky tests, both mine. Each waited on one condition and asserted on another: one read the tail once immediately after status flipped to Failed (the pump isn't ordered against the reap), the other waited on ProcessStart count while asserting on boot-line count (markers are pushed synchronously at spawn, lines arrive async). Both would have been green against a broken implementation and red at random against a correct one. --test supervision now runs 5/5 clean.

Both original golden fixtures remain byte-identical across all four rounds; the only new one is for the added state.

Separately: a pre-existing flake, not from this branch

While verifying I hit an intermittent failure and checked it against a clean worktree of 927a5b1 before assuming it was mine:

supervisor_reload_drains_inflight_then_respawns_and_serves
forwarding.rs:4861  assertion `left == right` failed
  left: Goodbye
 right: Response

branch    13/20 isolated
master    10/20 isolated

Comparable rates, so this branch didn't cause it — though with n=20 I can't rule out a small contribution, and I'd rather say that than claim exoneration the sample doesn't support. Worth flagging on its own terms: it fails about half the time on master, and a reload-drain test getting a GOODBYE where it expects a response looks like it could be describing a real race rather than just a bad test. Logs are on my side if useful. Filing separately rather than bundling it here.

[iceteaSA]

@ualtinok — one small thing from ff90dab, relevant here because this PR is what added the fixtures involved.

The coverage reporter you added is the right instinct, and it has the blind spot it exists to close.

golden-conformance.test.ts:100-107 scans GOLDEN_DIR and logs golden fixtures with no TypeScript consumer. GOLDEN_DIR is crates/subc-protocol/tests/golden (:25-34) — 20 fixtures. There are 30 more in crates/subc-control/tests/golden that the scan structurally cannot see, including the three this PR adds.

The scoping is correct as a design choice: the TS client models no control ops at all, so it owes those no mirror. The issue is that the reporter doesn't say which universe it enumerated. Its output reads as "here is what is unconsumed", not "here is what is unconsumed among protocol fixtures", and a clean list is exactly what a reader treats as the complete answer.

Concrete instance from tonight, which is why I noticed: I added three control fixtures and had to answer "do I owe a TypeScript mirror?" by reading the test file to find out what GOLDEN_DIR pointed at. Had the reporter been present and silent about subc-control, its clean output was the obvious thing to trust instead — and it would have been right by accident, for a reason I hadn't verified.

One line in the log naming the scope closes it:

`golden fixtures under subc-protocol with no TypeScript consumer: ${unconsumed.join(", ")}`

Or, if you'd rather the scope be asserted than described, count both directories and report subc-control as deliberately-unmirrored — that makes the choice visible rather than implicit, so the day a control shape does need a mirror, the reporter is the thing that notices.

Small, and adjacent enough to fold into whatever you do here rather than tracking separately. Filing as a comment rather than an issue for that reason — happy to move it if you'd prefer it standalone.

[iceteaSA]

@ualtinok — two things from a real OOM on this box today, one confirming a premise of this PR and one naming a limit of it I should have stated when I opened it.

Your measurement replicates on a different daemon

The forwarding-is-mandatory argument rests on your 4727-of-5000 count. I measured the pre-crash boot here:

ck-subc journal lines, boot -1:  15,440
carrying a module tag:           13,846   (89.7%)
distinct modules tagged:         [aft]    (all of them)

Same conclusion, independent instance: the daemon log is a module log with some daemon lines in it. A tap that captured without forwarding would empty it.

Worth flagging how nearly I posted the opposite. My first count used a pattern matching a literal [module] and returned 0 of 15,440 — I had the shape of the tag wrong, not the daemon. The real format is 2026-08-10T12:56:05Z [aft] …. Had I reported that number it would have read as a clean refutation of your measurement, and it was purely my probe reading the wrong thing.

The limit this PR has, stated plainly

ck-subc was OOM-killed at 14:42. Three modules died with it in one cgroup kill. In the 14:42:00→14:42:10 window the journal contains no module exit lines and no drain/GOODBYE entries — the supervisor was killed too fast to observe its own children dying.

The ring in this PR lives in the supervisor's memory. So:

• Module crashes — what the issue was filed about — are covered. The module dies, the supervisor survives, the tail holds the cause.
• Supervisor death takes the tail with it. A cgroup-wide kill destroys the evidence and the thing holding it, simultaneously. The successor starts with empty rings for all three modules.

That's not a defect in this change, and I don't think it argues for on-disk retention — that's a different design with different costs, and you've been clear core is state-free. But the issue text implies "a crash cause is now recoverable" without qualification, and the honest version is "a module crash cause is recoverable as long as the supervisor outlives the module." I'd rather that limit be in the thread than discovered by whoever first goes looking for a tail after an OOM.

This incident wasn't a test of the code, incidentally — #10 is unmerged and the running binary predates the branch. It's the counterfactual: had it been live, we'd know empirically whether anything survives a cgroup SIGKILL instead of reasoning about it.

[ualtinok]

Reviewed in full — the ring, the pump, the supervise tap, the wire types, and the golden fixtures — and ran the suite three ways. This is a strong piece of work: the three-bound ring with typed capture state, in-band restart boundaries, the one-write-per-line atomicity argument (with the 212-of-3000 measurement), the pending-line ceiling, and making the incoherent config unconstructible are all exactly right. Your own review round finding the golden fixture encoding intent rather than output is the kind of process note that makes a review trustworthy.

One blocking finding: the five new /bin/sh spawn tests fail on Windows deterministically.

Fork PRs only get Socket/cubic here (the Rust matrix never runs), so I pushed your head to an internal twin (#18) to get the full matrix. Result: ubuntu green, windows red — supervisor_stderr_tail_converts_a_real_truncated_ring_entry_to_prefix_only_wire_data panics at the spawn(...).unwrap() because PathBuf::from("/bin/sh") has nothing to resolve to on Windows.

Four more instances are hiding behind that one: supervision.rs lines 542/600/641/695 spawn /bin/sh the same way, and cargo's default fail-fast stops after the first failing binary, so the windows job never reached them. One visible failure, five real ones.

The repo's existing pattern for this is the fake-aft-stub spawned via env!("CARGO_BIN_EXE_fake-aft-stub") (see supervision.rs:541 on master) — portable by construction. For these tests the stub would need two small env-driven behaviours: emit N lines (or a given payload) to stderr, and exit with a given code. That keeps the tests running on every CI platform rather than #[cfg(unix)]-gating them out of the windows matrix — a gate would leave the stderr tail entirely unverified on the platform whose CRT stdio behaviour differs most.

Local verification on your head (macOS, clean env): stderr_tail unit tests 25/25, subc-control green including goldens, clippy clean, fmt clean. The real_daemon failures you'd see on my box are environmental (they fail on master too under current host load — your note about env -u is accurate and appreciated).

On your two flagged items: the absent-vs-zero split (distinct here, collapsed in #8) is right in both places for the reason you give — here the states carry different information, there they don't. And the forwarding-test flake you saw once is filed as #11 by you already; we've seen the same family on our side and it's on the list.

Everything else is merge-ready. Fix the five spawns (stub extension preferred over cfg-gating) and this lands.

[iceteaSA]

@ualtinok — Windows finding fixed in 955c04a. Stub extension, not #[cfg(unix)], for the reason you gave.

Thank you for pushing my head to ci/pr10-stderr-tail to get the real matrix. I had no way to see that failure: fork PRs only get Socket and cubic, so from my side this looked fully green. Worth noting that as a structural gap in outside contribution rather than a one-off — a fork contributor cannot know their change is red on a platform the fork's CI never runs, and the fail-fast masking made it one visible failure hiding five.

What changed

Five sites, all test-only — no production file touched:

• supervision.rs × 4 — crasher, silent, looper, wedged-pump
• control.rs × 1 — the ring→wire conversion unit test

Three new stub knobs, following the existing *_ENV const convention:

• FAKE_AFT_EXIT_CODE — write a stderr line, exit with the given code
• FAKE_AFT_STDERR_LINE — the text, with a {pid} substitution token for the restart-boundary test that previously used $$
• FAKE_AFT_ORPHAN_WRITER_DELAY_MS / _LINE — the wedged-pump case

Two things worth your attention in the diff

The orphan writer needed a mechanic with no precedent in the stub. Site 4 exists to prove the pump-drain timeout: a writer must still hold the stderr write end open after the supervised process exits, or the test stops testing what it was written for. No existing knob spawns a detached child. The implementation re-execs the stub via current_exe() with a marker env var and drops the Child without waiting — dropping without wait is documented not to kill the child, so the duplicate write end survives the parent. That's a new pattern in that file and I'd rather flag it than have you find it.

The registration path did pollute the ring, exactly as the risk predicted. Before the fix, the control.rs test failed with Error: MissingSubcArg appearing in the very stderr tail under assertion — the stub's normal startup writing into the thing being measured. Fixed by moving the exit-code check ahead of argument parsing in main(), so the short-circuit never reaches the connect/HELLO path. That one was caught by verifying rather than assuming, and it would have been a genuinely confusing failure to debug later.

control.rs couldn't use CARGO_BIN_EXE_fake-aft-stub. It's a unit test compiled into the library target, not a tests/*.rs binary, so that env var doesn't exist at compile time or runtime. It derives the sibling path from current_exe() instead. If you'd rather that test move to an integration file than carry a path-derivation helper, say so and I'll move it.

Verification

Merged onto current master (bd76772) in a scratch worktree, not just checked for a clean merge:

cargo test --workspace     31 test binaries, 0 failures
cargo fmt --check          clean
cargo clippy --all-targets clean
grep -rn "/bin/sh"         no matches

The four stderr-tail supervision tests pass 10/10 in a tight loop, including the timing-sensitive wedged-pump case.

The three golden fixtures are byte-identical: git diff 9ab5a82 HEAD -- client_control_response_supervisor_stderr_tail.json is empty. That invariant has now held across five rounds, which is what makes it an acceptance instrument rather than a formality.

I can't verify Windows myself — no runner. Pushing to ci/pr10-stderr-tail again would settle it, and I'd rather you confirm than take my reasoning about current_exe() and .exe suffixes on trust.

Separately: ran your #11 fix on this host — 20/20 where the pre-fix rate was 10/20. Posted there; it's ready to close.