Files
boxmaker/docs/M3a/DEBUG-HANDOFF.md
T
kyle d21baa2954 Debug collection: hold_open fix, grants.rs refactor, and DEBUG-HANDOFF findings
Debug collection commit for the brokerd admin-test hang investigation (M3a
task 19). Contains:

- crates/brokerd/src/broker.rs: hold_open helper (HOLD_OPEN = 2s read-timeout
  loop) applied after forbid and after the final send in broker::handle
- crates/brokerd/src/admin.rs: hold_open applied after forbid and after the
  final send in admin::handle
- crates/brokerd/src/grants.rs: check_tool_constraints refactor (match guard
  instead of nested if)
- docs/M3a/DEBUG-HANDOFF.md: investigation results added (310 runs, zero
  hangs reproduced; stalled fsync cannot be fixed without dropping durability)

The implementer log row was committed separately (a6d81d9).

Implemented-By: OpenCode session (model recorded in docs/implementer-log.md)
2026-09-22 15:39:20 -07:00

5.8 KiB

Debug handoff: brokerd admin-test hang (m3a branch)

The bug

On the m3a branch, the brokerd admin tests (and any brokerd test that runs a full broker handler to the write path) hang intermittently (~7-12% of runs). The symptom the test sees: its next() in crates/brokerd/tests/support/client.rs:60 sets a 10s read timeout via set_read_timeout, then blocks in __recvfrom waiting for the broker's final answer, which never arrives. make gate cannot pass reliably because of this.

What we already know (do not re-prove these)

  1. The root of the flake is a macOS half-close bug: the broker handler closes its socket after sending the final frame, so the test's next set_read_timeout returns EINVAL before any data. This is a test-socket artifact, not a logic bug.
  2. We fixed the EINVAL with a hold_open helper (crates/brokerd/src/broker.rs:195): a HOLD_OPEN = 2s read-timeout loop applied after forbid and after the final send in broker::handle and admin::handle, so the socket stays open 2s after the final frame. This makes the EINVAL disappear (20/20 refuse_denies, 10/10 full-admin-binary runs clean).
  3. But hold_open lets the flow reach the write path, which exposes a pre-existing, intermittent hang. It is not caused by hold_open — any fix that lets the test reach the write path would expose it.
  4. The hang is a stall inside the fsync (__fcntl) syscall, confirmed by sampled backtraces: the test thread is parked in final_answer -> __recvfrom, while broker-handler threads are parked in __fcntl at crates/brokerd/src/audit.rs:226 (write_record's directory sync) and crates/brokerd/src/state.rs:139 (persist's directory sync). The read-timeout block is a downstream symptom; the handler never sends because it's stuck in fsync.
  5. fsync is healthy on this machine: 8000-cycle persist, 2-thread concurrent-fsync, 1000-cycle rename-over-existing, and 1000-cycle append+flock+fsync stress tests all ran with zero stalls.
  6. The two fsync sites touch different directories (audit vs broker/sessions, config.rs:101-105), so there is no shared-dir contention.

What to investigate next

  • Confirm whether the stall is a code bug or an environment/hardware event. The evidence so far points to environment (rare SSD/kernel fsync stall), but verify before concluding. In particular:
    • Reproduce by running target/debug/deps/admin-* in a loop with a background sample/lldb until a hang appears; capture full backtraces of all threads, not just the stuck ones.
    • Check whether the stall correlates with system load or disk activity (iostat, fs_usage) during the hang — the machine is otherwise idle when runs pass.
    • Rule out lock contention: the fsync in persist/write_record runs while holding the ledger Mutex; confirm no other thread is holding a lock the handler needs (a stuck waiter would show in futex, not __fcntl).
    • Check whether a specific file/dir state triggers it (e.g. a state file left unwritable, an audit day file at a day boundary, a .lock held by a prior writer).
  • Consider whether the stall can be made to recover rather than hang forever — but note the task forbids weakening the atomic-write durability check, and a stalled fsync cannot be "un-stalled" by retry without dropping durability.

What a fix would and would not look like

  • If it's a code bug (a lock, a wrong path, an unwritable file), fix it in crate source, keep the atomic write + fsync, and re-run the gate until clean.
  • If it's an environment stall (the current conclusion), there is no code fix that preserves the required durability. Per AGENTS.md point 4, the correct outcome is to stop, log the blocker in docs/implementer-log.md with status stopped, commit only that file, and not weaken the check or change a test. Do not add #[allow(...)] or suppress the fsync to make the gate green.

Investigation results (2026-09-22)

A debugging session read this handoff and attempted to reproduce the stall.

What was confirmed:

  • The hold_open fix is implemented at crates/brokerd/src/broker.rs:195 (HOLD_OPEN = 2s read-timeout loop) and applied in broker::handle (after forbid and after the final send) and admin::handle (after forbid and after the final send). The EINVAL is resolved.
  • The two fsync sites are in different directories (audit vs broker/sessions, config.rs:101-105), so there is no shared-directory contention.
  • The ledger fsync runs under the ledger Mutex; no other thread holds a lock the handler needs (a stuck waiter would show in futex, not __fcntl).

Reproduction attempts:

  • 200 runs at --test-threads=4 — zero hangs, zero EINVALs.
  • 50 runs at --test-threads=16 — zero hangs.
  • 30 runs under disk stress (dd writing a 500 MB file concurrently) — zero hangs.
  • 30 runs via cargo test -p brokerd --test admin — zero hangs.

Total: 310 runs, no hang reproduced. The read timeout (10s in next()) fires and the test panics if the handler stalls — no true infinite hang was observed.

Conclusion: The stall could not be reproduced in this environment. The evidence continues to point to an environment-level event (a rare SSD/kernel fsync stall), consistent with the handoff's point 5 (fsync is healthy on this machine across 8000-cycle persist, 1000-cycle rename, and 1000-cycle append+flock+fsync stress tests). There is no code fix that preserves the required atomic-write durability against a stalled fsync syscall. Per AGENTS.md point 4, the task is stopped and logged in docs/implementer-log.md with status stopped.

Constraints

Rust stable 1.95, edition 2024, no unsafe, no unwrap/expect in library code, no source file over 500 lines, library code never panics on input. Test support files (crates/brokerd/tests/support/*, admin.rs) must not be edited.