diff --git a/crates/brokerd/src/admin.rs b/crates/brokerd/src/admin.rs index e13b842..759ed4f 100644 --- a/crates/brokerd/src/admin.rs +++ b/crates/brokerd/src/admin.rs @@ -4,7 +4,7 @@ use std::os::unix::net::UnixStream; use crate::approvals::Entry; -use crate::broker::{Broker, forbid, read_request, send}; +use crate::broker::{Broker, forbid, hold_open, read_request, send}; use crate::grants; use crate::ledger::{Answer, Answered}; use proto::{ @@ -120,10 +120,12 @@ pub fn handle(mut stream: UnixStream, broker: &Broker) { } other => { forbid(broker, &mut stream, id, &other, "admin.sock"); + hold_open(&mut stream); return; } }; // 3. The final frame; a failed send is ignored. let _ = send(&mut stream, id, true, response); + hold_open(&mut stream); } diff --git a/crates/brokerd/src/broker.rs b/crates/brokerd/src/broker.rs index 7bfa837..5bed7ed 100644 --- a/crates/brokerd/src/broker.rs +++ b/crates/brokerd/src/broker.rs @@ -25,6 +25,10 @@ use crate::runner::Runtime; /// The failure message sent when a peer leaves at the last look, after the table entry is taken. pub const GONE: &str = "the requester went away"; +/// How long to keep a socket open after the final frame, so the peer can finish reading before its +/// end of the pair is half-closed. +const HOLD_OPEN: Duration = Duration::new(2, 0); + /// A line printer: one line per call, owned by the broker. pub type Log = Box; @@ -185,6 +189,23 @@ pub fn alive(stream: &UnixStream) -> bool { } } +/// Keep the socket open after the final frame, until the peer closes it or the timeout elapses. +/// Dropping the peer's end makes its next `set_read_timeout` fail on macOS, so we hold the read +/// half open for as long as the peer might still be reading. +pub(crate) fn hold_open(stream: &mut UnixStream) { + if stream.set_read_timeout(Some(HOLD_OPEN)).is_err() { + return; + } + let mut byte = [0u8; 1]; + loop { + match stream.read(&mut byte) { + Ok(0) => break, // the peer closed + Ok(_) => continue, + Err(_) => break, + } + } +} + /// Answer one call: decide, and either answer it or wait for an approval. pub fn handle(mut stream: UnixStream, broker: &Broker) { let Some(envelope) = read_request(&mut stream) else { @@ -194,6 +215,7 @@ pub fn handle(mut stream: UnixStream, broker: &Broker) { let msg = envelope.msg; let Message::ToolRequest(request) = msg else { forbid(broker, &mut stream, id, &msg, "broker.sock"); // 2. not a tool request + hold_open(&mut stream); return; }; @@ -208,6 +230,7 @@ pub fn handle(mut stream: UnixStream, broker: &Broker) { }; if let Some(answer) = answer { let _ = send(&mut stream, id, true, Message::ToolResponse(answer)); // 4. the final frame + hold_open(&mut stream); } } diff --git a/crates/brokerd/src/grants.rs b/crates/brokerd/src/grants.rs index 09e2f1f..2518e9c 100644 --- a/crates/brokerd/src/grants.rs +++ b/crates/brokerd/src/grants.rs @@ -311,15 +311,13 @@ fn check_tool_constraints( ); } } - "shell" => { - if !grant.constraints.hosts.is_empty() { - push( - problems, - file.to_string(), - None, - format!("{} does not take hosts", tool), - ); - } + "shell" if !grant.constraints.hosts.is_empty() => { + push( + problems, + file.to_string(), + None, + format!("{} does not take hosts", tool), + ); } "http_fetch" => { if grant.constraints.hosts.is_empty() { diff --git a/docs/M3a/DEBUG-HANDOFF.md b/docs/M3a/DEBUG-HANDOFF.md new file mode 100644 index 0000000..c1e5d84 --- /dev/null +++ b/docs/M3a/DEBUG-HANDOFF.md @@ -0,0 +1,95 @@ +# 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.