boxmaker/docs/M3a/DEBUG-HANDOFF.md

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

## Resolution (2026-09-22, design model)

Resolved. The conclusions below are wrong and are kept only as the record of the investigation.
There is no fsync stall. The failure is a macOS rule about socket options, and it was in loopd's
production code as well as in the test client.

- **The cause.** macOS refuses every socket option with `EINVAL` once the peer has closed (XNU
  `sosetoptlock`, `bsd/kern/uipc_socket.c`: both `SS_CANTRCVMORE` and `SS_CANTSENDMORE` set),
  even while unread data is still buffered and readable. Linux never refuses. Anything that sets a
  read timeout before each read therefore fails on macOS as soon as the peer has sent its last
  bytes and closed. Measured directly: after a peer writes and closes, `setsockopt(SO_RCVTIMEO)`
  returns `EINVAL` on the Mac and succeeds on Talos, and the following read returns the data on
  both.
- **It was never intermittent.** At `2408e2c` the admin test failed 40 runs of 40 on the Mac,
  every one at `client.rs:60` with `os error 22`, and passed 40 of 40 on Talos. The work before
  this handoff ran on Talos (Linux); the handoff and `hold_open` were done on the Mac.
- **It was also a production bug.** loopd set a read timeout before every read in `BrokerPort`
  (`Deadline::read`) and in the HTTP client used for llama-server. On the Mac, twelve loopd test
  binaries failed with `os error 22`; `make gate` never reached them because `cargo test` stops at
  the first failing binary, which was brokerd's `admin`.
- **The "fsync stall" was a misread profile.** On macOS `File::sync_all` is
  `fcntl(F_FULLFSYNC)`, so every sync shows as `__fcntl`. It costs about 4 ms here (p50 4.1 ms,
  max 8.5 ms over 600 calls), and the admin binary does hundreds, so each run takes 2 to 9 s on
  the Mac against under 1 s on Talos, where the test directories are on tmpfs. A sample catches
  threads there because that is where the time goes, not because they are stuck. With `hold_open`
  in place, 170 admin runs on the Mac and 50 on Talos, and 10 to 20 runs of every brokerd test
  binary on each host, had no hang and no failure.
- **The fix.** `loopd::socket::set_read_timeout` takes that one refusal as success on Apple
  targets (a socket shut in both directions cannot block on a read), and both loopd call sites use
  it (`00a85c1`). The brokerd test client does the same (`d7009dc`, and in
  `docs/plans/M3a/files/`). `hold_open` is removed (`57dc789`); it only hid the test client's
  problem, and it kept every handler thread for up to 2 s after its final frame.

## 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.