Files
kyleandClaude Opus 5.5 e08deb39a6 brokerd: recover a torn line in place, real dates only, bounded ttl, EMFILE
From the independent review of task 23. A torn last line followed by an empty
later file had its recovery written into the later file, which broke the
chain for good; the line is now ended in its own file. The log-name rule
takes months 01 to 12 and days 01 to 31 only. [approvals] ttl_ms is limited
to a day, the longest loopd waits after a pending frame. Running out of file
descriptors or memory pauses the listener instead of stopping brokerd (the
errors the previous fix skipped do not occur on Linux). args.rs's doc fixed.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
2026-09-22 21:48:24 -07:00

393 lines
18 KiB
Markdown

# Runbook
One entry for every state in which Boxmaker refuses to work or holds something back, and for
events worth understanding when you see them. Every message for such a state ends with
`see docs/runbook.md#<entry>`; a gate check makes sure the entry exists.
Each entry says what you see, why the system refuses, how to confirm, how to fix, and how to check
the fix. Commands assume:
- `$BOXMAKER_HOME` is the harness home: `/var/lib/boxmaker` when deployed, `.state` in the
repository during development.
- `$GRANTS` is `[paths] grants` from `brokerd.toml`: `/etc/boxmaker/grants` when deployed.
- Until M7 there are no service units: the daemons run in a terminal, and "stop" means Ctrl-C or
`pkill -x <name>`.
Entries for M3a states are written ahead of the code and describe it as specified in
`docs/specs/2026-09-18-m3a-decision-path.md`.
## grants-invalid
**What you see.** `brokerd` prints one or more lines naming a grant file and a problem, then this
entry. Every tool call is denied, and the model tells you "the grant files have an error".
**Why.** One grant file is invalid, so `brokerd` denies everything until it is fixed. It cannot
skip the bad file: if the bad file was a `deny` grant, skipping it would allow what it was written
to forbid.
**Confirm.**
```sh
bxctl grants check
```
It prints each problem as `<file>:<line>: <problem>`. Common ones: a misspelled field (unknown
fields are errors); `secret` set (not supported until M4); `patterns` set (not supported); `hosts`
on a file tool or `paths` on `http_fetch`; a relative path or one with `..`, `.` or `//`; the path
`/` (grant the directories you mean); a `deny` grant whose `max_taint` is not `"secret"` (it would
stop denying once the session read a secret); a host with uppercase letters, a port, or an IP
address; a file name with characters outside `[a-z0-9-]`.
**Fix.** Edit the file, or move it out of `$GRANTS` while you work on it:
```sh
mkdir -p ~/grants-parked && mv "$GRANTS/<file>.toml" ~/grants-parked/
```
Do not park a `deny` grant unless you are sure nothing else would then allow what it forbids.
**Check.** `bxctl grants check` prints `grants: ok`. No restart is needed: `brokerd` reads the
grants again at the next call.
## audit-unavailable
**What you see.** `brokerd` prints an error writing to `$BOXMAKER_HOME/audit/`, then this entry.
Tool calls are denied, and the model says "the audit log cannot be written". Every later call
prints `brokerd: an earlier audit write failed; every call is denied until brokerd is restarted`.
A call that ran but whose result could not be recorded reaches the model as "the result could not
be recorded", without its content; `bxctl refuse` says "the refusal could not be recorded".
A variant: `brokerd: a thread panicked while holding the ledger`. That is a bug in `brokerd`, not
a disk problem; the fix below is the same, and the panic message above it in `brokerd`'s output is
worth keeping for a report.
**Why.** A call runs only after its decision is on disk. If the record cannot be written, nothing
runs.
**Confirm.**
```sh
df -h "$BOXMAKER_HOME"
ls -ld "$BOXMAKER_HOME/audit"; ls -l "$BOXMAKER_HOME/audit" | tail -3
```
Look for a full disk, a directory or file not owned by the user `brokerd` runs as, or a read-only
file system.
**Fix.** Free space or correct ownership (`chown` to the `brokerd` user; files are mode 0600, the
directory 0700). Do not edit, move or delete audit files to make space: that breaks the chain.
Then stop and start `brokerd`. It does not try again by itself: a failed write may have left part
of a line, and only the startup check deals with that. Expect
[audit-recovered](#audit-recovered) at that start.
**Check.** Ask for any tool call. It is decided normally, and `bxctl audit verify` prints
`audit: ok`.
## audit-chain-broken
**What you see.** `brokerd` refuses to start and prints `<file>:<line>: <what>`, then this entry.
Or `bxctl audit verify` prints the same and exits 1. If the break is in an older file, only
`bxctl audit verify` reports it: at an ordinary start `brokerd` checks the latest file alone.
**Why.** A record does not parse, its `seq` is not the next number, its `prev` is not the hash of
the line before, or a file does not continue from the one before it. Something changed the log
after it was written: an edit, a deleted or reordered line, a file restored from a backup, a
partial copy. `brokerd` will not add records after a history it cannot vouch for.
There is one innocent cause. After a crash `brokerd` recovers a torn last line by itself
([audit-recovered](#audit-recovered)), but if it is killed a second time while writing that
recovery record, the log is left with a line that nothing describes. The failure is then within
the last three lines of the latest file, and the last line is cut short.
**Confirm.**
```sh
bxctl audit verify
sed -n '<line-1>,<line+1>p' "$BOXMAKER_HOME/audit/<file>"
```
Work out what happened before going on: a restore, a manual edit, a disk problem, or none you know
of. If none you know of, treat it as a possible intrusion and keep the files as they are.
**Fix.** Keep a copy first, then accept the break explicitly:
```sh
cp -a "$BOXMAKER_HOME/audit" ~/audit-copy-$(date +%F)
brokerd serve --config <path> --accept-break
```
With this flag `brokerd` checks the whole log, not only the latest file, and appends an
`accepted_break` record naming the file and line of the first failure. It continues from there.
Nothing is repaired or deleted. The break stays visible in every later verification. One accepted
break covers everything between the failure and the break record, including any further damage
there, so look at that whole stretch before accepting it.
**Check.** `bxctl audit verify` prints `audit: ok` and lists the accepted break with its file and
line. Damage that happens after the break record needs its own accepted break.
## audit-recovered
**What you see.** `brokerd` prints "audit: recovered a torn final line" at start, then this entry.
It starts normally.
**Why.** The last record was being written when `brokerd` or the machine stopped, so the file ended
without a newline. That is expected after a crash, not an error. `brokerd` kept the partial line,
ended it, and wrote a `recovery` record holding its length and hash, chained from the last complete
record. The partial line may even look like a whole record; it is not one, and the recovery record
takes its `seq`. It was never acted on: a record allows something only once it is on disk with its
newline. If the partial line was the `result` of a call, the call did run and its result was
never delivered; `bxctl audit verify` lists that call as unfinished.
**Confirm.** `bxctl audit verify` lists the recovery with its file and line.
**Fix.** None needed. If recoveries happen often, find out why `brokerd` is being killed.
**Check.** `bxctl audit verify` prints `audit: ok`.
## brokerd-already-running
**What you see.** `brokerd` exits at start with "brokerd is already running" and this entry.
**Why.** Only one `brokerd` may write the audit log. It holds a lock on
`$BOXMAKER_HOME/audit/.lock` for as long as it runs, and the lock is released when the process
ends, however it ends.
**Confirm.**
```sh
pgrep -a brokerd
```
**Fix.** Use the running one, or stop it (`pkill -x brokerd`) and start again. Deleting `.lock`
does not help and is not needed.
**Check.** `pgrep -a brokerd` shows one process.
## brokerd-start-failed
**What you see.** `brokerd` exits 1 at start, before it serves anything, with one line naming its
config file, a directory or a socket, then this entry. `loopd` then reports
[broker-unavailable](#broker-unavailable) for every tool call.
**Why.** `brokerd` could not read or parse its config, could not create or make private (0700) the
directory a socket lives in, or could not bind a socket or make it private (0600). It will not
serve on a socket whose permissions it could not set, because those permissions are what keep other
programs off it.
**Confirm.** The line says which:
- `<config path>: …` — the file is missing, unreadable, or not valid TOML for `brokerd.toml`
(unknown keys are errors). Check it against `docs/specs/2026-09-18-m3a-decision-path.md`,
section 2, "Configuration".
- `cannot prepare <dir>: …` — the directory cannot be made or `chmod`ed:
`ls -ld <dir> "$(dirname <dir>)"`. A path that runs through a file, or a directory owned by
another user, gives this.
- `cannot prepare <socket or dir>: a socket needs a directory of its own` or `…: is a symbolic
link or not a directory` — `brokerd` makes a socket's directory 0700, so it refuses `/` and a
directory reached through a link (the link's target would be changed instead). Give each socket
its own real directory, as the defaults under `$BOXMAKER_HOME/run/` are.
- `cannot listen on <socket>: …` — `path must be shorter than SUN_LEN` means the socket path is
longer than 107 bytes; `Address already in use` means something still listens there
(`ss -xlp | grep <socket>`).
**Fix.** Correct the config, or the ownership of the directory, or choose a shorter socket path in
`[sockets]` (and the same path in `loopd`'s `[broker] socket`). If another process holds the
socket, stop it; `brokerd` removes a stale socket file by itself.
**Check.** `brokerd serve --config <path>` prints `brokerd: serving tools on … and approvals on …`.
## brokerd-listener-lost
**What you see.** One of three lines, then this entry:
- `brokerd: cannot accept on accept-broker (or accept-admin) for now, retrying: <error>`. It keeps
running and tries every 200 ms; the line is printed once per episode.
- `brokerd: cannot start a thread for a connection, so it was closed`. It keeps running.
- `brokerd: stopped serving: <error>`, and it exits 1: any other failure of `accept`.
In both cases `loopd` reports
[broker-unavailable](#broker-unavailable) for the calls that were refused.
**Why.** The system refused `brokerd` something it needs to serve: a new connection (`accept`
failed) or a thread. The usual cause is a
limit: open files (`EMFILE`), processes or threads for the user, or memory. A connection that is
refused gets no decision, so nothing runs for it.
**Confirm.**
```sh
ulimit -n; ulimit -u
ls /proc/$(pgrep -x brokerd)/fd | wc -l # while it runs
ps -o nlwp= -p $(pgrep -x brokerd) # its thread count
```
Many threads usually means many connections waiting on approvals, or a client that opens
connections and never sends: look at `bxctl approvals` and at which process holds the sockets
(`ss -xp | grep broker`).
**Fix.** Answer or let expire the pending approvals, stop whatever is flooding the socket, or raise
the limit. Then start `brokerd` again if it exited.
**Check.** `brokerd` prints `serving tools on …`, and a tool call is decided again.
## broker-state-damaged
**What you see.** `brokerd` prints an error reading or writing
`$BOXMAKER_HOME/broker/sessions/<id>.json`, then this entry. Either every call for that session is
denied ("this session's broker state is damaged"), or one call failed with "the result could not
be recorded". Such a call has no `Result` record, so `bxctl audit verify` lists it under "running
or unfinished"; that is expected, not a second fault.
**Why.** The file holds the session's taint and untrusted flag. If `brokerd` cannot read it, it
does not know how sensitive the session's data is, so it denies. If it cannot write it after a
tool ran, it withholds the result: content that raised the taint must not reach the model unless
the raised taint is on disk.
**Confirm.**
```sh
ls -l "$BOXMAKER_HOME/broker/sessions/<id>.json"*
cat "$BOXMAKER_HOME/broker/sessions/<id>.json"
df -h "$BOXMAKER_HOME"
```
A good file is one line such as `{"taint":"private","untrusted":false}`.
**Fix.** For a write failure, fix space or ownership as in
[audit-unavailable](#audit-unavailable). For a damaged file, do not guess low: set it from the
session's results. The session's audit `result` records show the highest `taint_after`, and any
result from an untrusted grant means `"untrusted":true`. If unsure, write
`{"taint":"secret","untrusted":true}`, which is always safe. The session only loses access to
grants with a lower `max_taint`. A `.tmp` file beside it is a write that did not finish and can
be removed.
**Check.** The next call for the session is decided normally.
## socket-forbidden
**What you see.** `brokerd` prints that a message of some kind arrived on the wrong socket, then
this entry.
**Why.** `broker.sock` accepts only tool requests from `loopd`; `admin.sock` accepts only admin
requests from `bxctl`. Nothing in the harness sends a wrong kind, so this is a bug or a component
doing what it should not, such as something trying to approve through the tool socket.
**Confirm.** Note the time, kind and socket. Check what was running: `pgrep -a 'loopd|bxctl'`.
Look at the session logs active at that time.
**Fix.** If a harness version mismatch explains it (a new `bxctl` against an old `brokerd`),
rebuild and restart both. Otherwise keep the logs, stop `loopd`, and investigate before running it
again.
**Check.** No further messages of this kind.
## broker-unavailable
**What you see.** `loopd` prints that it cannot reach `broker.sock`, or that `brokerd` did not
answer in time, then this entry. Tool calls fail with "the tool broker is unavailable", the model
says so, and the conversation goes on. Or, once at startup, `loopd` prints "no tool broker is
configured" and this entry, and tool calls fail with those words.
**Why.** `brokerd` is not running, was restarted during a call, did not answer within `[broker]
timeout_ms`, or `loopd`'s `[broker] socket` points somewhere else or is not set. Pending approvals
are lost when `brokerd` restarts. `bxctl audit verify` lists them as pending or abandoned.
**Confirm.**
```sh
pgrep -a brokerd
ls -l "$BOXMAKER_HOME/run/loop-broker/"
```
Compare the socket path with `[broker] socket` in `loopd`'s config and `[sockets] broker` in
`brokerd.toml`.
**Fix.** Start `brokerd`, or make the two paths agree. `loopd` needs no restart for that: it
connects per call. A changed or newly set `[broker] socket` does need a `loopd` restart.
**Check.** Ask the model to use a tool. The call is decided (allowed, asked or denied) instead of
failing.
## loopd-selftest-failed
**What you see.** `loopd` prints `selftest: FAILED: <reason>` and this entry, and exits 1.
**Why.** `loopd` will not start against a server that differs from the one its config describes,
that does not parse tool calls, or whose cache does not work.
**Confirm and fix, by reason.**
- `chat template sha256: expected …, got …`, `context per slot: …` or `slot count: …`. The server
changed: a model update, or new flags in `~/src/nixos/hw/straylight/default.nix`. Check what
changed on straylight. If the change is intended, update `[expect]` in `loopd`'s config:
```sh
curl -s 'http://straylight:11434/props?model=ornith-1.5-35b-a3b' | jq -j .chat_template | sha256sum
curl -s 'http://straylight:11434/props?model=ornith-1.5-35b-a3b' | jq '.default_generation_settings.n_ctx, .total_slots'
```
A template change also invalidates the M0 measurements. Re-run the checks in
`docs/inference-contract.md` before trusting the cache behaviour.
- `the tool call did not come back parsed: …`. The template or the server's tool parser changed.
Treat it like a template change. Do not start `loopd` until tool calls parse again.
- `turn 2 did not reuse turn 1's cache: …`. Another client may have taken the slot between the two
requests. Check `curl -s 'http://straylight:11434/slots?model=ornith-1.5-35b-a3b'` and run
`loopd selftest --config <path>` again. If it fails twice with the slot otherwise idle, the cache
is not working: check the server flags for `cache_prompt` and the KV settings.
- A connection, timeout or HTTP error. Check that `inferproxy` is running and that its upstream
answers: `curl -s http://straylight:11434/health`. A model load can take tens of seconds, so
retry once.
**Check.** `loopd selftest --config <path>` prints `selftest: ok`.
## session-log-damaged
**What you see.** A turn on an existing session fails with `<file>:<line>: <reason>` naming
`sessions/<id>/<epoch>.jsonl`, and this entry. Other sessions work.
**Why.** `loopd` replays the log exactly to rebuild the conversation, so a line it cannot read
would change what the model sees. It refuses rather than guess. `last line does not end in a
newline` means a write was cut off: `loopd` writes a record only after the request it describes
has finished, so a cut-off line was never used.
**Confirm.**
```sh
f="$BOXMAKER_HOME/sessions/<id>/0.jsonl"
wc -l "$f"; tail -c 300 "$f"
```
**Fix.** Keep a copy first. Then either start a new session (always safe), or, for a cut-off last
line only, drop it:
```sh
cp -a "$f" "$f.damaged-$(date +%s)"
head -n <line-1> "$f.damaged-"* > "$f" # keep the complete lines before the damaged one
```
Anything else (a damaged line in the middle, an unknown record type) means the file was changed
by something other than `loopd`. Start a new session and keep the old log for inspection.
**Check.** The next turn on the session succeeds. The first request re-reads the conversation if
the cache was lost, which `loopd` logs as a cache loss.
## core-memory-unreadable
**What you see.** Starting a new session fails with an error naming `memory/core.md`, and this
entry. Existing sessions still work: they use the baseline saved when they started.
**Why.** `memory/core.md` exists but cannot be read. A missing file is fine, but starting without
memory you wrote, and without telling you, is not.
**Confirm.**
```sh
ls -l "$BOXMAKER_HOME/memory/core.md"; head -c 100 "$BOXMAKER_HOME/memory/core.md"
```
Look for wrong ownership or mode, or a file that is not UTF-8 text.
**Fix.** Make it readable by the user `loopd` runs as (`chmod 0600` and `chown` to that user), or
save it again as UTF-8.
**Check.** A new session starts, and its `0.baseline.json` contains the text.