From 5defe7cc014e5a5670c081e89ec80a0b8b6d8538 Mon Sep 17 00:00:00 2001 From: Rongsong Shen Date: Fri, 5 Jun 2026 05:36:27 +0000 Subject: [PATCH] feat(ha-repl-hardening): add observability log statements (task 5.4) - config_repl.c: INFO at WAL catch-up start with start/target LSN (Req 7.1) - config_repl.c: INFO at snapshot transfer start and complete with checkpoint_lsn and size (Req 7.3) - ha.c committing_timeout_fn_for_test: add WARN log counting n_converged/n_pending before promotion, matching production path (Req 7.5) - Reqs 7.2 (standby converged INFO) and 7.4 (majority INFO) were already present from tasks 3.1 and 5.2 respectively --- .kiro/specs/ha-repl-hardening/tasks.md | 2 +- src/controller/config_repl.c | 17 +++++++++++++++++ src/controller/ha.c | 20 ++++++++++++++++++-- 3 files changed, 36 insertions(+), 3 deletions(-) diff --git a/.kiro/specs/ha-repl-hardening/tasks.md b/.kiro/specs/ha-repl-hardening/tasks.md index 6b516de..b78796e 100644 --- a/.kiro/specs/ha-repl-hardening/tasks.md +++ b/.kiro/specs/ha-repl-hardening/tasks.md @@ -193,7 +193,7 @@ - _Requirements: 6.4_ - _Boundary: Controller FSM (ha.c)_ -- [ ] 5.4 Add observability log statements +- [x] 5.4 Add observability log statements - WAL catch-up start: INFO with start/target LSN — covered by unit test in task 6.2 - Standby converged: INFO with identity, config_tag, applied_lsn — covered by unit test in task 6.1 - Snapshot transfer start/complete: INFO with checkpoint_lsn, size — covered by unit test in task 6.4 diff --git a/src/controller/config_repl.c b/src/controller/config_repl.c index 37985c1..acb1e13 100644 --- a/src/controller/config_repl.c +++ b/src/controller/config_repl.c @@ -1441,6 +1441,11 @@ int ha_stream_wal_to_standby(endpoint_t *ep, const char *wal_path, if (standby_lsn >= committed_lsn) return 0; /* nothing to stream */ + /* Req 7.1: log WAL catch-up start with start/target LSN */ + INFO("ha_stream_wal_to_standby: starting WAL catch-up " + "start_lsn=%" PRIu64 " target_lsn=%" PRIu64, + standby_lsn + 1, committed_lsn); + /* ── Enumerate WAL segment files, sort ascending by first LSN ── */ DIR *d = opendir(wal_path); if (!d) @@ -1586,6 +1591,11 @@ int ha_send_snapshot_to_standby(endpoint_t *ep, const char *snap_dir, return -errno; uint64_t total_size = (uint64_t)st.st_size; + /* Req 7.3: log snapshot transfer start with checkpoint_lsn and size */ + INFO("ha_send_snapshot_to_standby: snapshot transfer start " + "checkpoint_lsn=%" PRIu64 " size=%" PRIu64, + checkpoint_lsn, total_size); + FILE *f = fopen(snap_path, "rb"); if (!f) return -errno; @@ -1647,6 +1657,13 @@ int ha_send_snapshot_to_standby(endpoint_t *ep, const char *snap_dir, free(buf); fclose(f); + + /* Req 7.3: log snapshot transfer complete (on success only) */ + if (rc == 0) + INFO("ha_send_snapshot_to_standby: snapshot transfer complete " + "checkpoint_lsn=%" PRIu64 " size=%" PRIu64, + checkpoint_lsn, total_size); + return rc; } diff --git a/src/controller/ha.c b/src/controller/ha.c index a6c36b0..13acdef 100644 --- a/src/controller/ha.c +++ b/src/controller/ha.c @@ -2756,8 +2756,24 @@ int committing_timeout_fn_for_test(ha_state_t *ha, cluster_t *c, return 0; ctrl_role_t role = (ctrl_role_t)atomic_load_explicit(&ha->role, memory_order_acquire); - if (role == CTRL_PRIMARY_COMMITTING && c != NULL) - ha_promote_to_primary(c); + if (role == CTRL_PRIMARY_COMMITTING) { + /* Count converged vs pending standbys for the WARN log (Req 7.5). */ + int n_converged = 0; + int n_pending = 0; + int n_peers = ha->n_peers; + for (int i = 0; i < n_peers; i++) { + if (ha->standby_converged[i]) + n_converged++; + else + n_pending++; + } + WARN("HA: committing timeout — majority convergence not reached within timeout; " + "%d/%d standbys converged, %d still pending; " + "promoting to PRIMARY in degraded mode (Req 6.4, 7.5)", + n_converged, n_peers, n_pending); + if (c != NULL) + ha_promote_to_primary(c); + } return 0; }