Merge #354: the redeploy health gate classifies AMQP errors instead of counting them
CI / contract (push) Successful in 1m14s
CI / build (push) Successful in 1m36s

The gate counted ERROR lines since RESTART_MARK. On a laptop that idle-sleeps after one
minute on battery that meant 6 ERROR lines for an AMQP link that recovered every time,
and a gate that cries wolf is a gate nobody reads.

It now reports three states: no errors; only errors proven to have recovered (quiet, and
the gate passes); anything else (the old warning, unchanged). Attribution is per
connection, using the names #356 put into the log -- a lead-mailbox recovery can no
longer clear an unrecovered reply-inbox reset. A candidate carrying neither name is
unattributable and stays LOUD.

Two earlier rounds were rejected. Round 1 was inert: it matched nothing in the real log,
because the layout abbreviates the logger and 'Connection reset' sits in the stack trace,
not on the ERROR line -- my brief had pointed the worker at fleetd.out, which is untracked
and so absent from its worktree. Round 2 was correct and honest but could not attribute
anything, which is what motivated #356.

Verified on merge beyond the worker's own mutations:
 - ran the classifier against the REAL log, which is still in the pre-#356 format: 6 total,
   0 recovered, 6 unexplained. Old-format lines carry no connection name, so they stay loud
   -- the safe direction, on genuine data rather than a fixture.
 - adversarial fixture the worker did not write: a lead recovery BEFORE any failure banks
   no credit; 2 inbox resets with 1 recovery leaves 1 unexplained; a non-AMQP ERROR stays
   loud. total=3 recovered=1 unexplained=2, as intended.
 - RESTART_MARK still anchors the scanned region.

Caveat carried from the PR: the patterns are source-derived. The daemon has not been
redeployed, so they are not yet confirmed against a live log.
This commit is contained in:
Dai Ha
2026-09-05 06:09:29 +07:00
2 changed files with 294 additions and 6 deletions
+56 -6
View File
@@ -116,6 +116,50 @@ check_log_path_matches_plist() {
ok "log path check: script and plist agree ($resolved_out)"
}
# Classify ERROR lines in one fresh log region. AMQP failure messages now include the connection
# name, so a recovery can clear only errors for its own connection. A candidate with neither name
# remains unexplained: it must never be quieted by a recovery on the other connection.
classify_amqp_connection_errors() {
local log_file="$1" line pending_inbox=0 pending_lead_mailbox=0
REDEPLOY_ERROR_COUNT=0
REDEPLOY_RECOVERED_AMQP_ERRORS=0
REDEPLOY_UNEXPLAINED_ERRORS=0
while IFS= read -r line || [ -n "$line" ]; do
case "$line" in
*' ERROR '*|*' SEVERE '*)
REDEPLOY_ERROR_COUNT=$((REDEPLOY_ERROR_COUNT + 1))
case "$line" in
*'AMQP connection fleetd-reply-inbox: An unexpected connection driver error occurred'*|*'AMQP connection fleetd-reply-inbox: Caught an exception during connection recovery!'*)
pending_inbox=$((pending_inbox + 1))
;;
*'AMQP connection fleetd-lead-mailbox: An unexpected connection driver error occurred'*|*'AMQP connection fleetd-lead-mailbox: Caught an exception during connection recovery!'*)
pending_lead_mailbox=$((pending_lead_mailbox + 1))
;;
*'AMQP connection'*'An unexpected connection driver error occurred'*|*'AMQP connection'*'Caught an exception during connection recovery!'*)
REDEPLOY_UNEXPLAINED_ERRORS=$((REDEPLOY_UNEXPLAINED_ERRORS + 1))
;;
*) REDEPLOY_UNEXPLAINED_ERRORS=$((REDEPLOY_UNEXPLAINED_ERRORS + 1)) ;;
esac
;;
*'AMQP connection recovered; cleared held replies for fresh redelivery'*)
if [ "$pending_inbox" -gt 0 ]; then
pending_inbox=$((pending_inbox - 1))
REDEPLOY_RECOVERED_AMQP_ERRORS=$((REDEPLOY_RECOVERED_AMQP_ERRORS + 1))
fi
;;
*'AMQP lead mailbox connection recovered; cleared held messages for fresh redelivery'*)
if [ "$pending_lead_mailbox" -gt 0 ]; then
pending_lead_mailbox=$((pending_lead_mailbox - 1))
REDEPLOY_RECOVERED_AMQP_ERRORS=$((REDEPLOY_RECOVERED_AMQP_ERRORS + 1))
fi
;;
esac
done < "$log_file"
REDEPLOY_UNEXPLAINED_ERRORS=$((REDEPLOY_UNEXPLAINED_ERRORS + pending_inbox + pending_lead_mailbox))
}
# CB-600: sourceable for testing. When this file is SOURCED (not executed) it stops here — nothing
# below runs — so a test harness can `source` it to call check_log_path_matches_plist (or the
# other pure helpers above) against a throwaway plist fixture without ever reaching the mutating
@@ -361,15 +405,21 @@ tail -n "+$((RESTART_MARK + 1))" "$OUT" 2>/dev/null \
| grep -iE 'deferred|classification:|fleet health:|coverage' | tail -8 | sed 's/^/ /' \
|| echo " (nothing reported)"
# Errors since the restart, anchored to the marker so old noise cannot leak in.
ERRS="$(tail -n "+$((RESTART_MARK + 1))" "$OUT" 2>/dev/null | grep -cE ' (ERROR|SEVERE) ' || true)"
# Errors since the restart, anchored to the marker so old noise cannot leak in. Keep the fresh
# region in a file because the classifier must preserve the order of errors and recoveries.
FRESH_LOG="$(mktemp -t fleetd-fresh-log)"
trap 'rm -f "$FRESH_LOG"' EXIT
tail -n "+$((RESTART_MARK + 1))" "$OUT" > "$FRESH_LOG" 2>/dev/null || true
classify_amqp_connection_errors "$FRESH_LOG"
say "result"
ok "pid $NEW_PID, jar $(jar_id)"
if [ "${ERRS:-0}" -gt 0 ]; then
warn "$ERRS ERROR lines since restart:"
tail -n "+$((RESTART_MARK + 1))" "$OUT" | grep -E ' (ERROR|SEVERE) ' | tail -5 | sed 's/^/ /'
else
if [ "$REDEPLOY_ERROR_COUNT" -eq 0 ]; then
ok "no ERROR lines since restart"
elif [ "$REDEPLOY_UNEXPLAINED_ERRORS" -eq 0 ]; then
ok "$REDEPLOY_RECOVERED_AMQP_ERRORS AMQP connection reset ERROR lines recovered since restart"
else
warn "$REDEPLOY_ERROR_COUNT ERROR lines since restart:"
grep -E ' (ERROR|SEVERE) ' "$FRESH_LOG" | tail -5 | sed 's/^/ /'
fi
echo
echo " Next: call fleet_whoami and confirm it still answers 'primary'. A lead whose tab label"
+238
View File
@@ -0,0 +1,238 @@
#!/usr/bin/env bash
# Self-contained checks for the pure log classifier in redeploy-fleetd.sh.
set -euo pipefail
ROOT="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)"
TMP="$(mktemp -d "$ROOT/.redeploy-log-test.XXXXXX")"
trap 'rm -rf "$TMP"' EXIT
# Sourcing stops before redeploy-fleetd.sh can build, stop, or start the daemon.
source "$ROOT/scripts/redeploy-fleetd.sh"
fail() {
printf 'FAIL: %s\n' "$*" >&2
return 1
}
assert_equals() {
local expected="$1" actual="$2" description="$3"
[ "$expected" = "$actual" ] || fail "$description: expected $expected, got $actual"
}
classify_fixture() {
local name="$1"
classify_amqp_connection_errors "$TMP/$name"
}
test_no_errors() {
cat > "$TMP/no-errors.log" <<'LOG'
2026-09-05 12:00:00 INFO fleetd listening
LOG
classify_fixture no-errors.log
assert_equals 0 "$REDEPLOY_ERROR_COUNT" "no-errors total"
assert_equals 0 "$REDEPLOY_UNEXPLAINED_ERRORS" "no-errors unexplained"
}
test_recovery_patterns_match_source() {
grep -F 'AMQP connection {}: {}' "$ROOT/fleetd/src/main/java/dev/ltms/fleet/msg/AmqpReplyInbox.java" > /dev/null \
|| fail "AMQP failure pattern no longer matches source"
grep -F 'AMQP connection recovered; cleared held replies for fresh redelivery' \
"$ROOT/fleetd/src/main/java/dev/ltms/fleet/msg/AmqpReplyInbox.java" > /dev/null \
|| fail "reply-inbox recovery pattern no longer matches source"
grep -F 'AMQP lead mailbox connection recovered; cleared held messages for fresh redelivery' \
"$ROOT/fleetd/src/main/java/dev/ltms/fleet/msg/LeadMailbox.java" > /dev/null \
|| fail "lead-mailbox recovery pattern no longer matches source"
}
test_attributed_recovered_connection_error() {
cat > "$TMP/attributed-recovered.log" <<'LOG'
2026-09-05 12:00:00 ERROR [AMQP Connection broker:5672] d.l.fleet.msg.AmqpReplyInbox - AMQP connection fleetd-reply-inbox: An unexpected connection driver error occurred
2026-09-05 12:00:01 INFO [AMQP Connection broker:5672] d.l.fleet.msg.AmqpReplyInbox - AMQP connection recovered; cleared held replies for fresh redelivery
LOG
classify_fixture attributed-recovered.log
assert_equals 1 "$REDEPLOY_ERROR_COUNT" "attributed-recovered total"
assert_equals 1 "$REDEPLOY_RECOVERED_AMQP_ERRORS" "attributed-recovered errors"
assert_equals 0 "$REDEPLOY_UNEXPLAINED_ERRORS" "attributed-recovered unexplained"
}
test_source_derived_error_shapes_recover_by_connection() {
# These ERROR shapes come from AmqpConnectionFailureLogger on main. They need a live-log check
# after redeploy because the new code has not yet written a production line.
cat > "$TMP/source-derived.log" <<'LOG'
17:37:53.537 ERROR [AMQP Connection broker:5672] d.l.fleet.msg.AmqpReplyInbox - AMQP connection fleetd-reply-inbox: An unexpected connection driver error occurred
17:37:54.537 ERROR [AMQP Connection broker:5672] d.l.fleet.msg.AmqpReplyInbox - AMQP connection fleetd-reply-inbox: Caught an exception during connection recovery!
17:37:55.537 ERROR [AMQP Connection broker:5672] d.l.fleet.msg.AmqpReplyInbox - AMQP connection fleetd-reply-inbox: An unexpected connection driver error occurred
17:37:56.537 ERROR [AMQP Connection broker:5672] d.ltms.fleet.msg.LeadMailbox - AMQP connection fleetd-lead-mailbox: An unexpected connection driver error occurred
17:37:57.537 ERROR [AMQP Connection broker:5672] d.ltms.fleet.msg.LeadMailbox - AMQP connection fleetd-lead-mailbox: Caught an exception during connection recovery!
17:37:58.537 ERROR [AMQP Connection broker:5672] d.ltms.fleet.msg.LeadMailbox - AMQP connection fleetd-lead-mailbox: An unexpected connection driver error occurred
17:38:00.000 INFO [AMQP Connection broker:5672] d.l.fleet.msg.AmqpReplyInbox - AMQP connection recovered; cleared held replies for fresh redelivery
17:38:01.000 INFO [AMQP Connection broker:5672] d.l.fleet.msg.AmqpReplyInbox - AMQP connection recovered; cleared held replies for fresh redelivery
17:38:02.000 INFO [AMQP Connection broker:5672] d.l.fleet.msg.AmqpReplyInbox - AMQP connection recovered; cleared held replies for fresh redelivery
17:38:03.000 INFO [AMQP Connection broker:5672] d.ltms.fleet.msg.LeadMailbox - AMQP lead mailbox connection recovered; cleared held messages for fresh redelivery
17:38:04.000 INFO [AMQP Connection broker:5672] d.ltms.fleet.msg.LeadMailbox - AMQP lead mailbox connection recovered; cleared held messages for fresh redelivery
17:38:05.000 INFO [AMQP Connection broker:5672] d.ltms.fleet.msg.LeadMailbox - AMQP lead mailbox connection recovered; cleared held messages for fresh redelivery
LOG
classify_fixture source-derived.log
assert_equals 6 "$REDEPLOY_ERROR_COUNT" "source-derived total"
assert_equals 6 "$REDEPLOY_RECOVERED_AMQP_ERRORS" "source-derived recovered"
assert_equals 0 "$REDEPLOY_UNEXPLAINED_ERRORS" "source-derived unexplained"
}
test_cross_connection_unattributable_errors_stay_loud() {
# This candidate has neither stable connection name, so LeadMailbox recovery must not consume it.
cat > "$TMP/cross-unattributable.log" <<'LOG'
2026-09-05 12:00:00 ERROR [AMQP Connection broker:5672] unknown - AMQP connection: An unexpected connection driver error occurred
2026-09-05 12:00:01 ERROR [AMQP Connection broker:5672] unknown - AMQP connection: An unexpected connection driver error occurred
2026-09-05 12:00:02 INFO [AMQP Connection 10.10.20.13:5672] d.ltms.fleet.msg.LeadMailbox - AMQP lead mailbox connection recovered; cleared held messages for fresh redelivery
2026-09-05 12:00:03 INFO [AMQP Connection 10.10.20.13:5672] d.ltms.fleet.msg.LeadMailbox - AMQP lead mailbox connection recovered; cleared held messages for fresh redelivery
LOG
classify_fixture cross-unattributable.log
assert_equals 2 "$REDEPLOY_ERROR_COUNT" "cross-unattributable total"
assert_equals 0 "$REDEPLOY_RECOVERED_AMQP_ERRORS" "cross-unattributable recovered"
assert_equals 2 "$REDEPLOY_UNEXPLAINED_ERRORS" "cross-unattributable unexplained"
}
test_attributed_cross_connection_errors_stay_loud() {
# LeadMailbox recovery cannot heal AmqpReplyInbox errors.
cat > "$TMP/cross-attributed.log" <<'LOG'
2026-09-05 12:00:00 ERROR AmqpReplyInbox - AMQP connection fleetd-reply-inbox: An unexpected connection driver error occurred
2026-09-05 12:00:01 ERROR AmqpReplyInbox - AMQP connection fleetd-reply-inbox: An unexpected connection driver error occurred
2026-09-05 12:00:02 INFO LeadMailbox - AMQP lead mailbox connection recovered; cleared held messages for fresh redelivery
2026-09-05 12:00:03 INFO LeadMailbox - AMQP lead mailbox connection recovered; cleared held messages for fresh redelivery
LOG
classify_fixture cross-attributed.log
assert_equals 2 "$REDEPLOY_ERROR_COUNT" "cross-attributed total"
assert_equals 0 "$REDEPLOY_RECOVERED_AMQP_ERRORS" "cross-attributed recovered"
assert_equals 2 "$REDEPLOY_UNEXPLAINED_ERRORS" "cross-attributed unexplained"
}
test_attributed_unrecovered_connection_error() {
cat > "$TMP/unrecovered.log" <<'LOG'
2026-09-05 12:00:00 ERROR AmqpReplyInbox - AMQP connection fleetd-reply-inbox: An unexpected connection driver error occurred
LOG
classify_fixture unrecovered.log
assert_equals 1 "$REDEPLOY_ERROR_COUNT" "unrecovered total"
assert_equals 0 "$REDEPLOY_RECOVERED_AMQP_ERRORS" "unrecovered AMQP errors"
assert_equals 1 "$REDEPLOY_UNEXPLAINED_ERRORS" "unrecovered unexplained"
}
test_other_error_is_unexplained() {
cat > "$TMP/other-error.log" <<'LOG'
2026-09-05 12:00:00 ERROR dev.ltms.fleet.Fleetd - startup failed
2026-09-05 12:00:01 INFO dev.ltms.fleet.msg.AmqpReplyInbox - AMQP connection recovered; cleared held replies for fresh redelivery
LOG
classify_fixture other-error.log
assert_equals 1 "$REDEPLOY_ERROR_COUNT" "other-error total"
assert_equals 1 "$REDEPLOY_UNEXPLAINED_ERRORS" "other-error unexplained"
}
test_recovery_requirement_mutation_is_caught() {
classify_amqp_connection_errors() {
local log_file="$1" line
REDEPLOY_ERROR_COUNT=0
REDEPLOY_RECOVERED_AMQP_ERRORS=0
REDEPLOY_UNEXPLAINED_ERRORS=0
while IFS= read -r line || [ -n "$line" ]; do
case "$line" in
*' ERROR '*|*' SEVERE '*)
REDEPLOY_ERROR_COUNT=$((REDEPLOY_ERROR_COUNT + 1))
case "$line" in
*'AMQP connection fleetd-reply-inbox: An unexpected connection driver error occurred'*)
REDEPLOY_RECOVERED_AMQP_ERRORS=$((REDEPLOY_RECOVERED_AMQP_ERRORS + 1))
;;
*) REDEPLOY_UNEXPLAINED_ERRORS=$((REDEPLOY_UNEXPLAINED_ERRORS + 1)) ;;
esac
;;
esac
done < "$log_file"
}
if test_attributed_unrecovered_connection_error > "$TMP/mutation-output" 2>&1; then
fail "mutation accepted an unrecovered connection error"
fi
grep -F 'FAIL: unrecovered AMQP errors: expected 0, got 1' "$TMP/mutation-output" > /dev/null \
|| fail "mutation failed without the expected assertion"
printf 'Recovery mutation: FAIL: unrecovered AMQP errors: expected 0, got 1\n'
}
test_shared_counter_mutation_is_caught() {
classify_amqp_connection_errors() {
local log_file="$1" line pending=0
REDEPLOY_ERROR_COUNT=0
REDEPLOY_RECOVERED_AMQP_ERRORS=0
REDEPLOY_UNEXPLAINED_ERRORS=0
while IFS= read -r line || [ -n "$line" ]; do
case "$line" in
*' ERROR '*|*' SEVERE '*)
REDEPLOY_ERROR_COUNT=$((REDEPLOY_ERROR_COUNT + 1))
case "$line" in
*'AMQP connection'*'An unexpected connection driver error occurred'*|*'AMQP connection'*'Caught an exception during connection recovery!'*)
case "$line" in
*'fleetd-reply-inbox'*|*'fleetd-lead-mailbox'*) pending=$((pending + 1)) ;;
*) REDEPLOY_UNEXPLAINED_ERRORS=$((REDEPLOY_UNEXPLAINED_ERRORS + 1)) ;;
esac
;;
*) REDEPLOY_UNEXPLAINED_ERRORS=$((REDEPLOY_UNEXPLAINED_ERRORS + 1)) ;;
esac
;;
*'AMQP connection recovered; cleared held replies for fresh redelivery'*|*'AMQP lead mailbox connection recovered; cleared held messages for fresh redelivery'*)
if [ "$pending" -gt 0 ]; then
pending=$((pending - 1))
REDEPLOY_RECOVERED_AMQP_ERRORS=$((REDEPLOY_RECOVERED_AMQP_ERRORS + 1))
fi
;;
esac
done < "$log_file"
REDEPLOY_UNEXPLAINED_ERRORS=$((REDEPLOY_UNEXPLAINED_ERRORS + pending))
}
if test_attributed_cross_connection_errors_stay_loud > "$TMP/shared-mutation-output" 2>&1; then
fail "shared counter mutation accepted cross-connection recovery"
fi
grep -F 'FAIL: cross-attributed recovered: expected 0, got 2' "$TMP/shared-mutation-output" > /dev/null \
|| fail "shared counter mutation failed without the expected assertion"
printf 'Shared-counter mutation: FAIL: cross-attributed recovered: expected 0, got 2\n'
}
test_unattributable_quiet_mutation_is_caught() {
classify_amqp_connection_errors() {
local log_file="$1" line
REDEPLOY_ERROR_COUNT=0
REDEPLOY_RECOVERED_AMQP_ERRORS=0
REDEPLOY_UNEXPLAINED_ERRORS=0
while IFS= read -r line || [ -n "$line" ]; do
case "$line" in
*' ERROR '*|*' SEVERE '*)
REDEPLOY_ERROR_COUNT=$((REDEPLOY_ERROR_COUNT + 1))
case "$line" in
*'AMQP connection'*'An unexpected connection driver error occurred'*|*'AMQP connection'*'Caught an exception during connection recovery!'*)
REDEPLOY_RECOVERED_AMQP_ERRORS=$((REDEPLOY_RECOVERED_AMQP_ERRORS + 1))
;;
*) REDEPLOY_UNEXPLAINED_ERRORS=$((REDEPLOY_UNEXPLAINED_ERRORS + 1)) ;;
esac
;;
esac
done < "$log_file"
}
if test_cross_connection_unattributable_errors_stay_loud > "$TMP/unattributable-mutation-output" 2>&1; then
fail "unattributable mutation accepted an unknown connection"
fi
grep -F 'FAIL: cross-unattributable recovered: expected 0, got 2' "$TMP/unattributable-mutation-output" > /dev/null \
|| fail "unattributable mutation failed without the expected assertion"
printf 'Unattributable mutation: FAIL: cross-unattributable recovered: expected 0, got 2\n'
}
test_no_errors
test_recovery_patterns_match_source
test_attributed_recovered_connection_error
test_source_derived_error_shapes_recover_by_connection
test_cross_connection_unattributable_errors_stay_loud
test_attributed_cross_connection_errors_stay_loud
test_attributed_unrecovered_connection_error
test_other_error_is_unexplained
test_recovery_requirement_mutation_is_caught
test_shared_counter_mutation_is_caught
test_unattributable_quiet_mutation_is_caught
printf 'PASS: redeploy log classifier\n'