diff --git a/.wolf/buglog.json b/.wolf/buglog.json index dec06d69..de8c165a 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -19464,7 +19464,7 @@ "error_message": "User-reported, live 3-node cluster, right after bug-1700/bug-1701's redirect fix landed and was live-tested: `xceadmin scheduler record status --controller ` now correctly redirects ('redirected: localhost:9903 -> localhost:9901'), but the SAME command against the SAME redirect target intermittently fails with `Error: controller returned status -10013` (sometimes succeeds with real recording status, sometimes fails on an immediate repeat) instead of always succeeding.", "file": "src/xceadmin/src/xceadmin/scheduler.py (_send_admin_request), possibly xceadmin/discovery.py (follow_redirects)", "root_cause": "FULLY ROOT-CAUSED. -10013 is E_XCE_NOT_READY (errnox.h: XCE_ERRNO_BASE+12, 'Controller in CTRL_INIT or CTRL_ELECTING state'). The redirect from bug-1701's fix correctly points at whichever node was primary as of its last ctrlhello, but that node can be transiently mid-(re-)election by the time the redirected request actually arrives -- expected/normal on a freshly-booted cluster (election churn during the first several seconds), or any time a real failover is in flight. ha_dispatch_gate() returns -XCE_ERR_NOT_READY for exactly this transient window, with NO redirect populated (by design -- a CTRL_INIT/CTRL_ELECTING node genuinely has no settled primary to point to yet). The sibling code E_XCE_NOMASTER (errnox.h:22) carries an explicit design-intent comment: 'Standby has no known primary -- client should retry' -- but `_send_admin_request()` (scheduler.py:119-161) treats EVERY nonzero reply.status, including both E_XCE_NOT_READY and E_XCE_NOMASTER, as an immediate hard SchedAdminError with no retry at all. This is a documented client-side gap, not a server bug: the server-side behavior (refuse with a specific, distinguishable transient-state code) is correct and intentional; the client simply never implements the retry the errno's own comment already promises.", - "fix": "PENDING. Add bounded retry-with-backoff in xceadmin's scheduler-admin client path (_send_admin_request, scheduler.py, and verify whether push.py's config-push client has/needs the identical treatment for the same two codes) specifically for E_XCE_NOMASTER (10011) and E_XCE_NOT_READY (10013) -- both represent 'no settled primary right now, try again shortly', NOT a real failure. Do NOT add retry for E_XCE_STANDBY (10014, now redirect-handled by bug-1701) or any other status code. Suggested shape: a small fixed number of retries (e.g. 3-5) with a short fixed or lightly-backed-off delay (e.g. 1-2s), re-running the SAME follow_redirects() call from the top each attempt (a fresh attempt may get redirected differently once the election settles) -- mirror this project's existing bounded-retry conventions (e.g. verify_classify's retry loop in the HA soak driver, or follow_redirects' own _MAX_REDIRECT_HOPS=3 pattern) rather than inventing a new one. Needs a unit test proving: (a) a mocked server returning E_XCE_NOMASTER/E_XCE_NOT_READY N times then succeeding results in eventual success, not an immediate raise; (b) exceeding the retry budget still raises a clear, distinguishable error (not a silent hang); (c) E_XCE_STANDBY is NOT retried this way (still handled purely by redirect). Live-verify against a freshly-booted real cluster (the exact scenario that surfaced this) showing zero intermittent -10013 failures across N repeated invocations immediately after start-all.sh.", + "fix": "FIXED and LIVE-VERIFIED (2026-08-26). `_send_admin_request()` (src/xceadmin/src/xceadmin/scheduler.py:119-231) now wraps its whole request/redirect/decode cycle in a bounded retry loop, re-running `follow_redirects()` FROM SCRATCH each attempt (not a bare resend to the same host:port) -- a fresh attempt can discover a newly-settled or different primary once an election concludes. Retries EXACTLY `reply.status in (_E_XCE_NOMASTER, _E_XCE_NOT_READY)` (module-level constants at scheduler.py:80-111, values -10011/-10013 -- NEGATIVE, matching the real wire value confirmed via join.c:284 `rc = -E_XCE_NOMASTER` / commit.c:259 and controller.capnp:608's signed `Int32 status` field). `E_XCE_STANDBY` (-10014) is deliberately excluded -- untouched, still resolved purely by `follow_redirects()`'s existing redirect-following (bug-1701); a standby reply that DOES carry a redirect never even reaches this status check (follow_redirects consumes it internally), and one that does NOT carry a redirect is a genuine non-transient rejection that must keep failing immediately. No shared Python-side mirror of errnox.h's enum exists anywhere in xcecommon/xceadmin (confirmed by grepping the whole package) -- followed the one existing precedent instead of inventing a new convention: test_e2e_live_ha_push.py's own local `_E_XCE_STANDBY = 10014` constant with an errnox.h-citing comment. Retry budget: `_MAX_TRANSIENT_ATTEMPTS=4` total attempts (1 initial + 3 retries), `_TRANSIENT_RETRY_DELAY_S=1.5` fixed delay between attempts (`time.sleep`) -- sized at the same scale as this project's existing bounded-retry shapes (follow_redirects' own `_MAX_REDIRECT_HOPS=3`; the HA soak driver's verify_classify retry loop) since election-churn settling is single-digit-seconds, not a long outage; no exponential backoff needed at this scale. Retry-budget exhaustion still raises the existing `SchedAdminError` (no new exception type needed) but with a message appending '(still transient after N attempts over ~Xs -- giving up)' for clear distinguishability from an immediate non-retried hard failure. RED/GREEN proof (src/xceadmin/tests/test_scheduler.py): added `_SequentialMockController` (a finite, exact-connection-count multi-TLS-connection mock server, since the retry loop reconnects from scratch each attempt -- distinct from the file's existing one-shot `_MockController`) plus 5 new tests -- `test_record_status_retries_on_transient_status_then_succeeds` (parametrized NOT_READY/NOMASTER, 2 failures then success -> eventual success, FAILED pre-fix at collection time since the referenced constants didn't exist yet, and confirmed behaviorally via an ad hoc script that the pre-fix code raises immediately on a single transient reply with only 1 connection attempt), `test_record_status_retry_exhaustion_raises_distinguishable_error` (always-transient mock, `scheduler.time.sleep` monkeypatched so the test does not actually wait; asserts exact attempt count + distinguishable message), `test_record_status_standby_without_redirect_not_retried` and `test_record_status_standby_with_redirect_follows_redirect_not_retried` (regression locks: E_XCE_STANDBY is never retried, with/without a populated redirect, zero sleep calls in either case) -- all 5 PASS post-fix in 0.20s total (no real sleeping). Full xceadmin suite: 274 passed, 1 failed -- the failure (`test_live_config_push_against_standby_returns_standby_rejection_not_redirect`, test_e2e_live_ha_push.py) is PRE-EXISTING and unrelated: confirmed via `git stash push -- ` that it reproduces IDENTICALLY on the unmodified codebase -- it is a live e2e test whose own docstring already anticipated going stale once bug-1700/1701's generic dispatch-gate redirect fix (already landed this session) generalizes to `OPCode_upgradeConfig`, which it now has; zero new failures caused by this fix. LIVE VERIFICATION (real 3-node cluster, deploy-ha.sh + xce.build's real controller binary, editable-install xceadmin venv pointed at scheduler.py so before/after needed no rebuild, only a file swap): a plain fresh-boot tight loop immediately after start-all.sh did NOT naturally reproduce -10013 in this sandbox (election settles with highly variable timing, sometimes near-instantly, since `ha_has_write_quorum()`'s standby_endpoints are populated synchronously inside `raft_cb_become_leader` and are typically already satisfied by the time start-all.sh's 1s-granularity health-check first observes CTRL_PRIMARY) -- but a REAL FAILOVER (kill -9 the live primary, then hammer the two survivors with zero sleep, no health-check wait) reliably reproduced the exact user-reported symptom, which this bug's own root-cause writeup already named as an equally valid trigger ('...or any time a real failover is in flight'): pre-fix, the client surfaced a bare 'Error: controller returned status -10013' to the user at t+8.60s post-kill (exit 1); post-fix, an identical failover on a fresh cluster produced ZERO -10013/-10011 failures across the equivalent ~15s post-kill window (52 requests; every non-success was either a legitimate pre-election-completion 'connection refused' to the just-killed primary's now-dead listener, or a legitimate post-gate 'scheduler not connected' business-level SchedAdminError from this sandbox having no real xce_scheduler process deployed -- neither is a transient status code, and correctly reaches the caller unretried in both runs, proving the fix does not overreach). `push.py`'s `push_config()`/`probe_config()` (src/xceadmin/src/xceadmin/push.py:92-179) have the IDENTICAL gap -- same two transient codes, same immediate-return-as-data with zero retry -- confirmed by direct code read; NOT fixed here (out of this bug's Python-scheduler-admin-path scope, and push.py's error-vs-return convention differs from scheduler.py's raise-based one, so a proper fix there is more than a trivial shared-helper change) -- flagged as a sibling finding for a future bug, not silently left undocumented.", "tags": [ "xceadmin", "scheduler-admin", @@ -19478,7 +19478,9 @@ "found-live", "root-caused", "fix-scoped", - "unfixed" + "fixed", + "live-verified", + "push.py-sibling-gap-flagged" ], "related_bugs": [ "bug-1700",