An abort's reply races the process it ends
test_dev.ml's abort asks were a bare Wire.send/Wire.recv pair against a daemon that the abort itself is killing. In a merged flan dev the daemon is the program: flan_agent.c's listener writes ok and sets aborting, and the break loop's next pass _exit(134)s from the program thread while the editor's reply is still being composed on the serve thread. Nothing orders the two, so the reply arrives or the socket closes, at random. When it closed, Wire.recv raised Closed, nothing caught it, and the test binary died with no FAIL line and every case after it unrun. Four runs out of four at the null-allocator trap. Both endings mean the same thing and neither is the assertion: the waitpid wait underneath each row is what says the program went. aborted answers None for the end that arrived as an exit; the three sites that abort a stopped or trapped program go through it. The fourth abort is refused by a running program and ends nothing, so it is left alone. trap_park's describe poll is guarded with the other answer: these traps park because flan_trap_hook is installed, so a socket closing there is the trap having ended the program instead of stopping it, which is the failure that row already names. And SIGPIPE is ignored for the watchdog's reason, so a send into the socket a dead daemon left behind cannot kill the binary silently from the write side.
This commit is contained in:
parent
dc39631db7
commit
36624d6e33
45
FIX.org
45
FIX.org
@ -1577,7 +1577,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
|
||||
@ -1595,6 +1595,43 @@ observed failures landed at the same row, ~dev-trap-null-alloc~.
|
||||
exception at the same row, against 2 of 5 on this branch. The rates match
|
||||
because the code is the same.
|
||||
|
||||
Not fixed here, deliberately: the fix is to catch ~Closed~ in that poll and
|
||||
read it as the program having ended, which is a claim about what those rows
|
||||
mean and belongs to whoever owns them. Flagged rather than patched.
|
||||
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.
|
||||
|
||||
105
test/test_dev.ml
105
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 () ->
|
||||
|
||||
Loading…
x
Reference in New Issue
Block a user