From 6de6c079b0f6eed8dc8dfb357f844f625746d300 Mon Sep 17 00:00:00 2001 From: Joseph Ferano Date: Sun, 13 Sep 2026 13:12:17 +0700 Subject: [PATCH] What the "never listened" flake actually was, written where it was hunted MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Two lanes were sent after a contention race on a socket path. There is none. The sentence came from three sites and not the two HANDOFF-f1.md named — test_dev.ml:77 checks the *dev* socket with exactly that wording, in the same block whose *agent* socket check was fixed — and the cause is a bound too short for a build: flan dev links the whole program before it binds, ~600ms warm, measured at 6.5s here and 6.6-6.8s by the lane that fixed it, against a 5000ms await in test_dev.ml and 8000ms in the other two. Build.cachedir sits under dune's per-run TMPDIR, so that build is cold on every invocation and the failure is not occasional at all. The fix landed on another branch; nothing in this commit touches a test. The agent.sock ordering fix it does confirm: 30 sequential full dune test runs, 0 failures, no "never bound" in any log — so NEXT.md's "One flaky test, measured rather than suspected" section, left standing for whoever confirmed it, goes. HANDOFF-f1.md's "lengthening any timeout" bullet is qualified rather than deleted. It was true of the agent.sock check and read as a rule, and reading it as a rule is what kept this open for a second lane. --- HANDOFF-f1.md | 47 ++++++++++++++++++++++++++++++++--------------- NEXT.md | 50 ++++++++++++++++++++++---------------------------- 2 files changed, 54 insertions(+), 43 deletions(-) diff --git a/HANDOFF-f1.md b/HANDOFF-f1.md index 31c1401..952b802 100644 --- a/HANDOFF-f1.md +++ b/HANDOFF-f1.md @@ -54,22 +54,36 @@ longer sweep was **not measured**. ## What remains -1. **Identify and fix the other "the daemon never listened" flake.** It appeared once in one of two - post-change full `dune test` runs and is *not* test_dev's first block (that block is 0/10 under - the new code, and its own message is distinct). The message text is emitted from - `test/test_emacs.ml:50` and `test/test_repl.ml:71` with exactly that wording; `test/test_dev.ml`'s - other daemons all use qualified wording ("the break daemon…", etc.), so the culprit is almost - certainly `test_emacs` or `test_repl`. Re-run `dune test --root .` in a loop and capture per-binary - output to disambiguate. Likely the same class of bug — a bounded `await` on a socket path under - parallel-dune CPU contention — but that is a hypothesis, not a finding. Pre-existing: it did not - appear in the pre-change full run, but one observation each way proves nothing. -2. **Decide whether `merged_serve`'s 10s warning path deserves a test.** Nothing currently exercises +1. **Decide whether `merged_serve`'s 10s warning path deserves a test.** Nothing currently exercises lib/dev.ml:2322-2326 (a program that never calls `agent/start`). It was reachable only by accident here, via the unlink race that is now closed. -3. **Confirm the fix at the rate NEXT.md claims** with a longer sweep (40+ runs) if the 0/10 is - considered too thin, then delete the "One flaky test, measured rather than suspected" section from - `NEXT.md` (around line 138). That section was deliberately **left untouched** — it should be - removed by whoever confirms the fix, not by the change that made it. + +## Closed since: the other "the daemon never listened", which was not a race at all + +The previous item 1 sent two lanes after a contention race. **There is none**, and the reading it was +built on was wrong twice over: + +- The wording is **not** unique to `test_emacs.ml:50` and `test_repl.ml:71`. `test/test_dev.ml:77` — + the *dev* socket check in the same first block this handoff fixed the *agent* socket check in — + emitted exactly `the daemon never listened` as well. Three sites, not two, which is why a sighting + in a full-run log could not be attributed. +- The cause is a **bound that is too short for a build, not a race**. `flan dev` does an llc-and-link + of the whole program *before* it binds its socket, so the await covers a build. Warm and idle that + is ~600ms; under dune's own parallelism it was measured at 6.5s here and at 6.6s and 6.8s by the + lane that fixed it — against a 5000ms await in `test_dev.ml` and 8000ms in the other two. Nothing + about it is occasional; it reproduces whenever the build is cold, and `Build.cachedir` sits under + dune's per-run `TMPDIR`, so the object cache starts empty on **every** `dune test` invocation. + +Fixed on another branch: all three awaits now wait a minute, bounded by the existing watchdog rather +than by a guess, and `test_dev.ml` carries a named `listening` helper so the reason is written once +for its thirteen daemons. + +Two measurements from this lane that stand whatever else changes: **30 sequential full `dune test` +runs, 0 failures and no `never bound` in any of them** — the `agent.sock` ordering fix above is +confirmed at a sweep wide enough to close item 3 of the old list, so `NEXT.md`'s "One flaky test, +measured rather than suspected" section is deleted. The reproduction that came after it, on the 31st +run, was the *dev* socket at `test_dev.ml:77`, with `built dev-loop.flan in 6525ms` sitting four lines +below the FAIL in the same log — which is what turned the hypothesis into the finding above. ## Tried and rejected @@ -77,7 +91,10 @@ longer sweep was **not measured**. It looks like the obvious fix and it is wrong: it makes the test observe the file at the *earliest* possible instant, which makes it *more* likely to win the unlink race against `merged_serve` and more likely to trigger the silent 10s stall. Do not reintroduce it. -- **Lengthening any timeout.** Not needed; the ordering was missing, not the time. +- **Lengthening any timeout** — *for the `agent.sock` check*. Not needed there; the ordering was + missing, not the time. This does **not** generalise, and reading it as a rule cost two lanes: the + socket-appears checks above are a wait for a *build*, and there lengthening the bound was exactly + the fix. See the section before this one. ## Environment note for whoever picks this up diff --git a/NEXT.md b/NEXT.md index 2225e6c..3615ca7 100644 --- a/NEXT.md +++ b/NEXT.md @@ -35,19 +35,20 @@ The fix is ordering, not timing: the test checked for `agent.sock` before comple the check took it from 2/8 failures to 0/10, and closed a second race that was burning the full 10s timeout. `lib/dev.ml` was not touched. -1. **A different flake, seen once and unexplained.** `the daemon never listened` — that exact wording comes from - `test_emacs.ml:50` and `test_repl.ml:71`, not from the block that was fixed, whose other daemons all use - qualified wording. Probably the same class of bug, a bounded `await` on a socket path under parallel-dune CPU - contention, but that is a hypothesis. Loop `dune test` capturing per-binary output to pin it down. -2. **Decide whether `merged_serve`'s 10s warning path deserves a test.** `lib/dev.ml:2322-2326` is exercised by - nothing now that the unlink race is closed. -3. **Confirm at a longer sweep if 0/10 is too thin, then delete this file's "One flaky test, measured rather than - suspected" section.** It was deliberately left standing — it should go when someone confirms the fix, not in the - change that made it. +Confirmed at 30 sequential full `dune test` runs, 0 failures and no `never bound` in any of them, so the section +this file used to carry about it is gone. -Two things already tried and rejected, so they are not re-derived: wrapping the check in the file's `await` helper -makes the test observe the file at the *earliest* instant and so more likely to lose the race, and no timeout needed -lengthening. +1. **Decide whether `merged_serve`'s 10s warning path deserves a test.** `lib/dev.ml:2322-2326` is exercised by + nothing now that the unlink race is closed. + +**The other "never listened" was not a race, and the note that sent people after one was wrong twice.** That wording +came from *three* sites, `test_dev.ml:77` included, not from the two this file named. And it is a bound too short for +a build, not contention: `flan dev` links the whole program before it binds, ~600ms warm and measured at 6.5-6.8s +under dune's own parallelism, against 5000ms in `test_dev.ml` and 8000ms in the other two — `Build.cachedir` lives +under dune's per-run `TMPDIR`, so that build is cold on every invocation. Fixed on another branch: the three awaits +wait a minute now, bounded by the watchdog, with a named `listening` helper in `test_dev.ml`. The one thing not to +re-derive from `HANDOFF-f1.md` is its "lengthening any timeout" bullet — that applies to the `agent.sock` check +only, and reading it as a rule is what kept this open. ### From `HANDOFF-f3.md` — the watch is built; two tests are not @@ -58,11 +59,15 @@ editor's last tick rather than cumulative, because cumulative min/max reach the play and then never move again. Reset is its own message and never a side effect of reading, so the reader never writes the table. -1. **`emacs/test-flan-watch.el` — a `watch-num-i64` fixture site.** The regexp fix is the one change in that lane - with no regression test. `flan-watch-ghost-call-regexp` allowed a single hyphenated segment, so `watch-num-i64` - backtracked to failure and a numeric watch showed *no* inline value while looking normal in the buffer. -2. **`test/test_dev.ml` — assert the `n=0` render.** `watch_render_num` in `runtime/flan_dev.c` has a branch for a - slot that was never sampled and nothing reaches it. +The fixture is in: `emacs/test-flan-watch.el` pins both accumulator heads beside the one-segment ones, verified by +putting the old `?` back in `flan-watch-ghost-call-regexp` and watching exactly those two checks fail. + +1. **`watch_render_num`'s `n=0` branch is dead, and the choice is whose it is to remove.** No test can reach it: + `s->num` is set only in `watch_record`, which always falls through to `s->n += 1` inside one odd-generation + window, and the reader never compares the slot's epoch to the global one. The live consequence is that a read + after `:reset t` and before the program's next sample reports the *previous* window — which is why the test waits + for the count to drop instead of reading once. Either delete the branch or make the read epoch-aware; both are + `runtime/flan_dev.c` decisions. `HANDOFF-f3.md` has the argument. ### Not started: five more raylib core examples @@ -240,17 +245,6 @@ state holds fixed arrays or `Vec`s. **raylib 6.0 is not urgent:** all seven struct layouts on the game's path and every enum value it touches are byte-identical between 5.5 and the vendored 6.0. -### One flaky test, measured rather than suspected — **fixed, pending a longer sweep** - -The ordering fix is in (`f80a7a9`): 2/8 failures before, 0/10 after. This section stays until someone confirms it at -a sweep wide enough to be worth the claim, then goes. See `HANDOFF-f1.md`. The original reading follows. - - -`test_dev.ml`'s first block fails about one run in four with *"the merged program never bound -…/agent.sock"*. **It is not new** — reproduced at `54027ca`, before any of today's work, at the same rate. It is a -startup race in the one-process daemon's socket bind, not a real failure, and it makes "the suite is green" a -statement that needs a second run to make. Worth fixing before it trains someone to re-run on red. - ### Left mid-flight when the session ended Both lanes committed their main work and died on trailing polish; both are merged and the suite is green.