diff --git a/.wolf/buglog.json b/.wolf/buglog.json index de8c165a..551f8e39 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -19521,7 +19521,7 @@ "error_message": "User-reported, live 3-node cluster: `xceadmin scheduler record status --controller localhost:9901` failed once with `Error: scheduler disconnected`, then succeeded on the very next identical invocation moments later. Root-caused to a full cluster redeploy (user confirmed: 'This is a full rebuilt and re-deployed cluster') restarting all 5 processes (3 controllers + worker + scheduler) together -- PIDs across ctrl-1/ctrl-2/ctrl-3/scheduler/worker logs are all tightly clustered (4137667/4137684/4137696/4137745/4138046), confirming a coordinated restart, not an isolated scheduler crash. The request happened to land in the brief, normal window between the old scheduler disconnecting and the new one reconnecting.", "file": "src/xceadmin/src/xceadmin/scheduler.py (_send_admin_request)", "root_cause": "FULLY ROOT-CAUSED, same family as bug-1713 but NOT covered by that fix. 'scheduler disconnected' is delivered via a DIFFERENT signaling path than bug-1713's two numeric status codes: cluster.c's bug-1693 disconnect-detection mechanism (cluster.c:1052-1067) sends `reply.status = 0` (success at the RPC level) with `schedadminreplymsg{ok=false, error=\"scheduler disconnected\"}` -- a normal-status reply carrying a domain-level failure, not a nonzero `reply.status` the way E_XCE_NOT_READY/E_XCE_NOMASTER are. `_send_admin_request()` (scheduler.py:145-154) treats `admin_reply.ok == False` as an unconditional hard SchedAdminError for EVERY reason string, with no distinction between genuinely transient conditions ('scheduler disconnected', 'scheduler not connected', 'request timeout' -- all connection/timing related, expected to self-resolve within seconds, especially during a redeploy/restart cycle) and genuinely permanent domain errors ('not recording', 'already recording', 'invalid record file name' -- real error states that must NOT be retried, e.g. calling record-stop on an already-stopped recorder is a correct, meaningful rejection, not a transient hiccup).", - "fix": "PENDING -- deliberately NOT dispatched yet: bug-1713's fix agent is concurrently editing this exact same file (scheduler.py) for the sibling numeric-status-code retry gap. Dispatch this fix ONLY after bug-1713 lands and its diff is reviewed, to avoid two agents colliding on the same function. Scope: extend (or share the same retry-loop infrastructure bug-1713 adds) to also retry when `admin_reply.ok == False` and `admin_reply.error` matches one of the known-transient reason strings ('scheduler disconnected', 'scheduler not connected', 'request timeout') -- exact string match against the literal strings cluster.c/sched.c actually send (grep cluster.c/sched.c/handler.c for every `sched_admin_reply_t.error =`/`SchedAdminReply.error` assignment to get the authoritative list before hardcoding it, don't guess). Do NOT retry on any other ok=false reason (those are real domain errors). Needs a unit test mirroring bug-1713's mocked-server pattern: a mock returning ok=false/error='scheduler disconnected' N times then succeeding results in eventual success; ok=false/error='not recording' is NEVER retried (fails immediately, unchanged behavior). Live-verify against a real redeploy cycle (kill+restart the whole cluster, immediately hammer `record status` through the restart window) showing zero user-visible 'scheduler disconnected' failures.", + "fix": "FIXED and LIVE-VERIFIED (2026-08-26). Extended bug-1713's retry loop in `_send_admin_request()` (src/xceadmin/src/xceadmin/scheduler.py:158-249) to a SECOND, differently-signaled transient family: after decoding `admin_reply = reply.data.schedadminreplymsg` and finding `admin_reply.ok == False`, the code now checks `admin_reply.error in _TRANSIENT_ADMIN_REASONS` (new module-level frozenset, scheduler.py:114-160) and, if so and `attempt < _MAX_TRANSIENT_ATTEMPTS`, sleeps `_TRANSIENT_RETRY_DELAY_S` and `continue`s the SAME `for attempt in range(1, _MAX_TRANSIENT_ATTEMPTS+1)` loop bug-1713 already added -- no second retry loop, same budget (4 attempts, 1.5s fixed delay), same re-run-`follow_redirects()`-from-scratch shape (a fresh attempt can discover a newly-reconnected scheduler, exactly like a fresh attempt can discover a newly-settled primary in bug-1713's case). On exhaustion, raises the same `SchedAdminError` shape with the reason string annotated '(still transient after N attempts over ~Xs -- giving up)', mirroring bug-1713's own distinguishable-message convention exactly. AUTHORITATIVE error-string list (grepped every literal `sched_admin_reply_t`/`SchedAdminReply` `.error = \"...\"` assignment across src/controller/ and src/scheduler/, then read each site's surrounding code, not just the string text): transient (all 4 now in `_TRANSIENT_ADMIN_REASONS`) -- \"scheduler disconnected\" (cluster.c:1062, bug-1693's disconnect-detection path), \"scheduler not connected\" (cluster.c:958, `c->sched.ep==NULL`), \"request timeout\" (cluster.c:1078, SCHEDADMIN_TIMEOUT_MS wait expired), and \"server busy, try again\" (cluster.c:937, `vtaskmgr_blocking_acquire()` admission-reservation exhaustion -- a 4th transient reason NOT in this bug's original three-string hypothesis, added after reading the admission-gate's own 'try again' design comment: resource contention that self-resolves as soon as another admitted vtask op completes, not a domain rejection). Permanent (left untouched, still raise on the very first attempt): \"already recording\"/\"not recording\" (driver.c:390/426, rc==-EALREADY) and validation_error_text()'s six filename/path-rejection strings (driver.c:298-316: \"invalid record file name\", \"record directory not found\", \"record directory path is not a directory\", \"permission denied accessing record file\", \"a non-file entry with this name already exists\", \"record file path too long\"), plus a dynamic (not a fixed literal, so it could never join an exact-match retry set anyway) \"cannot write to %s: %s\" I/O-failure message (driver.c:398-404). RED/GREEN proof (src/xceadmin/tests/test_scheduler.py): confirmed RED by temporarily reverting only the two bug-1715 edits back to bug-1713's exact shipped state (not via git stash, since bug-1713's own fix was itself still an uncommitted working-tree change sharing the same file -- a bare `git stash` would have reverted bug-1713 too) -- the new parametrized `test_record_status_retries_on_transient_admin_reason_then_succeeds`/`..._retry_exhaustion_on_transient_admin_reason_...` tests failed at COLLECTION time (`AttributeError: module 'xceadmin.scheduler' has no attribute '_TRANSIENT_ADMIN_REASONS'`), and a standalone ad hoc script against that same pre-fix code confirmed BEHAVIORAL red too: a real TLS mock returning `ok=false, error='scheduler disconnected'` once raised `SchedAdminError` immediately after exactly 1 connection, no retry. Reapplied the fix -> GREEN: all 41 tests in test_scheduler.py pass, including 4 new `_TRANSIENT_ADMIN_REASONS`-parametrized retry-then-succeed tests, 4 new retry-exhaustion tests (one per confirmed-transient reason, each asserting exact connection_count == _MAX_TRANSIENT_ATTEMPTS and a distinguishable exhaustion message), and a new `test_record_stop_not_recording_never_retried` non-regression test (asserts connection_count==1, zero sleep calls, for the permanent 'not recording' reason). The pre-existing `test_record_start_error_codes_raise_sched_admin_error` parametrize list was edited (not left untouched): \"scheduler not connected\"/\"request timeout\" were removed (they are now confirmed-transient and retried, not raised immediately -- their coverage moved to the new retry tests) and replaced with two more confirmed-permanent validation_error_text() strings (\"record directory not found\", \"permission denied accessing record file\") alongside the original \"invalid record file name\", for stronger permanent-error coverage. bug-1713's own 5 tests (transient-status retry/exhaustion, both E_XCE_STANDBY regression locks) were run UNMODIFIED and all still pass -- no shared-loop refactor was needed since bug-1713's `for attempt in range(...)` loop and its `reply.status != 0` branch were reused as-is; only a second `if`/retry check was added inside the existing `if not admin_reply.ok:` branch. Full xceadmin suite: 283 passed, 1 failed -- the failure (`test_live_config_push_against_standby_returns_standby_rejection_not_redirect`) is the SAME pre-existing, already-flagged-stale failure named in bug-1713's own report (test_e2e_live_ha_push.py, stale since bug-1700/1701's redirect-gap fix generalized to OPCode_upgradeConfig) -- zero new failures caused by this fix (284 total tests vs bug-1713's reported 275, consistent with the 9 new tests added here). LIVE VERIFICATION (real 3-node cluster, deploy-ha.sh + start-all.sh, build.dbg's real xce_controller/xce_scheduler/xcecd_virtual binaries -- no C rebuild needed since this fix is Python-only and none of the C-side cluster.c/driver.c code changed): hammered `xceadmin.scheduler.record_status('localhost:9991')` (the elected primary) in a tight zero-delay loop against the fixed client for 20s while concurrently `kill -9`-ing the live xce_scheduler process mid-run and restarting it via `start-scheduler.sh` (a genuine scheduler-process-death-and-restart, not a mock, not a controller failover). Result: 153 of 154 requests during the window succeeded, most transparently absorbing the scheduler-down period with zero visible failure to the caller; ONE request genuinely hit the real 'scheduler not connected' condition, went through the full retry budget (logged exactly as designed: 'scheduler not connected (still transient after 4 attempts over ~4.5s -- giving up)'), and still surfaced a SchedAdminError because this particular sandbox's scheduler restart (relaunched via a fresh `nix develop` subshell each time, which carries its own multi-second evaluation overhead on top of the scheduler's own re-join handshake) took longer to fully rejoin than the shared 4-attempt/1.5s (~4.5s total) budget -- the very next request after that succeeded again. This is honestly reported as PARTIAL absorption, not a zero-failure live result like bug-1713's controller-failover scenario got: the retry mechanism is proven to engage correctly on a genuine, non-mocked signal end-to-end (real controller, real scheduler restart, real wire reply, real client-side retry/give-up message), and it converted what would have been 100% visible failure for the whole outage window (pre-fix) into 1 failure out of 154 requests (post-fix) -- but this sandbox's nix-develop-relaunch overhead for the scheduler restart is likely slower than a real production supervisor restart would be, so the single exhaustion here should not be read as proof the shared 4.5s budget is too short in general. Kept the identical bug-1713 budget as instructed (no concrete evidence specific to THIS class of condition that it's wrong -- the one exhaustion observed is plausibly a sandbox-restart-mechanism artifact, not a signal about the real-world scheduler-restart timescale) rather than inventing a different cadence from one ambiguous data point. `push.py`'s `push_config()`/`probe_config()` gap flagged by bug-1713 as a sibling finding remains unfixed and out of this bug's scope (unchanged from bug-1713's report).", "tags": [ "xceadmin", "scheduler-admin", @@ -19533,15 +19533,15 @@ "found-live", "root-caused", "fix-scoped", - "blocked-on-bug-1713", - "unfixed" + "fixed", + "live-verified" ], "related_bugs": [ "bug-1713", "bug-1693" ], "occurrences": 1, - "last_seen": "2026-08-26T18:45:00Z" + "last_seen": "2026-08-26T20:15:00Z" } ] -} \ No newline at end of file +}