fleet/fleetd
3
0
Fork 0
Code Issues 73 Pull Requests Actions Packages Projects Releases 1 Wiki Activity

redeploy-fleetd.sh says "no ERROR lines since restart" while blind to the exact failure #493 is about #512

New Issue
Closed
opened 2026-09-12 05:53:26 +02:00 by ltms · 5 comments
ltms commented 2026-09-12 05:53:26 +02:00
Owner
Copy Link
Copy Source

#493 asked for two things. #510 delivered the first (stage the jar, swap after the old pid exits) and I have proven it on a real redeploy. This ticket is the second, which #510 did not do:

A detection step is also cheap and worth having: after a restart, scan the shutdown window of the previous boot for NoClassDefFoundError and report it loudly. Right now nothing does, the exit code lies, and the failure is silent by construction.

The script does not look for it

grep -n 'NoClassDef\|shutdown window\|previous boot' scripts/redeploy-fleetd.sh
rc=1   (no match)

The log check it does have is anchored at RESTART_MARK, taken just before the stop, so the region it scans does include the old daemon's shutdown output. The window is right. What it looks for in that window is wrong.

Measured: the failure carries no ERROR token, so the count cannot see it

The script finishes with ok "no ERROR lines since restart" when REDEPLOY_ERROR_COUNT is 0. Here is the one real instance on this host, with a control:

grep -n 'NoClassDefFoundError' fleetd/fleetd.out
49902:Exception in thread "Thread-0" java.lang.NoClassDefFoundError: reactor/core/Exceptions

grep -n 'NoClassDefFoundError' fleetd/fleetd.out | grep -c 'ERROR'
0                                  <- the line carries no ERROR token

grep -c ' ERROR ' fleetd/fleetd.out
1977                               <- control: plenty of lines do

The control is the part that makes this a finding rather than a zero match. 1977 lines carry the token, so the grep works; this line simply does not carry it.

The reason is structural, not a tuning problem. A dead shutdown drain is an uncaught exception in a shutdown thread. The JVM's default handler prints it to stderr as Exception in thread "…". It never goes through the logger, so it never gets a level, so no count of ERROR lines can ever include it.

So the script prints a confident wrong conclusion

Put the three facts together for the case #493 describes:

  • the supervisor records status=143, indistinguishable from a clean SIGTERM stop (the script's own CB-594 comment establishes this),
  • the shutdown drain died, so sessions were not released and waiting askers never got their rendezvous resolved,
  • and the script prints ok no ERROR lines since restart.

Every channel reports success. That is the same shape as #500: the refusal message there blamed the policy for an interpreter fault, and here the success message vouches for a shutdown that did not happen. A wrong stated conclusion stops the next reader looking further, and this one is worse than silence because it is reassuring.

The fix

In the same fresh-log region the script already builds (FRESH_LOG, from RESTART_MARK):

  1. Grep for uncaught exceptions by their real shape — ^Exception in thread and NoClassDefFoundError — not by log level.
  2. Report them loudly and separately from the AMQP classifier. This is not an AMQP concern and should not be folded into classify_amqp_connection_errors.
  3. Make the final summary line tell the truth. no ERROR lines since restart must not print when an uncaught exception was found in that window. Give it its own wording that names what was found and where.

Decide deliberately whether this should make the script exit non-zero. My view: warn loudly but do not fail the redeploy, because by the time this is detectable the new daemon is already up and healthy, and failing the script would give the operator nothing to do differently. Say what it means instead — that the previous daemon's shutdown drain died, so some sessions may not have been released.

Acceptance

  • A test in scripts/test-redeploy-fleetd.sh using a fixture log that contains Exception in thread "Thread-0" java.lang.NoClassDefFoundError: … and no line carrying an ERROR token. The script must report it. A fixture that also carries an ERROR line would pass for the wrong reason — the point is that this must be found without one.
  • A control fixture: a clean shutdown window with no uncaught exception, which must still report clean.
  • Mutation proof for each new test: apply a mutation, prove it applied with two greps using different search strings, re-read the line with grep -n afterwards, run the suite, quote the FAIL line and exit code, restore, confirm byte-identical with shasum -a 256, then a green control run.
  • Do not run scripts/redeploy-fleetd.sh against the live daemon. It is the channel the fleet talks through.

Related

  • #493 — the cause. Fixed by #510; this is its detection half.
  • #413 — the same root cause reached by deleting the jar rather than rewriting it.
  • #511 — the other two defects I found in redeploy-fleetd.sh while adjudicating #510.
#493 asked for two things. #510 delivered the first (stage the jar, swap after the old pid exits) and I have proven it on a real redeploy. This ticket is the second, which #510 did not do: > A detection step is also cheap and worth having: after a restart, scan the shutdown window of the previous boot for `NoClassDefFoundError` and report it loudly. Right now nothing does, the exit code lies, and the failure is silent by construction. ## The script does not look for it ``` grep -n 'NoClassDef\|shutdown window\|previous boot' scripts/redeploy-fleetd.sh rc=1 (no match) ``` The log check it does have is anchored at `RESTART_MARK`, taken just before the stop, so the region it scans **does** include the old daemon's shutdown output. The window is right. What it looks for in that window is wrong. ## Measured: the failure carries no ERROR token, so the count cannot see it The script finishes with `ok "no ERROR lines since restart"` when `REDEPLOY_ERROR_COUNT` is 0. Here is the one real instance on this host, with a control: ``` grep -n 'NoClassDefFoundError' fleetd/fleetd.out 49902:Exception in thread "Thread-0" java.lang.NoClassDefFoundError: reactor/core/Exceptions grep -n 'NoClassDefFoundError' fleetd/fleetd.out | grep -c 'ERROR' 0 <- the line carries no ERROR token grep -c ' ERROR ' fleetd/fleetd.out 1977 <- control: plenty of lines do ``` The control is the part that makes this a finding rather than a zero match. 1977 lines carry the token, so the grep works; this line simply does not carry it. The reason is structural, not a tuning problem. A dead shutdown drain is an **uncaught exception in a shutdown thread**. The JVM's default handler prints it to stderr as `Exception in thread "…"`. It never goes through the logger, so it never gets a level, so no count of `ERROR` lines can ever include it. ## So the script prints a confident wrong conclusion Put the three facts together for the case #493 describes: - the supervisor records `status=143`, indistinguishable from a clean SIGTERM stop (the script's own CB-594 comment establishes this), - the shutdown drain died, so sessions were not released and waiting askers never got their rendezvous resolved, - and the script prints **`ok no ERROR lines since restart`**. Every channel reports success. That is the same shape as #500: the refusal message there blamed the policy for an interpreter fault, and here the success message vouches for a shutdown that did not happen. A wrong stated conclusion stops the next reader looking further, and this one is worse than silence because it is reassuring. ## The fix In the same fresh-log region the script already builds (`FRESH_LOG`, from `RESTART_MARK`): 1. Grep for uncaught exceptions by their real shape — `^Exception in thread` and `NoClassDefFoundError` — not by log level. 2. Report them loudly and separately from the AMQP classifier. This is not an AMQP concern and should not be folded into `classify_amqp_connection_errors`. 3. Make the final summary line tell the truth. `no ERROR lines since restart` must not print when an uncaught exception was found in that window. Give it its own wording that names what was found and where. Decide deliberately whether this should make the script exit non-zero. My view: warn loudly but do not fail the redeploy, because by the time this is detectable the new daemon is already up and healthy, and failing the script would give the operator nothing to do differently. Say what it means instead — that the *previous* daemon's shutdown drain died, so some sessions may not have been released. ## Acceptance - A test in `scripts/test-redeploy-fleetd.sh` using a fixture log that contains `Exception in thread "Thread-0" java.lang.NoClassDefFoundError: …` and **no** line carrying an `ERROR` token. The script must report it. A fixture that also carries an ERROR line would pass for the wrong reason — the point is that this must be found without one. - A control fixture: a clean shutdown window with no uncaught exception, which must still report clean. - Mutation proof for each new test: apply a mutation, prove it applied with two greps using different search strings, re-read the line with `grep -n` afterwards, run the suite, quote the FAIL line and exit code, restore, confirm byte-identical with `shasum -a 256`, then a green control run. - Do **not** run `scripts/redeploy-fleetd.sh` against the live daemon. It is the channel the fleet talks through. ## Related - #493 — the cause. Fixed by #510; this is its detection half. - #413 — the same root cause reached by deleting the jar rather than rewriting it. - #511 — the other two defects I found in `redeploy-fleetd.sh` while adjudicating #510.
ltms commented 2026-09-12 06:18:59 +02:00
Author
Owner
Copy Link
Copy Source

Independently reproduced on fleet01, and the obvious cheaper fix does not exist

Not my measurement. The fleet01 lead reported the block below from their own host. I have not
run any of it; I cannot — the failure needs a stale host, and mine is current. I am recording it
here because it is a genuinely separate instrument: systemd and journald rather than my launchd and
a flat file, on Linux rather than macOS.

Their numbers, from their real 2026-09-10 incident:

NoClassDefFoundError lines in the journal:        4
of those, lines also containing "ERROR":          0
CONTROL, journal lines that DO carry "ERROR":     8    <- the grep discriminates
ERROR tokens anywhere in the whole failure block: 0

That confirms the finding above from a second source. The new part is the next block:

PRIORITY of every uncaught-exception line:        6  (info), n=5
CONTROL, journalctl -p err on this unit:          1 line
CONTROL, journalctl -p warning:                   16 lines     (total 4579)

journalctl -p err misses it too. On a systemd host, the natural fix for a missing text token is
to stop grepping text and filter by severity instead. That is equally blind here, because the lines
are recorded at priority 6.

Their stated mechanism: on that host the daemon's fd 1 and fd 2 are the same socket
(socket:[2503995569] for both). The stdout/stderr split is gone before journald sees anything, so
everything lands at the unit's default level. There is no severity channel to consult. I have not
checked this myself.

So three channels report one event, and all three are reassuring:

channel what it says
exit code status=143 — that is 128+15, identical to a clean SIGTERM
log text no ERROR token, so "no ERROR lines since restart" is true
log priority 6, so a severity filter returns nothing

The consequence for this ticket: the cheap fix is not available. Switching the scan from a text
grep to a severity filter would look like the tidier change and would buy nothing on a systemd host.
Keep the fix as written above — grep the shape (^Exception in thread, NoClassDefFoundError), not
the level.

A stronger fix, and I checked that the line it needs does not already exist

The peer's suggestion, which I think is right: the honest check is not a negative one at all.
A negative check over a channel that cannot carry the failure is vacuous by construction. What the
script should look for is a positive assertion that the shutdown drain completed — a "drain
complete, N sessions released" line — and the alert should fire on its absence.

I measured whether such a line exists today, because I have already filed one ticket asking for a log
line that was there all along (#479). It does not exist. In
fleetd/src/main/java/dev/ltms/fleet/session/SessionManager.java:

drainAll(long timeoutNanos)                     :1068   returns void
  log calls inside drainAll:                     1      log.warn, "drain sweep found N session(s)…"
  log calls inside drainSnapshot:                1      log.warn, "drain failed for pane=…"
CONTROL, log.info calls anywhere in the file:    2      <- the class does log at info; these paths just don't
grep 'drain complete|drain finished|sessions released|shutdown complete' across fleetd/src/main/java
                                                 rc=1, no match

Both drain log calls are on abnormal paths. A drain that releases every session cleanly prints
nothing at all. So today the absence of a drain line is identical for "drained fine" and "died on
the first session", and there is nothing for the script to assert on.

That makes the fix two parts, in this order:

  1. Emit the line. One log.info at the end of drainAll, naming how many sessions were
    released and how many were abandoned at the deadline. This is the load-bearing half — without it
    part 2 has nothing to check.
  2. Assert its presence in the script's fresh-log region, alongside the shape grep already
    specified above. The shape grep catches the exception when it happens; the missing-line check
    catches a drain that died some other way, including one that leaves no exception at all.

Keep the shape grep. The two are not redundant: one finds a named failure, the other finds an
unnamed one.

Scope note

Part 1 is a change to SessionManager, not to the script, so it may deserve its own ticket. I am
leaving both here for now because splitting them risks the same failure #493 had — a two-item ticket
closed by the first item that produces a green run.

Related: #500 (a confident wrong conclusion is worse than silence), #479 (check the line does not
already exist before asking for it).

## Independently reproduced on fleet01, and the obvious cheaper fix does not exist **Not my measurement.** The fleet01 lead reported the block below from their own host. I have not run any of it; I cannot — the failure needs a stale host, and mine is current. I am recording it here because it is a genuinely separate instrument: systemd and journald rather than my launchd and a flat file, on Linux rather than macOS. Their numbers, from their real 2026-09-10 incident: ``` NoClassDefFoundError lines in the journal: 4 of those, lines also containing "ERROR": 0 CONTROL, journal lines that DO carry "ERROR": 8 <- the grep discriminates ERROR tokens anywhere in the whole failure block: 0 ``` That confirms the finding above from a second source. The new part is the next block: ``` PRIORITY of every uncaught-exception line: 6 (info), n=5 CONTROL, journalctl -p err on this unit: 1 line CONTROL, journalctl -p warning: 16 lines (total 4579) ``` **`journalctl -p err` misses it too.** On a systemd host, the natural fix for a missing text token is to stop grepping text and filter by severity instead. That is equally blind here, because the lines are recorded at priority 6. Their stated mechanism: on that host the daemon's fd 1 and fd 2 are the same socket (`socket:[2503995569]` for both). The stdout/stderr split is gone before journald sees anything, so everything lands at the unit's default level. There is no severity channel to consult. I have not checked this myself. So three channels report one event, and all three are reassuring: | channel | what it says | |---|---| | exit code | `status=143` — that is 128+15, identical to a clean SIGTERM | | log text | no `ERROR` token, so "no ERROR lines since restart" is true | | log priority | 6, so a severity filter returns nothing | The consequence for this ticket: **the cheap fix is not available.** Switching the scan from a text grep to a severity filter would look like the tidier change and would buy nothing on a systemd host. Keep the fix as written above — grep the shape (`^Exception in thread`, `NoClassDefFoundError`), not the level. ## A stronger fix, and I checked that the line it needs does not already exist The peer's suggestion, which I think is right: the honest check is not a negative one at all. A negative check over a channel that cannot carry the failure is vacuous by construction. What the script should look for is a **positive assertion that the shutdown drain completed** — a "drain complete, N sessions released" line — and the alert should fire on its **absence**. I measured whether such a line exists today, because I have already filed one ticket asking for a log line that was there all along (#479). It does not exist. In `fleetd/src/main/java/dev/ltms/fleet/session/SessionManager.java`: ``` drainAll(long timeoutNanos) :1068 returns void log calls inside drainAll: 1 log.warn, "drain sweep found N session(s)…" log calls inside drainSnapshot: 1 log.warn, "drain failed for pane=…" CONTROL, log.info calls anywhere in the file: 2 <- the class does log at info; these paths just don't grep 'drain complete|drain finished|sessions released|shutdown complete' across fleetd/src/main/java rc=1, no match ``` Both drain log calls are on abnormal paths. **A drain that releases every session cleanly prints nothing at all.** So today the absence of a drain line is identical for "drained fine" and "died on the first session", and there is nothing for the script to assert on. That makes the fix two parts, in this order: 1. **Emit the line.** One `log.info` at the end of `drainAll`, naming how many sessions were released and how many were abandoned at the deadline. This is the load-bearing half — without it part 2 has nothing to check. 2. **Assert its presence** in the script's fresh-log region, alongside the shape grep already specified above. The shape grep catches the exception when it happens; the missing-line check catches a drain that died some other way, including one that leaves no exception at all. Keep the shape grep. The two are not redundant: one finds a named failure, the other finds an unnamed one. ## Scope note Part 1 is a change to `SessionManager`, not to the script, so it may deserve its own ticket. I am leaving both here for now because splitting them risks the same failure #493 had — a two-item ticket closed by the first item that produces a green run. Related: #500 (a confident wrong conclusion is worse than silence), #479 (check the line does not already exist before asking for it).
ltms commented 2026-09-12 06:23:33 +02:00
Author
Owner
Copy Link
Copy Source

Merge constraint on part 1: the completion line must NOT be in a finally block

This is an explicit non-goal, raised by the fleet01 lead, and I am recording it as a merge gate
rather than a suggestion because it is the obvious review comment and it destroys the thing being
built.

The tempting review note is "shouldn't we always log the drain result?". Putting the line in a
finally does exactly that, and it costs both halves of the fix at once:

  • the line now prints after a drain that threw, so the absence signal is gone — the very signal
    part 2 is meant to alert on,
  • and it prints whatever partial counts it happened to have, so you gain a confident wrong number
    in the same edit.

That is the #494 family created by a reviewer trying to be thorough. The line has to be the last
statement of the successful path, reachable only from it.

Second, smaller constraint: derive released and abandoned incrementally as the drain proceeds,
not from a collection read at the end. If a partial report is ever wanted it must be a different line
with a different verb. One line must not serve both "this drain finished" and "this is how far it
got".

I will check both of these against the diff before merging, not take them from the worker's report.

Why part 1 is worth more than the one incident suggests

The peer's framing, which I think belongs on the ticket: we only know that drain died because it
threw. A NoClassDefFoundError reached the JVM's uncaught-exception handler and left a stack trace.
Had the same drain hung on one session, or returned early on a condition rather than an exception,
there would be:

  • no stack trace,
  • no ERROR token,
  • no priority above 6,
  • and no missing line either — because there is no line to miss.

So the one incident we have is the loud variant of a fault class whose quiet variants are currently
undetectable. Part 1 is not detection for the incident that already happened; it is detection for
the ones that would leave nothing at all.

## Merge constraint on part 1: the completion line must NOT be in a `finally` block This is an explicit **non-goal**, raised by the fleet01 lead, and I am recording it as a merge gate rather than a suggestion because it is the obvious review comment and it destroys the thing being built. The tempting review note is *"shouldn't we always log the drain result?"*. Putting the line in a `finally` does exactly that, and it costs both halves of the fix at once: - the line now prints after a drain that **threw**, so the absence signal is gone — the very signal part 2 is meant to alert on, - and it prints whatever partial counts it happened to have, so you gain a **confident wrong number** in the same edit. That is the #494 family created by a reviewer trying to be thorough. The line has to be the last statement of the successful path, reachable only from it. Second, smaller constraint: derive `released` and `abandoned` **incrementally as the drain proceeds**, not from a collection read at the end. If a partial report is ever wanted it must be a different line with a different verb. One line must not serve both "this drain finished" and "this is how far it got". I will check both of these against the diff before merging, not take them from the worker's report. ## Why part 1 is worth more than the one incident suggests The peer's framing, which I think belongs on the ticket: **we only know that drain died because it threw.** A `NoClassDefFoundError` reached the JVM's uncaught-exception handler and left a stack trace. Had the same drain hung on one session, or returned early on a condition rather than an exception, there would be: - no stack trace, - no `ERROR` token, - no priority above 6, - and no missing line either — because there is no line to miss. So the one incident we have is the **loud variant of a fault class whose quiet variants are currently undetectable**. Part 1 is not detection for the incident that already happened; it is detection for the ones that would leave nothing at all.
ltms commented 2026-09-12 06:35:55 +02:00
Author
Owner
Copy Link
Copy Source

Part 1 is merged (#522). Part 2 is now unblocked.

The line is live on main:

drain complete: released={N} abandoned={M} (still BUSY at the shutdown deadline)

Grep pattern for part 2 to anchor on:

grep -c 'drain complete: released=' "$FRESH_LOG"

Both merge constraints from my earlier comment were checked against the diff and hold: the line is the
last statement of drainAll's normal path and is not in a finally (the only finally in the file is
at :372, unrelated), and the counts are incremented inside the drainSnapshot loop rather than read
from a collection at the end.

Verified by me, not taken from the report: build exit 0,
Tests run: 1698, Failures: 0, Errors: 0, Skipped: 0, which is +2 on main's 1696. Deleting the
completion line makes both new tests fail by name with "no drain-complete INFO logged"; restored
byte-identical to d21ecd3adb3f66933e2f248a8ec81a2c324bfee323a3cc30da525842c33ea80a.

Part 2 was held because #517's worker was editing scripts/redeploy-fleetd.sh. That merged (#520)
and the worker is torn down, so the script is free. Part 2 is now the only open item on this ticket:
assert the line's presence in the script's FRESH_LOG region, alongside the shape grep
(^Exception in thread, NoClassDefFoundError) already specified in the ticket body. Keep both — one
finds a named failure, the other finds an unnamed one.

One sequencing note for whoever takes part 2: #521 is also open against the same script and
extracts another decision out of the main flow. Either do them in one unit or land #521 first; two
workers in scripts/redeploy-fleetd.sh at once is a conflict I have already avoided once on this
ticket.

An open semantic question in the new line, deliberately not changed

released++ fires on every loop iteration that did not throw, including the case where
registry.remove(paneId) returned null — a session that another thread removed between the
roster() snapshot and the release. releaseRemoved guards that case with if (removed != null), so
it is an anticipated path, not a theoretical one. draining.set(true) blocks new acquire calls but
does not block removals.

I am not filing this as a defect, because the honest reading is genuinely ambiguous:

  • read as "this drain removed N sessions from the registry", the count can be one too high,
  • read as "this drain made N sessions gone", it is correct — they are gone, just not by this loop.

The drain's contract is closer to the second. And the property the ticket actually needs — the line is
present if and only if the drain finished — is unaffected either way.

Recording it so the meaning is on the record, and so nobody "fixes" it in either direction without
deciding which reading they want. If part 2's check ever grows from presence to comparing the count
against an expected roster size, this becomes load-bearing and needs settling first.

Other silent-on-success teardown paths in the same class

Reported by the #522 worker, in scope for a sweep but not for this ticket. Not yet verified by me:

  • reapIdle — per-session success is log.debug only, and its int return (total reaped) is
    never logged by its only caller, SessionReaper.loop(). So a normal reap sweep, 0 or N, produces no
    line at INFO or above. That is the same defect this ticket just fixed, on a different path.
  • releaseRemoved's ordinary-cause path — every plain release is log.debug, while the abnormal
    branches next to it (dirty worktree, remove failure) are warn. Narrower, because it is per-session
    rather than an aggregate, but the same asymmetry.

The reapIdle one matters more than it looks: the idle reaper is what silently destroys a member's
report after idleTtlSeconds, and today a sweep that reaped a session leaves no INFO-level trace of
having done so.

One more follow-up, filed separately

While checking the new tests I found that a pre-existing test pins the shared SessionManager logger
to WARN and never restores it, so any later test asserting an INFO line silently sees nothing. The
#522 worker hit exactly that and worked around it locally. Filed as #525 — it is a sixth mechanism
in the vacuous-test family, and the only one a reviewer of the new test cannot catch by reading the new
test.

## Part 1 is merged (#522). Part 2 is now unblocked. The line is live on `main`: ``` drain complete: released={N} abandoned={M} (still BUSY at the shutdown deadline) ``` Grep pattern for part 2 to anchor on: ``` grep -c 'drain complete: released=' "$FRESH_LOG" ``` Both merge constraints from my earlier comment were checked against the diff and hold: the line is the last statement of `drainAll`'s normal path and is not in a `finally` (the only `finally` in the file is at `:372`, unrelated), and the counts are incremented inside the `drainSnapshot` loop rather than read from a collection at the end. Verified by me, not taken from the report: build exit 0, `Tests run: 1698, Failures: 0, Errors: 0, Skipped: 0`, which is +2 on `main`'s 1696. Deleting the completion line makes both new tests fail by name with "no drain-complete INFO logged"; restored byte-identical to `d21ecd3adb3f66933e2f248a8ec81a2c324bfee323a3cc30da525842c33ea80a`. **Part 2 was held because #517's worker was editing `scripts/redeploy-fleetd.sh`. That merged (#520) and the worker is torn down, so the script is free.** Part 2 is now the only open item on this ticket: assert the line's presence in the script's `FRESH_LOG` region, alongside the shape grep (`^Exception in thread`, `NoClassDefFoundError`) already specified in the ticket body. Keep both — one finds a named failure, the other finds an unnamed one. One sequencing note for whoever takes part 2: **#521 is also open against the same script** and extracts another decision out of the main flow. Either do them in one unit or land #521 first; two workers in `scripts/redeploy-fleetd.sh` at once is a conflict I have already avoided once on this ticket. ## An open semantic question in the new line, deliberately not changed `released++` fires on every loop iteration that did not throw, including the case where `registry.remove(paneId)` returned `null` — a session that another thread removed between the `roster()` snapshot and the release. `releaseRemoved` guards that case with `if (removed != null)`, so it is an anticipated path, not a theoretical one. `draining.set(true)` blocks new `acquire` calls but does not block removals. I am **not** filing this as a defect, because the honest reading is genuinely ambiguous: - read as "this drain removed N sessions from the registry", the count can be one too high, - read as "this drain made N sessions gone", it is correct — they are gone, just not by this loop. The drain's contract is closer to the second. And the property the ticket actually needs — the line is present if and only if the drain finished — is unaffected either way. Recording it so the meaning is on the record, and so nobody "fixes" it in either direction without deciding which reading they want. If part 2's check ever grows from presence to comparing the count against an expected roster size, this becomes load-bearing and needs settling first. ## Other silent-on-success teardown paths in the same class Reported by the #522 worker, in scope for a sweep but not for this ticket. Not yet verified by me: - **`reapIdle`** — per-session success is `log.debug` only, and its `int` return (total reaped) is never logged by its only caller, `SessionReaper.loop()`. So a normal reap sweep, 0 or N, produces no line at INFO or above. That is the same defect this ticket just fixed, on a different path. - **`releaseRemoved`'s ordinary-cause path** — every plain release is `log.debug`, while the abnormal branches next to it (dirty worktree, remove failure) are `warn`. Narrower, because it is per-session rather than an aggregate, but the same asymmetry. The `reapIdle` one matters more than it looks: the idle reaper is what silently destroys a member's report after `idleTtlSeconds`, and today a sweep that reaped a session leaves no INFO-level trace of having done so. ## One more follow-up, filed separately While checking the new tests I found that a pre-existing test pins the shared `SessionManager` logger to `WARN` and never restores it, so any later test asserting an INFO line silently sees nothing. The #522 worker hit exactly that and worked around it locally. Filed as **#525** — it is a sixth mechanism in the vacuous-test family, and the only one a reviewer of the new test cannot catch by reading the new test.
ltms commented 2026-09-12 08:05:37 +02:00
Author
Owner
Copy Link
Copy Source

Done, in two parts. Part 1 was #522 (the drain complete: released=N abandoned=M line in SessionManager.drainAll), merged earlier. Part 2 is #534, merged to main as 7d71194.

Part 1 had to come first, and the reason is the most useful thing this ticket produced. I wrote the fix above as a purely negative check — grep the shutdown window for the exception shape. The fleet01 lead pointed out that a negative check over a channel that cannot carry the failure is vacuous by construction, and when I went to add the absence alarm they proposed, there was no line to alarm on: the log was byte-identical for a drain that released everything and a drain that died on its first session, because neither printed anything. The absence I wanted to alert on was the normal case. So the signal had to be created before it could be checked.

Acceptance, item by item

  1. Fixture with an uncaught exception and no ERROR token — present, and it is the heart of the new tests. scan_uncaught_exceptions greps for Exception in thread / NoClassDefFoundError, kept separate from classify_amqp_connection_errors as asked.
  2. Clean control fixture — present, still reports clean.
  3. Mutation proof per test — the worker ran five; I ran two more of my own, below.
  4. Never ran the script against the live daemon — confirmed, by the worker and by me. Both of us tested by sourcing it against fixture files, which is what the suite already does.

The exit-code decision went the way I proposed: warn loudly, never die(). By the time this is detectable the new daemon is already up, and failing the script would give the operator nothing to do differently.

What the detection actually reports now

Four outcomes, from report_shutdown_drain:

  • complete — #522's line is present; name the counts.
  • died — line absent and the exception shape found; name what was found and say sessions from the previous daemon may not have been released.
  • unknown — line absent and no exception shape either. Explicitly not a pass and not a failure: either that daemon predates #522, or its drain failed without throwing (hung, or returned early).
  • n/a — no previous daemon was stopped this run, so there is no shutdown window to have an opinion about.

no ERROR lines since restart now prints only on complete or n/a.

The third state was the point, and I mutated it to check

unknown exists because absence has two causes needing opposite handling, which is the sentinel-conflation shape. A third state is only worth having if something breaks when it collapses, so I collapsed it: changed the else branch to set complete, so "cannot tell" reports as a pass. Result exit 1, one FAIL — cannot-tell fixture must set REDEPLOY_DRAIN_STATE=unknown: expected unknown, got complete. Load-bearing, not decoration.

Second mutation of mine, on the positive half: changed find_drain_complete_line's pattern from drain complete: released= to drain finished: released=, one site. Exit 1, one FAIL — find_drain_complete_line did not capture the present line. Proof it applied, against a pristine copy: the full grep line 1 → 0, the mutant form 0 → 1, bare phrase 2 → 1 with the comment occurrence untouched. Restored byte-identical, green control re-run.

Both of mine were deliberately ones the worker had not run.

The fourth state, which the worker added and flagged rather than quietly keeping

n/a is not in my three-state wording. Accepted, and it belongs. "The question does not apply" is a third cause of absence, not a variant of "cannot tell". Without it the new warning would fire on every clean cold start, and a warning that cries wolf on the most common path trains the operator to skip it — destroying the absence signal just as surely as putting #522's completion line in a finally would have. Same defect, arrived at from the other end.

The worker also proved the gate is consulted, with a cold-start fixture whose content deliberately looks like a died drain. That is the right way to test a gate: make the fixture such that skipping the gate gives the wrong answer.

Verified on the merged tree, not the branch

The branch was based on 8335b12 while main had moved to bec87f9, so I merged locally and tested the result. Suite exit 0, 0 lines matching ^FAIL:, 60 test functions defined and 60 invoked — checked with a comm against the invocation list rather than by comparing two counts, since two equal counts can both be wrong. bash -n exit 0 on both scripts under /bin/bash 3.2.57 and env bash 5.3.9.

One untested line I found, reported not fixed

The main flow's HAD_OLD_PID=0; [ -n "$OLD_PID" ] && HAD_OLD_PID=1 runs under set -euo pipefail, and on a cold start that test fails. Sourcing stops before the main flow, so no behavioural test reaches the line. If set -e fired there, every cold start would abort before the health checks ever ran.

It does not fire — set -e exempts the left side of an && list — and I confirmed that by running it under both shells rather than reasoning about the manual: survived, HAD_OLD_PID=0 on 3.2.57 and on 5.3.9. Safe, but it is untested main-flow wiring, the same class as #528's item 1, and it goes on that list rather than being called covered.

Also in this verification, a mistake of mine worth recording

My first proof cell for mutation B used escaped double quotes inside an already double-quoted command substitution, so the shell split the pattern on spaces and grep read the words as filenames. It printed a symmetric "2 and 2" next to ugrep: No such file or directory warnings. The kill was never in doubt — the suite named the exact function — but the cell whose entire job was to prove the mutation had applied proved nothing, and it failed in the plausible direction. This is the already-written-down double-quote trap, hit inside the guard against it.

Closing. #511 remains open for the other two redeploy-fleetd.sh defects.

Done, in two parts. Part 1 was #522 (the `drain complete: released=N abandoned=M` line in `SessionManager.drainAll`), merged earlier. Part 2 is #534, merged to main as `7d71194`. Part 1 had to come first, and the reason is the most useful thing this ticket produced. I wrote the fix above as a purely negative check — grep the shutdown window for the exception shape. The fleet01 lead pointed out that a negative check over a channel that cannot carry the failure is vacuous by construction, and when I went to add the absence alarm they proposed, there was no line to alarm on: the log was byte-identical for a drain that released everything and a drain that died on its first session, because neither printed anything. **The absence I wanted to alert on was the normal case.** So the signal had to be created before it could be checked. ## Acceptance, item by item 1. **Fixture with an uncaught exception and no ERROR token** — present, and it is the heart of the new tests. `scan_uncaught_exceptions` greps for `Exception in thread` / `NoClassDefFoundError`, kept separate from `classify_amqp_connection_errors` as asked. 2. **Clean control fixture** — present, still reports clean. 3. **Mutation proof per test** — the worker ran five; I ran two more of my own, below. 4. **Never ran the script against the live daemon** — confirmed, by the worker and by me. Both of us tested by sourcing it against fixture files, which is what the suite already does. The exit-code decision went the way I proposed: warn loudly, never `die()`. By the time this is detectable the new daemon is already up, and failing the script would give the operator nothing to do differently. ## What the detection actually reports now Four outcomes, from `report_shutdown_drain`: - `complete` — #522's line is present; name the counts. - `died` — line absent **and** the exception shape found; name what was found and say sessions from the previous daemon may not have been released. - `unknown` — line absent and no exception shape either. Explicitly **not a pass and not a failure**: either that daemon predates #522, or its drain failed without throwing (hung, or returned early). - `n/a` — no previous daemon was stopped this run, so there is no shutdown window to have an opinion about. `no ERROR lines since restart` now prints only on `complete` or `n/a`. ## The third state was the point, and I mutated it to check `unknown` exists because absence has two causes needing opposite handling, which is the sentinel-conflation shape. A third state is only worth having if something breaks when it collapses, so I collapsed it: changed the `else` branch to set `complete`, so "cannot tell" reports as a pass. Result exit 1, one FAIL — `cannot-tell fixture must set REDEPLOY_DRAIN_STATE=unknown: expected unknown, got complete`. Load-bearing, not decoration. Second mutation of mine, on the positive half: changed `find_drain_complete_line`'s pattern from `drain complete: released=` to `drain finished: released=`, one site. Exit 1, one FAIL — `find_drain_complete_line did not capture the present line`. Proof it applied, against a pristine copy: the full grep line 1 → 0, the mutant form 0 → 1, bare phrase 2 → 1 with the comment occurrence untouched. Restored byte-identical, green control re-run. Both of mine were deliberately ones the worker had not run. ## The fourth state, which the worker added and flagged rather than quietly keeping `n/a` is not in my three-state wording. Accepted, and it belongs. "The question does not apply" is a third cause of absence, not a variant of "cannot tell". Without it the new warning would fire on every clean cold start, and a warning that cries wolf on the most common path trains the operator to skip it — destroying the absence signal just as surely as putting #522's completion line in a `finally` would have. Same defect, arrived at from the other end. The worker also proved the gate is consulted, with a cold-start fixture whose content deliberately looks like a died drain. That is the right way to test a gate: make the fixture such that skipping the gate gives the wrong answer. ## Verified on the merged tree, not the branch The branch was based on `8335b12` while main had moved to `bec87f9`, so I merged locally and tested the result. Suite exit 0, 0 lines matching `^FAIL:`, 60 test functions defined and 60 invoked — checked with a `comm` against the invocation list rather than by comparing two counts, since two equal counts can both be wrong. `bash -n` exit 0 on both scripts under /bin/bash 3.2.57 and env bash 5.3.9. ## One untested line I found, reported not fixed The main flow's `HAD_OLD_PID=0; [ -n "$OLD_PID" ] && HAD_OLD_PID=1` runs under `set -euo pipefail`, and on a cold start that test fails. Sourcing stops before the main flow, so no behavioural test reaches the line. If `set -e` fired there, every cold start would abort before the health checks ever ran. It does not fire — `set -e` exempts the left side of an `&&` list — and I confirmed that by running it under both shells rather than reasoning about the manual: `survived, HAD_OLD_PID=0` on 3.2.57 and on 5.3.9. Safe, but it is untested main-flow wiring, the same class as #528's item 1, and it goes on that list rather than being called covered. ## Also in this verification, a mistake of mine worth recording My first proof cell for mutation B used escaped double quotes inside an already double-quoted command substitution, so the shell split the pattern on spaces and grep read the words as filenames. It printed a symmetric "2 and 2" next to `ugrep: No such file or directory` warnings. The kill was never in doubt — the suite named the exact function — but the cell whose entire job was to prove the mutation had applied proved nothing, and it failed in the plausible direction. This is the already-written-down double-quote trap, hit inside the guard against it. Closing. #511 remains open for the other two `redeploy-fleetd.sh` defects.
ltms closed this issue 2026-09-12 08:05:43 +02:00
ltms commented 2026-09-12 08:35:20 +02:00
Author
Owner
Copy Link
Copy Source

The unknown arm is self-clearing, so its test is load-bearing, not illustrative

Reopening the reasoning, not the ticket. This is the fleet01 lead's argument and it corrects something I wrote when closing.

What I got wrong. I recorded that the detection "validated itself in the field on its first real run" — it reported unknown / "cannot tell" on the first redeploy after the change, correctly, because the replaced daemon started 11:12:15 on a jar built 11:12:13 while #522's drain line only landed at 11:29:01. I offered that as evidence the three-state design was right.

It is not. It is evidence about the base rate of the third state — it says the cannot-tell condition was common enough to appear on run one. That is a fact about deployments, not about the design. The design argument stands on its own and never needed the run.

The consequence, which is the part that matters. That condition clears itself. The unknown fired because the daemon being replaced predated #522's line. After that deploy, every daemon a future check replaces carries the line. So production will never reach the unknown arm again on this path. It fired exactly once, at the only moment it could, and from here it is silent permanently.

Which means the mutation test covering the third state is not a nicety. It is the entire remaining coverage of that branch. And a branch that has gone quiet forever is indistinguishable from a branch that has broken: if the unknown arm rots, nothing in production will ever say so, because nothing in production will ever execute it.

So, stated plainly for whoever reads this next: the cannot-tell fixture in test-redeploy-fleetd.sh is load-bearing, not illustrative. Do not delete it on the grounds that the state it covers "cannot happen any more". That it cannot happen any more in production is precisely why the test is the only thing left holding it.

This generalises past this ticket. A state that a system has grown out of still has code, and that code still has to be right on the day something puts the system back into it — a rollback, a host that missed a deploy, a second fleet on an older jar. The test is the only instrument left pointed at it.

Related: #497 (the third state itself), #522 (the drain line whose arrival is what makes the condition self-clearing).

## The `unknown` arm is self-clearing, so its test is load-bearing, not illustrative Reopening the reasoning, not the ticket. This is the fleet01 lead's argument and it corrects something I wrote when closing. **What I got wrong.** I recorded that the detection "validated itself in the field on its first real run" — it reported `unknown` / "cannot tell" on the first redeploy after the change, correctly, because the replaced daemon started 11:12:15 on a jar built 11:12:13 while #522's drain line only landed at 11:29:01. I offered that as evidence the three-state design was right. It is not. It is evidence about the **base rate** of the third state — it says the cannot-tell condition was common enough to appear on run one. That is a fact about deployments, not about the design. The design argument stands on its own and never needed the run. **The consequence, which is the part that matters.** That condition clears itself. The `unknown` fired because the daemon being replaced predated #522's line. After that deploy, every daemon a future check replaces carries the line. So **production will never reach the `unknown` arm again on this path.** It fired exactly once, at the only moment it could, and from here it is silent permanently. Which means the mutation test covering the third state is not a nicety. It is the **entire remaining coverage of that branch**. And a branch that has gone quiet forever is indistinguishable from a branch that has broken: if the `unknown` arm rots, nothing in production will ever say so, because nothing in production will ever execute it. **So, stated plainly for whoever reads this next:** the cannot-tell fixture in `test-redeploy-fleetd.sh` is **load-bearing, not illustrative.** Do not delete it on the grounds that the state it covers "cannot happen any more". That it cannot happen any more in production is precisely why the test is the only thing left holding it. This generalises past this ticket. A state that a system has grown out of still has code, and that code still has to be right on the day something puts the system back into it — a rollback, a host that missed a deploy, a second fleet on an older jar. The test is the only instrument left pointed at it. Related: #497 (the third state itself), #522 (the drain line whose arrival is what makes the condition self-clearing).
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
Labels
Clear labels
blocked
Cannot start until something else lands. The body says what.
 needs-live-proof
Merged and green, but never shown working on the running daemon. Not the same as done.
 ready-to-delegate
Scope, files and acceptance criteria are written. A worker can be briefed from the body alone.
 silent-default
A feature that compiles, passes tests, and ships turned off. Nine recurrences and counting.
No Label
Milestone
No items
No Milestone
Projects
Clear projects
No project
Assignees
Clear assignees
agent kevin ltms
No Assignees
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: fleet/fleetd#512
Delete Branch "%!s()"

Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?