obs(ha-term-safety): promote committed_lsn advance to INFO + harness polls authoritative commit signal

The commit-engine committed_lsn advance was TRACE-only; promoted to INFO (fires only
on a real advance, not noisy) so operators/tests can observe the authoritative primary
committed watermark. The clean-failover harness now polls this 'commit: committed_lsn
N -> M' line (not the lagging ha_process_standby_state heartbeat) with generous catch-up
headroom.

This made the live RED->GREEN visible: with Option A, committed_lsn reaches 5 on a
stable cluster ('jobs committed on a majority (committed_lsn=5 >= 5)') even via catch-up
delivery — the commit-stall is fixed.
This commit is contained in:
Rongsong Shen 2026-06-23 00:28:14 +00:00
parent 83fbed2370
commit 9e5e293605
2 changed files with 18 additions and 8 deletions

View file

@ -181,8 +181,13 @@ static void commit_advance_locked(commit_engine_t* ce)
#endif
atomic_store(&ce->p->committed_lsn, cand);
TRACE("commit: committed_lsn %lu -> %lu (n_peers=%d)", cur, cand,
ce->n_peers);
/* INFO (not TRACE): the authoritative primary committed_lsn advance. Fires
* only on a real advance (monotonic guard above), so it is not noisy, and it
* is the canonical operator/test signal for the committed watermark — the
* standby-reported committed_lsn in ha_process_standby_state heartbeats lags
* and only logs on the one-time converged transition. */
INFO("commit: committed_lsn %lu -> %lu (n_peers=%d)", cur, cand,
ce->n_peers);
pthread_cond_broadcast(&ce->cond);
}

View file

@ -202,16 +202,21 @@ log "primary is $PRIMARY"
# job entries on the new primary's promotion-truncate (correct Raft, NOT a job
# loss) — making the "no committed-job lost" assertion a race (it passed/failed
# nondeterministically on whether replication won the race with the kill). The
# primary logs each standby's learned committed_lsn via ha_process_standby_state;
# require it to reach the committed boundary (own-term noop LSN 1 + the committed
# JOB_SUBMIT entries; bug-845 doubles each submit => 1 + 2*N_JOBS).
# Poll the PRIMARY's AUTHORITATIVE committed_lsn — the commit-engine INFO line
# `commit: committed_lsn N -> M` (commit.c), which fires on every real advance.
# (Do NOT grep the ha_process_standby_state `committed_lsn=N` heartbeat line: that
# is the standby's *learned* committed_lsn, which lags and only logs on the
# one-time converged transition — a misleading signal.) Boundary = own-term noop
# LSN 1 + the committed JOB_SUBMIT entries; bug-845 doubles each submit => 1 + 2*N_JOBS.
COMMITTED_BOUNDARY="${XCE_FAILOVER_COMMITTED:-$((1 + 2 * N_JOBS))}"
COMMIT_WAIT_S="${XCE_FAILOVER_COMMIT_WAIT_S:-40}"
# Catch-up of N entries with per-entry fdatasync can be slow on a loaded box;
# allow generous headroom (committed advances once the catch-up streamer + ACKs land).
COMMIT_WAIT_S="${XCE_FAILOVER_COMMIT_WAIT_S:-90}"
log "waiting up to ${COMMIT_WAIT_S}s for jobs to commit on a majority (committed_lsn >= $COMMITTED_BOUNDARY)"
COMMIT_HIGH=0
for _ in $(seq 1 "$COMMIT_WAIT_S"); do
COMMIT_HIGH="$(grep -oE 'committed_lsn=[0-9]+' "$TOPDIR/logs/${PRIMARY}.log" 2>/dev/null \
| awk -F= '{print $2}' | sort -n | tail -1)"
COMMIT_HIGH="$(grep -oE 'commit: committed_lsn [0-9]+ -> [0-9]+' "$TOPDIR/logs/${PRIMARY}.log" 2>/dev/null \
| awk '{print $NF}' | sort -n | tail -1)"
COMMIT_HIGH="${COMMIT_HIGH:-0}"
[ "$COMMIT_HIGH" -ge "$COMMITTED_BOUNDARY" ] && break
sleep 1