From 82ca001683e24087f7f89abcafa4fda4f978b4f2 Mon Sep 17 00:00:00 2001 From: Joseph Ferano Date: Mon, 14 Sep 2026 08:11:08 +0700 Subject: [PATCH] The flake was SIGPIPE, and the handoff says how it was caught --- HANDOFF-emacs-flake.md | 164 ++++++++++++++++++++++++++++++----------- 1 file changed, 123 insertions(+), 41 deletions(-) diff --git a/HANDOFF-emacs-flake.md b/HANDOFF-emacs-flake.md index 6aa0446..d5b5c35 100644 --- a/HANDOFF-emacs-flake.md +++ b/HANDOFF-emacs-flake.md @@ -1,8 +1,11 @@ -# The `test_emacs` flake +# The `test_emacs` flake — SIGPIPE, and a socket that outlived its process + +**Closed.** It was neither of the two mechanisms this repository had seen +before. It was a third: `SIGPIPE`. ## The symptom -One run of `dune test --root .` exited 1; the next run on the same tree exited 0. +One run of `dune test --root .` exited 1; the next on the same tree exited 0. ``` FAIL the client notices a stop nobody asked about @@ -10,51 +13,130 @@ One run of `dune test --root .` exited 1; the next run on the same tree exited 0 Error: error ("flan dev: cannot reconnect to /tmp/build_997a01_dune/flan-emacs-dev.sock: make client process failed: Connection refused, ...") ``` -## What the error text already rules out +## Which mechanism it was -Two mechanisms have produced something like this here before: a genuine -listen/connect ordering bug, and a five-second await against a cold -`llc`-and-link. Neither fits this text, and the reason is in the branches: +Neither of the two named in the brief. -- **A 20s poll deadline that simply expired** leaves the connection *live*. - The two `FAIL`s would print and `flan-dev-restarts` would then succeed. - There would be no `Error:` line at all. -- **The daemon exiting** — the child program finishing, `serve` returning - `closed`, or any OCaml exception — runs `Fun.protect`'s finally in - `Dev.two_process`, which unlinks the socket. The client then takes the - `(not (file-exists-p ...))` branch and says *"nothing is listening on ...; - start `flan dev program.flan` again"*. A different message. -- **`Connection refused`** on a unix socket needs the path to exist *and* no - socket in listen state behind it. In `two_process` (lib/dev.ml:2514-2526) - `bind` and `listen` are adjacent, nothing else ever creates that path, and - the only close of the listening fd is in the same finally that unlinks. So - it is reachable essentially one way: **the daemon died without running its - finally — that is, it was killed by a signal.** +- **Not a listen/connect ordering bug.** `bind` and `listen` are adjacent in + both `Dev.two_process` and `Dev.merged_setup`, nothing else creates that + path, and the connection that failed was one that had already been working + for forty checks. +- **Not a timeout too short for a cold build.** That failure mode is now + reproducible on demand (see *The tick budget* below) and it produces an + entirely different message. +- **It was `SIGPIPE`.** The daemon answers an editor by calling `Wire.send`, + which is `Unix.write_substring`. Nothing in the OCaml half of the daemon + ignored `SIGPIPE`, so a reply written into a socket whose reader had gone + killed the process outright. In the merged one-process build that process is + the program, the compiler and the listener at once — so the program died + without ever reporting a stop (the two `FAIL`s), and the socket file was left + on disk with nothing accepting on it (`Connection refused` on a path that + plainly exists). One event, all three lines. -The machine was loaded (several compiler lanes building at once) and `/tmp` -filled to 100% the day before, so the OOM killer is the first candidate. + It is not a contrived shape. `flan-dev--live-connection` reopens a dead + connection, Emacs tears the old process down when it does, and a reply + already on its way out lands in the gap. `flan_agent.c` had reached the same + conclusion from the other side years ago and passes `MSG_NOSIGNAL`; the half + written in OCaml never got the same treatment. -## The plan +## How it was reproduced -1. Fix the observability first. `test_emacs.ml` throws away the one fact that - discriminates: the cleanup `waitpid` matches `| _ -> true` and drops the - status, and the temporary files are removed *before* the exit code is - checked, so the program's output is gone by the time anyone looks. -2. Reproduce by running `_build/default/test/test_emacs.exe` in a loop under - artificial load, recording the daemon's wait status, `df /tmp` and - `dmesg | tail` each iteration. -3. Fix the mechanism the evidence names. -4. Sweep the siblings — `test_repl.ml`, `test_dev.ml`, `test_cider.ml`. What - they share with `test_emacs.ml` is the discarded wait status, not a missing - connect retry: they already have retrying `connect` helpers. +A client that sends one request and closes before the reply arrives: -## Open questions +``` +daemon DIED after 1 hit-and-run connections +daemon wait status: 141 (128+13=141 is SIGPIPE) +socket file left behind: YES +and a fresh client gets: + [Errno 111] Connection refused +``` + +That is the reported failure, exactly, in under a second and every time. With +the fix, 300 such connections leave the daemon serving. + +The reproduction is now a check in `test_dev.ml`, in the robustness daemon's +block: eight hit-and-run connections, then a request proving the session is +still there and still knows what it installed. Against the parent of the fix it +fails with `killed by SIGPIPE`. + +## The fix + +`lib/dev.ml`, three parts: + +1. `ignore_sigpipe ()` where the listening socket is bound — in both + `two_process` and `merged_setup`. Ignored rather than handled, because + `serve` already treats a failed write as a closed connection. +2. The reply write is guarded. An `exception` case on a `match` covers the + *scrutinee*, not the branch body, so the `EPIPE` that ignoring the signal + produces went straight past the two handlers below it and out of the accept + loop — which ended the session just as surely, only quietly. Without this + the first fix converts `SIGPIPE` into `flan dev: Unix.Unix_error(EPIPE)` and + the daemon still stops. +3. The socket is unlinked on the ways out the daemon does not control as well + as the one it does: an `atexit` in the merged `main` for `exit(3)`, which is + what `flan_rt.c`'s `rt_die` takes on any runtime trap; by hand in + `flan_agent.c`'s `die_now`, and in `main`'s `_exit(rc)` fallback, both of + which skip the `atexit` chain deliberately. A stale socket can now only come + from a `SIGKILL`. + +`emacs/flan-dev.el`: a refusal on a path that exists is reported as a leftover +socket rather than as `Connection refused`. The raw message is what sent two +investigations here the wrong way. + +`test/test_emacs.ml` and `test/test_repl.ml`: the daemon's wait status is kept +instead of discarded, and the program's output is read *before* the temporary +files are removed rather than after. The old order deleted the evidence and +then printed the exit code — which is why nobody could tell, twice running, +whether the daemon had exited or been killed. + +## The sibling call sites + +Four files are in this family and the answer differs for each: + +- `test_dev.ml` and `test_repl.ml` drive the same daemon, so `lib/dev.ml`'s fix + covers them. Neither had a separate copy of the bug. +- `test_cider.ml` has **no daemon and no running program** — it drives the + inspector and break buffer from fixtures. It is not in this family at all, + despite the name. +- `test_emacs.ml` was the only one whose harness destroyed the evidence before + reading the exit code; `test_repl.ml` had the same ordering and is fixed too. + +So: one bug, one site, three harnesses — not the three-way split the last one +had. + +## The tick budget — a second hazard, and not this one + +`test/programs/dev-repl.flan` ran `(dotimes [i 4000] (agent/wait 5) ...)`: a +twenty-second program under a two-minute test, and `test_emacs` drives one +daemon through the whole run. On a loaded machine the client can still be +working when the program reaches its last tick. + +This is real and it is reproducible — sweep the budget and the same two +break-loop checks fail at 165, 175 and 185 ticks — but it is **not** the flake +above, because it fails honestly: `the program exited; restart flan dev` at one +budget, `nothing is listening on ...` at another. Never `Connection refused`. +That is what ruled it out. + +Raised to 24000, which is what `dev-robust.flan` already uses for the same +reason. The 600s watchdogs are what actually bound the run. + +## Verification + +- `dune test --root .` — three runs, 232 checks, 0 failures, exit 0 each time. + All three under sixteen busy loops; two of them alongside a running + `spike/x86/survey.sh`. +- `spike/x86/survey.sh` — 103 MATCH / 0 DIFFER / 0 REFUSED. + +## Open questions for the author - `lib/cimport.ml:1138` still spells its own `cachedir` under `$TMPDIR`, which NEXT.md:694 flags as the last remnant of the cold-cache bug. Another lane - holds that file. It is both a per-run cold cache and a plausible filler of - `/tmp`. - -## Status - -Stub. Investigation in progress. + holds that file. Folding it onto `Build.cachedir` is still a one-line change. +- `Build.cachedir` is now under `XDG_CACHE_HOME`, which means it is **shared** + between concurrently running lanes rather than private per dune run. The + writes are `tmp`-then-`rename`, so nothing can read a half-written object, + and nothing in this investigation pointed at it. Noted only because "several + compiler lanes at once" is now a condition the suite is expected to survive. +- `runtime/flan_dev.c:51` reaches `abort()` on a full name table, and `abort` + runs neither the `atexit` chain nor anything else. It is a 4096-name limit + and no test comes near it, so it is left as it is.