What the "never listened" flake actually was, written where it was hunted
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.
This commit is contained in:
parent
6e7b53b988
commit
6de6c079b0
@ -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
|
||||
|
||||
|
||||
50
NEXT.md
50
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.
|
||||
|
||||
Loading…
x
Reference in New Issue
Block a user