diff --git a/FIX.org b/FIX.org index 38458b6..d90bb06 100644 --- a/FIX.org +++ b/FIX.org @@ -1590,7 +1590,7 @@ before the rows were written and again after the rebase. It is in ~test_sanitize.ml~'s list; per the sweep policy the sweep itself was not run. ** Found while running it: ~dune test~ exits 1 at random, and has since before - this lane + this lane — FIXED ~test_dev.ml~'s ~trap_park~ rows are racy, and when they lose the race the whole test binary dies with ~Fatal error: exception Flan.Wire.Closed~ — exit 1 with no FAIL line anywhere, which is the worst shape a failure can have @@ -2195,3 +2195,44 @@ parameter list is refused by name where it is written: forms with no fields to name. Take the form and pick it apart in the body Pinned in test_flan.ml. Whoever wants it should decide what it means first. + +Flagged rather than patched by that lane, and fixed by the one after it. The +diagnosis was right about the exception and one row off about where: the +losing ~ask~ is the ~abort~ that ends the row, not the ~describe~ poll that +opens it — every reproduction died on the line after ~flan: aborted at the +break loop~, four runs out of four. + +*The claim those rows now make.* ~abort~ is the one verb that ends the +process answering it, and in a merged ~flan dev~ that process is the daemon. +flan_agent.c's listener writes its own ~ok~ and sets ~aborting~; the break +loop's next pass calls ~die_now~, which is ~_exit(134)~, from the *program* +thread — while the reply to the editor is still being composed on the *serve* +thread, out of ~Dev.abort~'s ~ok~. Nothing orders the two. So an abort that +did exactly what was asked comes back either as ~:status "ok"~ or as the +socket closing under the read, and both are the same outcome. Neither is the +assertion: what says the abort worked is the ~waitpid~ wait underneath it, +which every one of these rows already does. A new ~aborted~ helper in +~test_dev.ml~ answers ~None~ for the end that arrived as an exit, and the +three sites that abort a stopped or trapped program go through it — the break +row, the globals row and ~trap_park~. The fourth ~abort~ in the file is the +one a *running* program refuses; it ends nothing and was left alone, as was +~test_agent.ml~'s, which talks to the agent's own channel: the ~ok~ is on the +wire before ~aborting~ is set, so the exit cannot overtake it, and that +file's ~send~ reads to EOF and already swallows a ~Unix_error~ besides. + +The ~describe~ poll that opens ~trap_park~ is guarded too, and with the other +answer: these traps park because ~flan_trap_hook~ is installed, and with no +hook ~rt_trap~ falls through to ~rt_die~ and the program takes the daemon +with it — so a socket closing *there* is the trap having ended the program +instead of stopping it, which is the failure that row already names. Closed +on the abort is a pass; closed on the poll is a FAIL with a reason. Neither +is a retry. + +SIGPIPE is ignored in ~test_dev.ml~ for the watchdog's reason: with a daemon +that exits by design, a ~Wire.send~ into the socket it left behind would kill +the binary with no line saying why — the same silent shape, reached from the +write side. + +Measured after: 22 runs of ~test_dev.exe~, all exit 0, no fatal exception; 5 +runs of ~dune test --root . --force~, all exit 0. ~--force~ because dune +caches a test that passed, and a cached pass proves nothing about a race. diff --git a/test/test_dev.ml b/test/test_dev.ml index c6bef30..45ea562 100644 --- a/test/test_dev.ml +++ b/test/test_dev.ml @@ -12,6 +12,19 @@ open Flan nothing at all. See watchdog.ml. *) let () = Watchdog.arm ~seconds:900 "test_dev" +(* SIGPIPE ignored, and for the watchdog's own reason: a binary killed by a + signal prints no line saying why and leaves every case after it unrun. The + daemons here are ended on purpose — an [abort] at a break or a trap exits + the process, because in a merged [flan dev] the daemon *is* the program — + so a [Wire.send] into a socket whose peer has just gone is a shape this + file reaches by design. Ignored, it comes back as EPIPE out of + [Unix.write], which a case can name; unignored, it is the test binary that + dies. [flan dev] ignores it for the same reason — see [Dev.ignore_sigpipe], + whose note is about the other end of these same sockets. *) +let () = + try Sys.set_signal Sys.sigpipe Sys.Signal_ignore + with Invalid_argument _ -> () + (* The counter, the scratch paths, the poll and the daemon wait are all in test_support.ml, which is where [listening]'s long note about telling a still-building daemon from a dead one now lives too. The watchdog armed @@ -113,6 +126,39 @@ let status r = let contains_sub = Test_support.contains +(* ── The one verb whose reply races the process it ends ─────────────── *) + +(* [abort] is answered twice over, and the two answers are not ordered. On the + program's own channel flan_agent.c's listener writes "ok" and then sets + [aborting]; the break loop's next pass prints "aborted at the break loop" + and calls [die_now], which is [_exit(134)] — from the program thread. The + reply to the editor is composed on the *serve* thread, out of [Dev.abort]'s + [ok], and in a merged [flan dev] both threads are in this one process. So + an abort that did exactly what was asked comes back either as + [:status "ok"] or as the socket closing under the read, depending on which + thread got there first. + + Both are the same outcome, and neither is the assertion. What says the + abort worked is the [waitpid] wait every caller does underneath it: the + process ended. [aborted] therefore answers [None] for the end that arrived + as an exit, and its callers check a status only when there is one to check. + + Written out because the bare [Wire.recv] this replaces lost that race often + enough to kill the binary outright — [Fatal error: exception + Flan.Wire.Closed], no FAIL line, and every case after it silently unrun, + which is the worst shape a flake can take here. Reproduced four runs out of + four at the null-allocator trap before this. + + [Unix_error] is caught beside [Closed] because a peer that [_exit]s can + reset the connection rather than close it cleanly, and a reset leaves + [Unix.read] by its errno rather than as the EOF [Wire.recv] turns into + [Closed]. The same end, arriving under another name. *) +let aborted c = + match Wire.parse (Wire.send c "(:op \"abort\")"; Wire.recv c) with + | r -> Some r + | exception Wire.Closed -> None + | exception Unix.Unix_error _ -> None + (* ── Whose fault a full reload ring is ──────────────────────────────── *) (* The agent refuses a module it has no room to queue with "the program is not @@ -1107,10 +1153,15 @@ let () = | fs -> fail "frames left on the shadow stack by five handled errors: %s" (String.concat ", " (List.map (fun (n, o) -> n ^ "/" ^ o) fs))); - let r = ask "(:op \"abort\")" in - if status r <> "ok" then - fail "abort was refused by a stopped program: %s" - (Option.value ~default:"" (Wire.string_field r "message")) + (* [aborted] and not [ask]: the reply races the exit it asked for, + and a session that went before it could answer is the abort + having worked. The wait on [bpid] below is the claim. *) + (match aborted c with + | None -> () + | Some r -> + if status r <> "ok" then + fail "abort was refused by a stopped program: %s" + (Option.value ~default:"" (Wire.string_field r "message"))) end); Unix.close c; (* No [close] op: an abort ends the program, and the daemon owns the @@ -1314,10 +1365,27 @@ let () = | Some { Form.v = Form.Sym "t"; _ } -> true | _ -> false in - let last = ref (ask "(:op \"describe\")") in - if not - (await (fun () -> last := ask "(:op \"describe\")"; stopped !last)) - then fail "the %s trap never stopped the program, it ended it" what + (* Seeded with a reply nobody sent rather than with a first [ask]: the + poll below overwrites it on its first pass, and the ask it replaces + was a second bare [Wire.recv] exposed to the same closing socket. *) + let last = ref (Wire.parse "()") in + (* The poll, and what a session that vanishes under it means. These + traps park because [flan_trap_hook] is installed; with no hook + [rt_trap] falls through to [rt_die], the program [_exit]s 134 and + takes the merged daemon with it — so a socket closing here is the + trap having ended the program instead of stopping it, which is the + failure named below and not something to wait out. There is no + retry: the daemon was answering a moment ago, [listening] saw to + that, so this is never a session still coming up. *) + let ended = ref false in + let poll () = + match ask "(:op \"describe\")" with + | r -> last := r; stopped r + | exception Wire.Closed -> ended := true; true + | exception Unix.Unix_error _ -> ended := true; true + in + if (not (await poll)) || !ended then + fail "the %s trap never stopped the program, it ended it" what else begin (* Which trap, by name. There is no [defstruct] behind these — they are traps and not conditions, and [layout] will say it cannot @@ -1390,11 +1458,20 @@ let () = fail "an expression while parked at the %s trap: %s" what (Option.value ~default:(status r) (Wire.string_field r "message")); (* Torn down by [abort], not by [close]: a trap parks for good, so - there is no resume to wait for and nothing to gain by waiting. *) - let r = ask "(:op \"abort\")" in - if status r <> "ok" then - fail "abort at the %s trap: %s" what - (Option.value ~default:"" (Wire.string_field r "message")) + there is no resume to wait for and nothing to gain by waiting. + + Through [aborted], because this is the site where the race it + describes was actually losing: the trap's break loop calls + [die_now] from the program thread while the serve thread is still + writing the reply, and a closed socket here says the program + ended, which is what the abort asked for. The [waitpid] below is + what asserts it. *) + (match aborted c with + | None -> () + | Some r -> + if status r <> "ok" then + fail "abort at the %s trap: %s" what + (Option.value ~default:"" (Wire.string_field r "message"))) end; Unix.close c; if not @@ -2554,7 +2631,7 @@ let () = (* Nothing handled the condition, so there is no restart to resume by and [abort] is the only way out. The daemon owns the program's lifetime, so it comes down on its own. *) - ignore (ask "(:op \"abort\")"); + ignore (aborted c); Unix.close c; if not (await ~ms:5000 (fun () ->