From 88b0ac99374c5e19e274679f7f7f0acdb7192ab0 Mon Sep 17 00:00:00 2001 From: Rongsong Shen Date: Fri, 4 Sep 2026 04:37:11 +0000 Subject: [PATCH] fix(scheduler): close post-failover rejoin detection gap (bug-1760) An idle scheduler (nothing queued to publish) never noticed a dead controller connection: sched_needs_rejoin was only ever set as a side effect of an active client-library call, and an idle round makes none. After any controller failover with nothing already in flight, jobs submitted to the new primary stayed PEND indefinitely. Adds xcecli_is_connection_broken() (libxce) -- a pure, socket-free read of the transport's already-async-maintained dead/alive flag, set for free by the existing RDHUP disconnect handler with zero application calls. sched_check_pending_rejoin() now retries xcecli_join() on either the existing reactive flag or this new passive signal, so a healthy idle scheduler still makes zero extra network calls while a genuinely dead connection self-heals within one ~1s round -- live-verified against a 3-node HA cluster (rejoin fired ~300ms after new-primary election with nothing submitted in between). Also closes out bug-1735 (job memory/CPU usage reporting): confirmed already fixed on this branch since 2026-08-30, just never marked in the bug log. Co-Authored-By: Claude Sonnet 5 Claude-Session: https://claude.ai/code/session_01XYdtrEWWZfKRRGED7raEYg --- .wolf/buglog.json | 43 ++- src/include/client.h | 14 + src/lib/client.c | 9 + src/lib/testsuite/test_libxce_retry.c | 43 +++ src/scheduler/include/scheduler.h | 6 + src/scheduler/src/main.c | 24 ++ src/scheduler/src/scheduler.c | 60 +++- src/scheduler/testsuite/meson.build | 6 +- .../test_scheduler_decision_publish_retry.c | 264 ++++++++++++++++++ 9 files changed, 441 insertions(+), 28 deletions(-) diff --git a/.wolf/buglog.json b/.wolf/buglog.json index bc249285..0cd7aa17 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -19511,7 +19511,7 @@ "error_message": "User-reported live deployment: xce_scheduler process died and restarted unexpectedly (PID changed from 3964918 to 4137745 in scheduler.log with a ~79s gap, no manual restart by the user) during a live 3-node cluster test session; xceadmin briefly reported 'Error: scheduler disconnected' (the already-correct bug-1693 disconnect-detection path in cluster.c, working as designed -- not itself a bug) then recovered on the next attempt once the scheduler rejoined. User confirmed via `sudo dmesg -T` a REAL kernel-level segfault: `xce_scheduler[2815660]: segfault at 30 ip 0000601569e1fb35 sp 00007db7db1f6e00 error 4 in xce_scheduler[23b35,601569e01000+de000] likely on CPU 5 (core 16, socket 0)` -- though this specific dmesg entry is dated Aug 25 19:21:39, a DIFFERENT, earlier occurrence than today's specific restart (Aug 26 ~18:00-18:02), not necessarily the direct cause of THIS restart. No core dump exists for xce_scheduler anywhere in /var/lib/systemd/coredump/ (only xce_controller and python entries present, despite the scheduler segfault being kernel-confirmed) -- a separate, notable gap in this environment's crash-capture coverage for the scheduler process specifically.", "file": "src/scheduler/ (exact crash site unknown -- no core dump, no backtrace available for either occurrence)", "root_cause": "NOT ROOT-CAUSED -- confirmed real (kernel dmesg segfault line, error code 4 = user-mode read fault, not a random/unrelated event) but no core dump or backtrace exists for any xce_scheduler crash observed so far, including the Aug 25 19:21:39 kernel-confirmed occurrence and today's (Aug 26, ~18:00-18:02) restart (PID 3964918 -> 4137745), which may or may not be the SAME underlying bug -- the two occurrences have not been correlated beyond both being unexplained scheduler deaths. Notable secondary finding: systemd-coredump is confirmed working for xce_controller (4 real core.xce_controller.*.zst files captured and used earlier this session, see bug-1699) but has captured ZERO xce_scheduler crashes despite at least one kernel-confirmed scheduler segfault -- needs investigation on the user's real machine (check core_pattern/ulimit -c/systemd-coredump size or process-name filtering specifically for the scheduler binary; also worth checking whether the scheduler's own launch wrapper -- start-scheduler.sh, a bare unwrapped invocation with no core-dump-enabling ulimit call -- inherits a different ulimit -c than however the controller happens to get its unlimited setting). FOLLOW-UP (2026-08-26, disambiguating today's restart from the Aug-25 segfault): checked dmesg for today's exact restart window (17:45-18:15) -- zero xce_scheduler entries (the ONLY dmesg segfault hit remains the single Aug 25 19:21:39 occurrence). journalctl for the same window -- zero xce_scheduler entries at all. dmesg confirms OOM killer was never actually invoked against any process in this window (only periodic OOM-killer enable/disable toggling, unrelated). ulimit -c is unlimited and core_pattern correctly routes to systemd-coredump (confirmed working for xce_controller, 4 real cores captured this session). The combination of (a) unlimited core-dump capacity + correct core_pattern, (b) zero kernel fault-signal record, (c) zero OOM record, (d) zero journalctl record for today's specific window strongly indicates today's PID change (3964918 -> 4137745) was NOT a crash of any kind -- a genuine fault signal (SIGSEGV/SIGABRT/SIGBUS/SIGILL/SIGFPE) is unconditionally kernel-logged regardless of which process triggers it, and none was. The scheduler is launched as a bare backgrounded process (start-scheduler.sh, no systemd unit), so an ordinary kill/pkill sent by an unrelated concurrent process on this shared machine would leave NO trace in dmesg or journalctl -- most likely explanation for today's specific restart, DECOUPLED from this bug going forward. This buglog entry now tracks ONLY the confirmed, kernel-verified Aug 25 19:21:39 xce_scheduler segfault (still unreproduced, still no core available, still worth investigating on recurrence) -- not today's restart, which is environmental noise, not a code bug.\n\nUPDATE (2026-08-29, bug-1731 live gdb-wrapped repro session): CRASH CAPTURED LIVE, first-ever backtrace for this crash family. Root cause of the earlier no-core-dump gap circumvented by launching xce_scheduler wrapped in `gdb -batch -ex run` FROM PROCESS START (not attach-after-the-fact) during a heavy burst-array workload (6 concurrent `jobsub -a 50` array submissions, 300 near-instant /bin/true elements, on a live 3-node HA cluster, debug build profile). Reproduced at T+150s into the burst. Full backtrace:\nSIGSEGV in sched_get_project(core, name=0x41d0000000000000) at scheduler/src/core.c:412, called from core_build_job() at scheduler/src/core_events.c:221, called from xce_core_push_events() at scheduler/src/core_events.c:725 (crashed on the 3rd of a 6-event batch), called from xce_sched_driver_translate_pending_events() (driver.c:555) <- xce_sched_driver_run_normal_mode_round() (driver.c:749) <- main() (main.c:465). Registers: rax=rdx=rsi=0x41d0000000000000 (corrupted `name` arg present in 3 registers), rdi=0x555555695da0 (valid `core` arg). Single-thread fault in the main scheduling-round thread (all 9 other threads idle in pthread_cond_wait/epoll_wait) -- not a cross-thread race at the fault site itself, though the corruption's origin is not yet located.\ncore_build_job() (core_events.c:221) calls sched_get_project(core, j->submit->project_name). The two preceding calls in the same function (sched_get_user, sched_get_queue, reading earlier fields of the same job_submit_data_t*) succeeded, so j->submit itself is a valid pointer -- but its project_name field held 0x41d0000000000000, not NULL and not a plausible string pointer. clone_job_submit_data() (handler.c:102-150) calloc()s the destination and only strdup()s project_name when the source is non-NULL, so a legitimately-absent project name would be NULL (which sched_get_project's own guard at core.c:412 handles safely) -- this crash requires the field to have been overwritten with garbage AFTER allocation. Points to memory corruption or a stale/reused pointer in the array-job event-translation/batching path under heavy concurrent load, not a missing-null-check. NOT YET further isolated -- the corruption's write site is still unknown. Fault class (SIGSEGV, invalid-pointer read via strlen()) matches the original kernel dmesg description (`error 4` = user-mode read fault) closely enough that this is plausibly the same crash family, now finally attributable to an exact function/line/call-chain instead of an unattributed dmesg line.\n\nUPDATE (2026-08-29, post-fix live-repro session -- bug-1730/1731/1733 fixes now all landed and included): two-phase reproduction attempt, both phases succeeded.\n\nPHASE 1 (ASAN, fresh clean builds of controller/scheduler/worker/xceadmin including commits 42eeaa1e[bug-1733 vtaskmgr UAF fix], b1323f8d[bug-1730], ebe691c3+67009815[bug-1731]): deployed fresh 3-node HA cluster (/tmp/xce-deploy-bug1714-asan2), launched xce_scheduler directly under ASAN (ASAN_OPTIONS=detect_leaks=0:halt_on_error=1:abort_on_error=1), ran a 10x50-element concurrent array-job burst (500 elements, wave 1 of a planned two-wave/1000-element burst). CRASH REPRODUCED WITHIN WAVE 1 ITSELF -- before all 10 clients' submissions even completed, after only 2 of 10 array pushes had been expanded by the scheduler (100 of the intended 500 elements). This is FASTER than the original bug-1731-session capture (T+150s) and definitively proves the bug is STILL PRESENT after all three recent fixes, not masked or perturbed by ASAN instrumentation. Verbatim ASAN report:\n AddressSanitizer:DEADLYSIGNAL\n ==562488==ERROR: AddressSanitizer: SEGV on unknown address (pc 0x64b0be11076e ...)\n ==562488==The signal is caused by a READ memory access.\n #0 sched_get_project ../scheduler/src/core.c:412\n #1 core_build_job ../scheduler/src/core_events.c:221\n #2 xce_core_push_events ../scheduler/src/core_events.c:725\n #3 xce_sched_driver_translate_pending_events ../scheduler/src/driver.c:555\n #4 xce_sched_driver_run_normal_mode_round ../scheduler/src/driver.c:749\n #5 main ../scheduler/src/main.c:465\n Register values: rax=rdx approx corrupted; rax = 0x41d0000000000000 (still exactly 2^30=1073741824.0 as an IEEE-754 double, matching the original capture bit-for-bit) -- IDENTICAL crash signature, file, line, and call chain to the original bug-1731-session capture. SUMMARY: AddressSanitizer: SEGV core.c:412 in sched_get_project.\n Diagnostically important: ASAN's own heap-buffer-overflow and use-after-free shadow-memory detectors did NOT fire -- only the raw SIGSEGV/DEADLYSIGNAL handler caught this, exactly as a non-ASAN build would. This RULES OUT a classic redzone-violating heap overflow into an adjacent allocation (ASAN would have caught that at the WRITE) and argues for either (a) a wrong-offset/type-confusion write within a still-valid allocation, or (b) a use-after-free where the stale read happens only after the freed chunk has already left ASAN's quarantine and been legitimately reallocated for a new, unrelated live object -- which Phase 2 then confirmed directly.\n\nPHASE 2 (gdb scripted watchpoint, debug -O0 -g3 profile, same fix set, fresh cluster /tmp/xce-deploy-bug1714-dbg2): launched xce_scheduler under `gdb -batch -x scheduler-watchpoint.gdb`, breaking on clone_job_submit_data() (handler.c:102, called once per array element from make_array_element), sampling every 31st call and arming a hardware watchpoint on the returned job_submit_data_t's ->project_name field (via `finish` + cast of $rax to the known x86-64 System V pointer-return-value register), capped at 3 simultaneous watchpoints to stay within HW watchpoint budget. Ran the same burst pattern. ALL THREE armed watchpoints fired within the first burst wave. Full verbatim capture in this session's transcript; key facts:\n - All three watched job_submit_data_t->project_name fields transitioned from a plausible-looking heap string pointer (e.g. 'Old value = 0x7fffe000bc60 \"0\\275\"') to exactly NULL (0x0) -- i.e., we caught a real WRITE, but a NULL-out, not the resource-double corruption pattern itself.\n - Root cause of that write, nailed by backtrace: the write instruction was __memset_avx2_unaligned_erms, called from libCapnC_Runtime.so's capn_init_mem()/init_fp(), called from xce_decode() (lib/request.c:103) -- i.e. Cap'n Proto's own message-decode-buffer zero-initialization for a BRAND NEW INCOMING NETWORK REQUEST, executing on a COMPLETELY DIFFERENT thread (LWP 580496, decoding its own client's array submission) than the thread that had originally cloned the watched job_submit_data_t (LWP 580499, decoding a DIFFERENT client's array submission, job_array pointer 0x7fffe0000cf0 vs 0x7fffe4002fe0).\n - This is DEFINITIVE PROOF of the corruption mechanism: a job_submit_data_t's heap chunk, after being freed, gets immediately recycled by glibc malloc to serve an UNRELATED incoming request's Cap'n Proto decode buffer on a different thread. Any stale pointer still referencing the old (freed) job_submit_data_t will, from that point on, read whatever the CURRENT occupant of that memory happens to contain -- first zeros (as caught here), but on a LATER reuse cycle for something that stores a raw IEEE-754 double (e.g. an xce_alloc_t's `value` field, src/include/xce/types.h:270), it would read exactly the 2^30/1GiB bit pattern seen in both the original and this session's crash.\n - IMPORTANT CAVEAT / what remains UNRESOLVED: the free() itself, in this specific capture, was almost certainly LEGITIMATE, not a bug by itself. Verified by static reading of driver.c's xce_sched_driver_translate_pending_events(): within one drain/translate call, xce_core_push_events(core, events, n) (driver.c:555, which runs every core_build_job() call for the whole batch) unconditionally executes BEFORE the cleanup loop that calls release_translated_payload()->free_Job_ptr()->free_JobSubmitData_ptr() (driver.c:585-588) -- ownership/free ordering within a single batch is correct by inspection. sched_on_job_array() (handler.c) also does not push a client's array to the scheduler until its ENTIRE 50-element clone loop completes, so the specific object we watched (armed at clone call #31, i.e. mid-loop) could only have been freed AFTER its owning thread's full loop finished, was submitted as one combined XCE_SCHED_OP_UPDATE_JOB request, and was drained+processed+freed by an EARLIER, already-completed scheduling round -- i.e. a normal, successful lifecycle, not an early/premature free caught in the act. The actual bug is therefore NOT in this ownership-transfer/free ordering itself, but in some OTHER, not-yet-identified code path that reads a job_submit_data_t (or the containing xce_job_t) a SECOND time, AFTER it has already been correctly processed and freed once. Did not have time this session to isolate that second/stale reader. Two concrete leads for the next session: (1) whether a redelivered/retried array push can race sched_on_job_array()'s per-element `sched_get_job(&(sched->core), jobid) != NULL` dedup check (handler.c ~212) against the window before a just-submitted job is actually added to sched->jobs (which only happens later, inside core_build_job()/sched_add_job(), not at submit time) -- if so, two independent xce_job_t/job_submit_data_t clones could exist for the same jobid, and it's worth checking whether anything then conflates or double-references them; (2) core_build_schedobj() (core_events.c:174-197, called from core_build_job() at core_events.c:253 with the ORIGINAL `j` still valid) does `obj->project = makeString(j->submit->project_name)` -- a SECOND independent read of j->submit->project_name beyond the sched_get_project() call at core_events.c:221 that actually crashes; worth double-checking core_build_schedobj/its 3 tag-dispatch helpers for any raw pointer-aliasing (vs. deep copy) into the resulting long-lived xce_sched_job_t/xce_sched_obj_t that could keep referencing freed submit-owned memory after `j` itself is gone.\n\nBoth clusters deployed this session (/tmp/xce-deploy-bug1714-asan2, /tmp/xce-deploy-bug1714-dbg2) were torn down cleanly after their captures; the crash/watchpoint logs remain on disk at /tmp/xce-deploy-bug1714-asan2/logs/scheduler_asan.log and /tmp/xce-deploy-bug1714-dbg2/logs/scheduler_gdb_watchpoint.log for reference (not committed, local /tmp only -- copy out if this environment gets reset before a follow-up session).\n\nUPDATE (2026-08-30, Part 1/Part 2 investigation session): PART 1 (static-only, XceData_data_schedjobs dataset->rows aliasing) -- RULED OUT, not a bug. Traced the full decode chain for the schedjobs/jobs table (src/lib/xcectx.c:139 xce_decode() -> src/lib/request.c:1786 extract_data() -> src/lib/controller.capnp.c decode_Job_list()/decode_Job_ptr() (line 6348/6369) -> decode_JobSubmitData_ptr() (line 12427) -> decode_JobSubmitData() (line 12223)). Confirmed every xce_job_t (calloc, decode_Job_ptr/decode_Job_list) and every job_submit_data_t (calloc, decode_JobSubmitData_ptr) is an independent heap allocation, and every job_submit_data_t string field uses STRING_DUP (= strdup, controller.capnp.h:9) -- structurally identical to clone_job_submit_data()/decode_pidinfo(). extract_data() (request.c:1786-1815) only memcpy's the already-decoded xce_job_t* POINTER VALUES into dataset->rows (then memsets the source array to prevent double-free) -- it never aliases into the capnp segment/request buffer, and this happens entirely INSIDE xce_decode(), before capn_free(&c) at request.c:281 destroys the wire buffer. So sched_handle_dataset()'s XceData_data_schedjobs case handing dataset->rows to sched_on_jobs() for deferred driver-thread processing is a correct, safe zero-copy ownership transfer of already-independent objects, not a second UAF class. The XceData_data_jobArray case's contrasting comment ('we never alias... unlike the list-shaped cases above') is about a different concern (N-way sharing of one spec across array elements), not capnp-buffer lifetime -- both cases are equally safe on that specific axis.\n\nPART 2 (live pointer-lifecycle tracking, main task) -- did NOT capture a fresh crash this session despite extensive effort (see below), but surfaced a significant, previously-undocumented, independently-reproducible finding that materially narrows the investigation and directly answers this entry's own Question 3 lead about a redelivery/retry mechanism. Full method: added temporary mutex-guarded fprintf/fflush diagnostic logging (address, jobid, tid, timestamp) at three sites -- make_array_element() (handler.c, ALLOC), every free_Job_ptr()/free_JobSubmitData_ptr() call site in driver.c's release_translated_payload() (FREE), and core_build_job() (core_events.c) immediately before the historically-crashing sched_get_project() line (READ). The shared logging implementation was placed in src/lib/utils.c (a genuine, non-generated libxce.a source file) rather than controller.capnp.c, after discovering mid-session that src/lib/controller.capnp.c is NOT actually compiled -- meson's custom_target regenerates lib/controller.capnp.c/.h from src/schema/controller.capnp fresh into the BUILD directory on every build, silently discarding any manual source-tree edit to that file (confirmed empirically: an initial edit there vanished from the compiled object with no error). Built (debug profile), deployed multiple fresh 3-node HA clusters, launched xce_scheduler under `gdb -batch -ex run -ex \"thread apply all bt full\"`, and drove very heavy concurrent `jobsub -a 50` array-job bursts -- far exceeding the original recipe's intensity: 6-15 concurrent submissions per wave, 20+ waves across several redeploys (both -v and -vvv controller verbosity), well over 100 total concurrent array submissions / 5000+ array elements pushed. The scheduler did NOT crash in any of these attempts (longest single continuous run: ~16 minutes / 5 waves without a restart), a notably higher bar than the original session's 150s/6-concurrent capture -- see 'What changed / open question' below.\n\nKEY FINDING (from the diagnostic log, cross-referenced against the scheduler's own pre-existing Bug-A WARN logging): every array-job jobid gets independently, repeatedly RE-CONSTRUCTED and pushed to the scheduler via the ORDINARY (non-array) XceData_data_schedjobs/JOBS_PUSH bulk path -- confirmed by cross-referencing FREE events against ALLOC events by jobid: every array-path jobid showed MORE free events than array-path (make_array_element) allocs, each with a DISTINCT heap address (never the same address freed twice -- ruling out a literal double-free), e.g. jobid 4658596961282883584 was array-allocated once but freed 18 times from 18 distinct addresses over a 16-minute run. Each of these extra frees is preceded by a matching WARN in scheduler.log: 'xce_core_push_events JOBS_PUSH: sched_add_job failed for jobid ... (rc=-17), discarding duplicate/orphaned job' -- i.e. Bug A's fix (this same buglog entry, prior session) is correctly catching and safely discarding every one of these redelivered duplicates before they reach the picker. CRITICALLY, this was reproduced in a run with ZERO client-side submission failures/retries (confirmed: grep for 'jobsubmit failed'/'retry' across all burst client output files in the clean final run returned zero matches, yet the SAME redelivery pattern still occurred, up to 18x per jobid) -- this RULES OUT the client-retry-on-timeout hypothesis (XCECLI_FAILOVER_CALL's retry loop, client_internal.h) as the trigger; the redelivery is NOT a symptom of client-observed transport failure, it happens under clean, fully-acknowledged submissions too. Static reading of the two most likely controller-side mechanisms did not find an obvious culprit: (1) persist_apply_pump_run() (persist.c:5521) advances last_applied_lsn strictly one entry at a time under apply_pump_lock and only ever processes next=last_applied_lsn+1, so a genuine re-walk of an already-applied LSN range looks structurally impossible by construction; (2) apply_committed_entry()'s WAL_JOB_ARRAY_SUBMIT case (persist.c:4391-4461) explicitly fires HOOK_DETAIL_JOB_NEW exactly once per successful apply, with an EEXIST short-circuit for an idempotent whole-record re-apply. Neither explains a genuinely repeated, single-job-shaped (l->count==1, routed through xcesched_push_joblist() per sched.c:326-327's dispatch, not xcesched_push_jobarray()) HOOK_DETAIL_JOB_NEW fire for jobids that were originally created via the array path. bug-1419's in-flight submission registry (job.c:71-140, tracks [base_jobid, base_jobid+array_size) ranges) is the most likely place a gap could exist for this specific pattern but was not dynamically traced this session -- NEXT STEP for a follow-up session: either a live gdb breakpoint on sched_job_new_fun()/xcesched_push_joblist() (sched.c) capturing the call's l->count and full backtrace, or controller-side instrumentation logging out_new_jobs.count at every HOOK_DETAIL_JOB_NEW fire site, to determine whether this is a genuine second independent WAL commit for an overlapping jobid range (a real gap in bug-1419's registry or jobid_range_exists()) or some other apply-side effect not yet identified by static reading.\n\n(a) vs (b) QUESTION -- NOT SETTLED this session (no fresh crash captured to inspect). The redelivery-storm finding above establishes a plausible AMPLIFYING mechanism (far more job_submit_data_t alloc/free churn under array-job load than previously suspected, all safely discarded by Bug A but still consuming and freeing large volumes of same-shaped heap chunks under concurrent capnp-decode pressure on other threads) but does not by itself prove a stale-pointer read, since every redelivered object observed in this session's log was a freshly-decoded, valid object at its own READ time (not a stale/freed one) -- the two prior sessions' watchpoint-proven UAF mechanism (freed job_submit_data_t memory reused by malloc for an unrelated concurrent capnp decode buffer) still requires a genuinely stale SECOND reference somewhere, which this session did not catch live.\n\nWhat changed / open question: this session's burst intensity substantially exceeded the recipe that reliably crashed within 150s-2.5min in the two prior sessions (same debug build profile, same gdb wrapper, same jobsub -a 50 command), yet produced zero crashes across ~20+ waves / 100+ concurrent submissions / 5000+ array elements over multiple redeploys. Possible explanations, none confirmed: (1) the two prior sessions' side-bug fixes (bug-1730's core_events.c fix, bug-1731's HOOK_DETAIL_JOB_FAIL fix, and this entry's own Bug A/Bug B, all landed 2026-08-29 per git log -- 'fix(scheduler): don't hand an orphaned duplicate job to the picker' at commit 38437e57 among them) may have shifted timing enough to reduce (not eliminate) the race window; (2) this session's burst driver script (piped `xce_test --norc` REPL commands, one process per concurrent submission) may differ subtly in timing/pacing from whatever exact mechanics the original crash-capturing sessions used; (3) simple bad luck across a large but still finite number of attempts for a genuinely rare race. All temporary diagnostic instrumentation (handler.c, driver.c, core_events.c, src/lib/utils.c) was fully reverted before this session ended -- confirmed via `git diff` returning clean/identical-to-HEAD for all four tracked files, plus a manual re-check of the untracked/regenerated src/lib/controller.capnp.c (git-invisible, confirmed no leftover bug1714_diag_log references anywhere under src/). Full scheduler ASAN test suite re-run after revert: 54/55 pass, the one failure (test_recordstart_symlink_escape_replies_error) is the already-documented pre-existing sandbox filesystem-permissions flake, unrelated to this session. All deployed clusters (3x) torn down; zero xce_controller/xce_scheduler/xcecd_virtual/gdb processes left running. NEXT STEP for a follow-up session: (a) pursue the redelivery-storm's exact trigger per the NEXT STEP above (this is now the most concrete, evidence-backed lead); (b) if reproduction is attempted again, consider a substantially longer single continuous run (30+ min) rather than many shorter redeploys, since this session's longest unbroken run was only ~16 minutes and the original captures may have benefited from cumulative state a fresh redeploy resets each time.\n\nUPDATE (2026-08-30, later same day, large-ASAN-quarantine live-repro session): NEW APPROACH TRIED, NOT YET DOCUMENTED IN THIS ENTRY -- launched the ALREADY-BUILT ASAN xce_scheduler (src/xce.build/scheduler/xce_scheduler, built 2026-08-30 11:36, already including every fix through commit 22aa16bf/38437e57 -- no rebuild needed since ASAN_OPTIONS is a runtime env var, not compile-time) with a deliberately oversized quarantine/redzone (ASAN_OPTIONS=quarantine_size_mb=256:redzone=256:max_redzone=2048:detect_leaks=0:abort_on_error=1:halt_on_error=1) specifically to test whether the documented \"freed block reused too fast for ASAN's default quarantine\" explanation for plain-ASAN's prior silence (see the 2026-08-29 post-fix update above) would resolve with a much larger quarantine. Deployed a controller-only + scheduler 3-node HA cluster (NO worker -- confirmed by static reading of the crash call chain, in this same entry, that sched_get_project()/core_build_job()/xce_core_push_events() all fire at JOBS_PUSH submission-ingestion time, before any picker/allocator/worker involvement, so a worker is not required to trigger this specific crash; xcecd_virtual was also unavailable to build this session, see environmental note below, making this a load-bearing simplification, not just a shortcut). Drove a sustained, unthrottled burst-submission loop (8 concurrent `client`+`jobsub -u root -q normal -c hostname -a 50` xce_test invocations per wave, back-to-back waves, ~1-8s apart) for ~8 minutes continuous wall clock, reaching 64 waves = 25,600 array elements pushed (verified via a final controller `joblist` count of 25,756 PEND jobs, consistent with no jobs lost at the controller level) -- substantially higher volume and, without a worker providing any execution-time backpressure, likely higher submission RATE than any prior session's recipe (the original crash-capturing sessions used 6 concurrent x 50 = 300 elements in 150s; this session pushed 25,600 in ~480s, roughly an order of magnitude more elements per unit time). RESULT: the scheduler did NOT crash and produced ZERO AddressSanitizer reports of any kind (grep -ci AddressSanitizer scheduler.log == 0) across the full run. ADDITIONAL NEGATIVE FINDING: the 2026-08-30-morning session's \"redelivery-storm\" (array-job jobids redelivered via the ordinary JOBS_PUSH path, discarded by Bug A with a \"discarding duplicate/orphaned job\" WARN, observed up to 18x per jobid that session) did NOT reproduce AT ALL this run either -- zero occurrences of that WARN string anywhere in 94,794 scheduler.log lines, despite comparable-or-higher load. This is a second, independent \"previously-reliable symptom now absent\" data point in addition to bug-1714's own crash, on the same day, suggesting SOMETHING about either the exact submission-driver mechanics (this session used direct `client`+`jobsub` xce_test invocations; the morning session used a different piped-REPL driver script whose exact mechanics were not preserved) or genuine environment/timing variance materially changes whether either symptom fires -- not just bad luck on the crash alone. CAVEAT (important, do not skip): a controller build from an EARLIER point in this same work session (commit 38437e57 onward, built 2026-08-30 03:21) and a scheduler build from 11:36 the same day were reused as-is (not rebuilt) for this attempt -- both already post-date every fix this entry and its siblings (bug-1730/1731/1733) describe, so this is a like-for-like continuation of the \"post-fix\" investigation, not a regression to older code.\n\nENVIRONMENTAL INCIDENT (important for future sessions on this sandbox): this session began by finding the root filesystem at 0 bytes available (936.8G/936.8G used), which blocked ALL work (builds, deploys, even log writes) until resolved. `nix-collect-garbage` (no -d) was run to reclaim space, which worked (freed ~790GB, root cause was almost certainly months of accumulated `nix develop` closures across many past sessions' worth of ASAN toolchains, never garbage-collected) but had a serious side effect: it evicted this flake's own cached bootstrap-toolchain closure (gnum4/bison/gmp/mpfr/isl/libmpc/autoconf/a full multi-stage GCC bootstrap), forcing EVERY subsequent `nix develop ./src` invocation on this box -- including a DIFFERENT, concurrently-running agent's own controller build for an unrelated bug (bug-1735) -- into a full from-source toolchain rebuild. This cost roughly 15-20 minutes of wall clock before ANY build (mine or the other agent's) could proceed, and materially ate into this session's time budget. LESSON for next time: if disk space must be reclaimed on this box again, prefer `nix-store --gc --print-dead` / a bounded `nix-collect-garbage --max-freed ` first to gauge what will be evicted, since this flake's own dev-shell closure is apparently NOT protected by a persistent gcroot between sessions and is fully re-buildable-from-scratch (not just re-fetchable) when evicted -- a full unbounded `nix-collect-garbage` is disproportionately expensive here. Once resolved, this session worked around not having a fresh full build by (a) reusing the ALREADY-BUILT src/xce.build/{controller,scheduler} binaries directly (their /nix/store runtime deps were, fortunately, NOT evicted -- `ldd` still resolved cleanly) with the new ASAN_OPTIONS applied purely at launch time, and (b) building ONLY the missing `xceadmin` component fresh (into a separate dir, src/xce.build.bug1714xa) since a cluster.bin config cannot be produced without it -- this minimal-rebuild strategy is worth reusing directly if this situation recurs, rather than a full `xce-build.sh all`.\n\nbug-1734 was NOT reproduced this session: its repro recipe needs a worker to actually run jobs to DONE/EXIT so the scheduler-vs-controller view can be compared; no `xcecd_virtual` binary exists in any build dir on this box currently (checked src/xce.build, src/xce.build.validate, src/build-asan, src/build-asan-1696repro -- only worker *test* binaries exist, no `xcecd_virtual` itself), and this session's bounded time budget (already consumed by the disk/nix incident above) did not allow building `worker` fresh on top of the already-spent time. See bug-1734's own entry for a same-day cross-reference note.", - "fix": "STILL NOT FIXED -- but no longer blocked on evidence collection; see root_cause UPDATE above for the first captured backtrace. NEXT STEP: find what writes garbage into job_submit_data_t->project_name after clone_job_submit_data() allocates it -- likely somewhere in the array-job batching/event-translation path (xce_core_push_events / xce_sched_driver_translate_pending_events) given the crash hit specifically while processing event index 2 of a 6-event batch under heavy concurrent array-job load. Reproduction recipe confirmed reliable enough to use again: debug-profile build, xce_scheduler launched via `gdb -batch -ex run -ex \"thread apply all bt full\"` from process start (script preserved at /tmp/xce-deploy-bug1731/scripts/start-scheduler-gdb.sh), 6 concurrent 50-element array submissions against a live 3-node HA cluster -- crashed within 150s this run.\n\nUPDATE (2026-08-29): STILL NOT FIXED. This session's two-phase live-repro (ASAN + gdb watchpoint, see root_cause UPDATE) upgrades the diagnosis from 'read-site backtrace only' to 'corruption mechanism proven' (freed job_submit_data_t memory gets recycled by malloc for unrelated Cap'n Proto decode buffers on other threads; any surviving stale pointer to the old object then reads garbage matching whatever now occupies that memory) but the actual SOURCE of the stale pointer/second-reader is still not isolated. NEXT STEP, sharpened from this session's two leads: (1) audit sched_on_job_array()'s per-element dedup check (handler.c ~212) for a race window against a redelivered/retried array push (job not yet added to sched->jobs at submit time, only later inside core_build_job()/sched_add_job()); (2) audit core_build_schedobj() and its 3 tag-dispatch helpers (core_events.c:110-197) for any raw pointer stored into the long-lived xce_sched_obj_t/xce_sched_job_t that aliases (rather than deep-copies via makeString()) memory owned by the short-lived original xce_job_t/job_submit_data_t, which release_translated_payload() frees shortly after core_build_job() returns.\n\nUPDATE (2026-08-29, two side-bugs found during this investigation FIXED -- bug-1714's OWN root cause remains UNFIXED, see this session's root_cause UPDATE above and the still-open leads there): while chasing this bug's stale-pointer UAF, static code reading (not live repro) surfaced two SEPARATE, independently-confirmed defects, real bugs on their own merits, not proven to BE this bug's own root cause. Both now fixed with TDD (RED->GREEN) and full regression evidence.\n\nBug A -- xce_core_push_events()'s JOBS_PUSH case (src/scheduler/src/core_events.c, the XCE_CORE_EVENT_JOBS_PUSH switch case) never checked sched_add_job()'s return value. sched_add_job() (core.c:219) is a thin wrapper around key_add(core->jobs, jobid, job), which returns a negative errno (duplicate-jobid class failure) if the jobid already exists -- previously silently discarded, so a freshly-built xce_sched_job_t that FAILED to register in core->jobs was still handed to picker->picker_iface->on_job_push() anyway: an orphaned job object the picker now tracks but that sched_get_job()/any other core->jobs-keyed lookup can never find again. FIX: check sched_add_job()'s return value; on failure, skip the on_job_push() call, log a WARN (matching this case's existing WARN convention for the job==NULL branch), and free the orphaned job at the same granularity core_build_job()'s own early-failure paths already use (FREEUP(job->resreq); FREEUP(job->schedobj); FREEUP(job);) -- job->user/queue/project deliberately left alone (kvmgr-owned get-or-create lookups, not owned by this job instance); job->allocs/accounts deliberately left alone too (out of scope -- xce_sched_job_t has no complete destructor anywhere in this codebase; kill_sched_job() in schedobj.c only frees job->rusages, a genuine pre-existing gap this fix does not attempt to close). TDD: RED -- added test_jobs_push_duplicate_jobid_does_not_call_on_job_push_or_leak to src/scheduler/testsuite/test_core_events.c (pushes one job successfully, baseline on_job_push count 1, then pushes a second JOBS_PUSH batch with the SAME jobid); on unfixed code this failed with 'Expected 1 Was 2' (on_job_push fired a second time for the orphaned duplicate), confirming the bug. GREEN -- after the fix, the same test passes: on_job_push count stays at 1, and sched_get_job() for that jobid still returns the ORIGINAL job object, not the duplicate.\n\nBug B -- sched_on_job_array()'s per-element dedup check (src/scheduler/src/handler.c ~line 179-226) has a TOCTOU race window: it runs on the network request-handling thread and checks sched_get_job() against core->jobs, but a job is only actually inserted into core->jobs later, when the separate DRIVER thread drains the pending-update queue and calls xce_core_push_events() -> JOBS_PUSH -> sched_add_job(). A redelivered (e.g. network-retried) copy of the same array push arriving on the request thread during that window is not caught by this check, so a second, independent set of xce_job_t/job_submit_data_t clones for the same jobids gets constructed and enqueued too. Per this session's analysis, eliminating the race itself (e.g. a new synchronized pending-jobids set) was deliberately NOT attempted -- out of scope, bigger architectural change, own risk -- because it is not actually necessary: once Bug A is fixed, this race is SAFE rather than dangerous, since the redelivered duplicate is now correctly and safely rejected at the authoritative uniqueness boundary (sched_add_job()'s key_add()), freed, and never reaches the picker. FIX: documentation only, no logic change -- added a comment on the dedup check explaining the race window, that it is a best-effort optimization (not a correctness boundary), and that sched_add_job()'s key_add() (now correctly handled per Bug A) is the actual authoritative dedup boundary a redelivered duplicate ultimately hits. No test needed (no behavior change); covered indirectly by Bug A's test, which models exactly the duplicate-jobid scenario this race can produce.\n\nFull regression (nix develop ./src --command bash src/tools/xce-build.sh scheduler asan --incremental): 54/55 scheduler test suites pass. The one remaining failure, test_recordstart_symlink_escape_replies_error in test_admin_request.c (expected 'invalid record file name', got 'permission denied accessing record file'), is the already-known, pre-existing bug-1561-adjacent sandbox filesystem-permissions flake, unrelated to and unaffected by this change -- present identically before these fixes were applied (also seen in the RED run). IMPORTANT: these two fixes are scoped, standalone correctness fixes for real, independently-confirmed defects -- they do NOT resolve bug-1714's own root cause (the stale-pointer UAF into a freed job_submit_data_t, see root_cause above). That remains open; the two still-open leads listed in this entry's prior fix UPDATE (2026-08-29) are what a future session should pursue next, now narrowed since lead (1) [sched_on_job_array()'s dedup race] has been read closely enough to conclude it is not itself hazardous post-Bug-A -- lead (2) [core_build_schedobj()'s makeString()-vs-alias handling] remains the live suspect.\n\nUPDATE (2026-08-30): STILL NOT FIXED -- no fix attempted this session (per this entry's own 'do not attempt a speculative fix without a confirmed root cause' guidance). This session's Part 1 static audit ruled out the XceData_data_schedjobs dataset->rows aliasing as a second UAF class (see root_cause UPDATE). Part 2's live pointer-lifecycle instrumentation did not capture a fresh crash despite ~20+ burst waves substantially exceeding the historically-successful recipe's intensity, but did surface a new, real, independently-reproducible finding: array-job jobids get redelivered to the scheduler via the ordinary single-job XceData_data_schedjobs/JOBS_PUSH path many times (up to 18x observed) after their original array-path submission, confirmed unrelated to client-side retries (reproduced with zero client submission failures). Bug A (this same entry, prior session) correctly discards every one of these before they reach the picker, so this redelivery is not itself a proven crash cause, but it is a strong candidate AMPLIFYING factor for the previously-proven malloc-reuse race (more job_submit_data_t churn = more opportunities to hit the race) and a concrete, scoped lead for a follow-up session (see root_cause UPDATE's 'NEXT STEP'). All temporary diagnostic instrumentation was fully reverted (verified via git diff + full re-run of the scheduler ASAN test suite: 54/55, same pre-existing flake as before). No code changes remain in the working tree from this session.\n\nUPDATE (2026-08-30, later same day): STILL NOT FIXED, STILL NOT REPRODUCED. Tried the large-ASAN-quarantine idea this entry's own root_cause section flagged as untried (quarantine_size_mb=256:redzone=256:max_redzone=2048, launched via already-built binaries, no rebuild) against a controller+scheduler-only cluster (no worker -- confirmed unnecessary for this specific crash's call chain, which fires entirely at JOBS_PUSH submission-ingestion time). 64 waves / 25,600 array elements over ~8 minutes, an order of magnitude more throughput than the original 150s/300-element capture: zero crash, zero ASAN reports of any kind, and (new, separate negative finding) zero recurrence of the morning session's reliably-observed redelivery-storm WARN either. Ruling nothing new out beyond what's already documented -- this is a THIRD consecutive session-day attempt (after the 08-29 post-fix session and the 08-30-morning session) where heavy live load did not reproduce a symptom that DID reproduce reliably in the two original capturing sessions (bug-1731's live-repro session and this entry's own 08-29 post-fix Phase-1/Phase-2 session), now across three different techniques (plain heavy load, gdb-wrapped heavy load with diagnostic instrumentation, and now large-quarantine ASAN). NEXT STEP suggestion, sharpened by three failed-to-reproduce sessions in a row: the two ORIGINAL successful captures both happened on 2026-08-29, before commit 38437e57 (Bug A) and its sibling Bug B documentation landed the same day, and EVERY session since (including this one) has been AFTER those fixes landed. While Bug A/B were carefully reasoned to be independent of bug-1714's own root cause (see this entry's history), the fact that reproduction rate appears to have dropped sharply coincident with their landing -- both the crash itself AND the previously-reliable redelivery-storm symptom now failing to reproduce under comparable or heavier load -- is a pattern worth taking seriously rather than dismissing as noise. Concrete suggestion for a follow-up session: (a) try reverting JUST commit 38437e57 (Bug A's fix) in a throwaway branch/build and re-run this exact large-quarantine-ASAN recipe against pre-Bug-A code, to directly test whether Bug A's fix (or the TOCTOU race it interacts with) was itself part of what made the race window practically hittable, rather than assuming independence holds; (b) if pre-Bug-A code DOES still crash under this recipe while post-Bug-A does not, that would suggest Bug A's fix (checking sched_add_job()'s return and discarding the duplicate instead of silently handing it to the picker) also incidentally narrows or closes bug-1714's own race window as a side effect worth understanding precisely rather than just accepting as an unexplained improvement. Both this session's build artifacts (src/xce.build.bug1714xa, a from-scratch xceadmin build with wheel+venv) were left in place (not cleaned up, unlike the temp deploy dir and processes) since they represent real, reusable build work with no live-process footprint.", + "fix": "STILL NOT FIXED -- but no longer blocked on evidence collection; see root_cause UPDATE above for the first captured backtrace. NEXT STEP: find what writes garbage into job_submit_data_t->project_name after clone_job_submit_data() allocates it -- likely somewhere in the array-job batching/event-translation path (xce_core_push_events / xce_sched_driver_translate_pending_events) given the crash hit specifically while processing event index 2 of a 6-event batch under heavy concurrent array-job load. Reproduction recipe confirmed reliable enough to use again: debug-profile build, xce_scheduler launched via `gdb -batch -ex run -ex \"thread apply all bt full\"` from process start (script preserved at /tmp/xce-deploy-bug1731/scripts/start-scheduler-gdb.sh), 6 concurrent 50-element array submissions against a live 3-node HA cluster -- crashed within 150s this run.\n\nUPDATE (2026-08-29): STILL NOT FIXED. This session's two-phase live-repro (ASAN + gdb watchpoint, see root_cause UPDATE) upgrades the diagnosis from 'read-site backtrace only' to 'corruption mechanism proven' (freed job_submit_data_t memory gets recycled by malloc for unrelated Cap'n Proto decode buffers on other threads; any surviving stale pointer to the old object then reads garbage matching whatever now occupies that memory) but the actual SOURCE of the stale pointer/second-reader is still not isolated. NEXT STEP, sharpened from this session's two leads: (1) audit sched_on_job_array()'s per-element dedup check (handler.c ~212) for a race window against a redelivered/retried array push (job not yet added to sched->jobs at submit time, only later inside core_build_job()/sched_add_job()); (2) audit core_build_schedobj() and its 3 tag-dispatch helpers (core_events.c:110-197) for any raw pointer stored into the long-lived xce_sched_obj_t/xce_sched_job_t that aliases (rather than deep-copies via makeString()) memory owned by the short-lived original xce_job_t/job_submit_data_t, which release_translated_payload() frees shortly after core_build_job() returns.\n\nUPDATE (2026-08-29, two side-bugs found during this investigation FIXED -- bug-1714's OWN root cause remains UNFIXED, see this session's root_cause UPDATE above and the still-open leads there): while chasing this bug's stale-pointer UAF, static code reading (not live repro) surfaced two SEPARATE, independently-confirmed defects, real bugs on their own merits, not proven to BE this bug's own root cause. Both now fixed with TDD (RED->GREEN) and full regression evidence.\n\nBug A -- xce_core_push_events()'s JOBS_PUSH case (src/scheduler/src/core_events.c, the XCE_CORE_EVENT_JOBS_PUSH switch case) never checked sched_add_job()'s return value. sched_add_job() (core.c:219) is a thin wrapper around key_add(core->jobs, jobid, job), which returns a negative errno (duplicate-jobid class failure) if the jobid already exists -- previously silently discarded, so a freshly-built xce_sched_job_t that FAILED to register in core->jobs was still handed to picker->picker_iface->on_job_push() anyway: an orphaned job object the picker now tracks but that sched_get_job()/any other core->jobs-keyed lookup can never find again. FIX: check sched_add_job()'s return value; on failure, skip the on_job_push() call, log a WARN (matching this case's existing WARN convention for the job==NULL branch), and free the orphaned job at the same granularity core_build_job()'s own early-failure paths already use (FREEUP(job->resreq); FREEUP(job->schedobj); FREEUP(job);) -- job->user/queue/project deliberately left alone (kvmgr-owned get-or-create lookups, not owned by this job instance); job->allocs/accounts deliberately left alone too (out of scope -- xce_sched_job_t has no complete destructor anywhere in this codebase; kill_sched_job() in schedobj.c only frees job->rusages, a genuine pre-existing gap this fix does not attempt to close). TDD: RED -- added test_jobs_push_duplicate_jobid_does_not_call_on_job_push_or_leak to src/scheduler/testsuite/test_core_events.c (pushes one job successfully, baseline on_job_push count 1, then pushes a second JOBS_PUSH batch with the SAME jobid); on unfixed code this failed with 'Expected 1 Was 2' (on_job_push fired a second time for the orphaned duplicate), confirming the bug. GREEN -- after the fix, the same test passes: on_job_push count stays at 1, and sched_get_job() for that jobid still returns the ORIGINAL job object, not the duplicate.\n\nBug B -- sched_on_job_array()'s per-element dedup check (src/scheduler/src/handler.c ~line 179-226) has a TOCTOU race window: it runs on the network request-handling thread and checks sched_get_job() against core->jobs, but a job is only actually inserted into core->jobs later, when the separate DRIVER thread drains the pending-update queue and calls xce_core_push_events() -> JOBS_PUSH -> sched_add_job(). A redelivered (e.g. network-retried) copy of the same array push arriving on the request thread during that window is not caught by this check, so a second, independent set of xce_job_t/job_submit_data_t clones for the same jobids gets constructed and enqueued too. Per this session's analysis, eliminating the race itself (e.g. a new synchronized pending-jobids set) was deliberately NOT attempted -- out of scope, bigger architectural change, own risk -- because it is not actually necessary: once Bug A is fixed, this race is SAFE rather than dangerous, since the redelivered duplicate is now correctly and safely rejected at the authoritative uniqueness boundary (sched_add_job()'s key_add()), freed, and never reaches the picker. FIX: documentation only, no logic change -- added a comment on the dedup check explaining the race window, that it is a best-effort optimization (not a correctness boundary), and that sched_add_job()'s key_add() (now correctly handled per Bug A) is the actual authoritative dedup boundary a redelivered duplicate ultimately hits. No test needed (no behavior change); covered indirectly by Bug A's test, which models exactly the duplicate-jobid scenario this race can produce.\n\nFull regression (nix develop ./src --command bash src/tools/xce-build.sh scheduler asan --incremental): 54/55 scheduler test suites pass. The one remaining failure, test_recordstart_symlink_escape_replies_error in test_admin_request.c (expected 'invalid record file name', got 'permission denied accessing record file'), is the already-known, pre-existing bug-1561-adjacent sandbox filesystem-permissions flake, unrelated to and unaffected by this change -- present identically before these fixes were applied (also seen in the RED run). IMPORTANT: these two fixes are scoped, standalone correctness fixes for real, independently-confirmed defects -- they do NOT resolve bug-1714's own root cause (the stale-pointer UAF into a freed job_submit_data_t, see root_cause above). That remains open; the two still-open leads listed in this entry's prior fix UPDATE (2026-08-29) are what a future session should pursue next, now narrowed since lead (1) [sched_on_job_array()'s dedup race] has been read closely enough to conclude it is not itself hazardous post-Bug-A -- lead (2) [core_build_schedobj()'s makeString()-vs-alias handling] remains the live suspect.\n\nUPDATE (2026-08-30): STILL NOT FIXED -- no fix attempted this session (per this entry's own 'do not attempt a speculative fix without a confirmed root cause' guidance). This session's Part 1 static audit ruled out the XceData_data_schedjobs dataset->rows aliasing as a second UAF class (see root_cause UPDATE). Part 2's live pointer-lifecycle instrumentation did not capture a fresh crash despite ~20+ burst waves substantially exceeding the historically-successful recipe's intensity, but did surface a new, real, independently-reproducible finding: array-job jobids get redelivered to the scheduler via the ordinary single-job XceData_data_schedjobs/JOBS_PUSH path many times (up to 18x observed) after their original array-path submission, confirmed unrelated to client-side retries (reproduced with zero client submission failures). Bug A (this same entry, prior session) correctly discards every one of these before they reach the picker, so this redelivery is not itself a proven crash cause, but it is a strong candidate AMPLIFYING factor for the previously-proven malloc-reuse race (more job_submit_data_t churn = more opportunities to hit the race) and a concrete, scoped lead for a follow-up session (see root_cause UPDATE's 'NEXT STEP'). All temporary diagnostic instrumentation was fully reverted (verified via git diff + full re-run of the scheduler ASAN test suite: 54/55, same pre-existing flake as before). No code changes remain in the working tree from this session.\n\nUPDATE (2026-08-30, later same day): STILL NOT FIXED, STILL NOT REPRODUCED. Tried the large-ASAN-quarantine idea this entry's own root_cause section flagged as untried (quarantine_size_mb=256:redzone=256:max_redzone=2048, launched via already-built binaries, no rebuild) against a controller+scheduler-only cluster (no worker -- confirmed unnecessary for this specific crash's call chain, which fires entirely at JOBS_PUSH submission-ingestion time). 64 waves / 25,600 array elements over ~8 minutes, an order of magnitude more throughput than the original 150s/300-element capture: zero crash, zero ASAN reports of any kind, and (new, separate negative finding) zero recurrence of the morning session's reliably-observed redelivery-storm WARN either. Ruling nothing new out beyond what's already documented -- this is a THIRD consecutive session-day attempt (after the 08-29 post-fix session and the 08-30-morning session) where heavy live load did not reproduce a symptom that DID reproduce reliably in the two original capturing sessions (bug-1731's live-repro session and this entry's own 08-29 post-fix Phase-1/Phase-2 session), now across three different techniques (plain heavy load, gdb-wrapped heavy load with diagnostic instrumentation, and now large-quarantine ASAN). NEXT STEP suggestion, sharpened by three failed-to-reproduce sessions in a row: the two ORIGINAL successful captures both happened on 2026-08-29, before commit 38437e57 (Bug A) and its sibling Bug B documentation landed the same day, and EVERY session since (including this one) has been AFTER those fixes landed. While Bug A/B were carefully reasoned to be independent of bug-1714's own root cause (see this entry's history), the fact that reproduction rate appears to have dropped sharply coincident with their landing -- both the crash itself AND the previously-reliable redelivery-storm symptom now failing to reproduce under comparable or heavier load -- is a pattern worth taking seriously rather than dismissing as noise. Concrete suggestion for a follow-up session: (a) try reverting JUST commit 38437e57 (Bug A's fix) in a throwaway branch/build and re-run this exact large-quarantine-ASAN recipe against pre-Bug-A code, to directly test whether Bug A's fix (or the TOCTOU race it interacts with) was itself part of what made the race window practically hittable, rather than assuming independence holds; (b) if pre-Bug-A code DOES still crash under this recipe while post-Bug-A does not, that would suggest Bug A's fix (checking sched_add_job()'s return and discarding the duplicate instead of silently handing it to the picker) also incidentally narrows or closes bug-1714's own race window as a side effect worth understanding precisely rather than just accepting as an unexplained improvement. Both this session's build artifacts (src/xce.build.bug1714xa, a from-scratch xceadmin build with wheel+venv) were left in place (not cleaned up, unlike the temp deploy dir and processes) since they represent real, reusable build work with no live-process footprint.\n\nUPDATE (2026-09-04, live-repro session -- CRASH REPRODUCED, major new causal-chain finding, still no confident fix): Built an isolated debug profile (controller/scheduler/worker/xceadmin) into src/xce.build.bug1714repro specifically to avoid a concurrently-running interactive session also building/testing in this same worktree (tmux 'scheduler-1') -- deployed a fresh 3-node cluster on ports 9971-9973 (/tmp/xce-deploy-1714), launched xce_scheduler under `gdb -batch -ex run -ex \"thread apply all bt full\"` from process start, then drove the same recipe as the two original successful captures: 6 concurrent `jobsub -a 50` array submissions (300 elements) via xce_test against the live cluster.\n\nCRASH REPRODUCED, ~12s after the burst started (faster than either prior successful capture). Identical signature to every previous occurrence, byte-for-byte: SIGSEGV in sched_get_project (core.c:412), name=0x41d0000000000000 (same corrupted-double bit pattern), called from core_build_job (core_events.c:222) <- xce_core_push_events (core_events.c:754, this time on event index 16 of a 67-event batch, vs the original capture's index 2 of 6) <- xce_sched_driver_translate_pending_events (driver.c:555) <- xce_sched_driver_run_normal_mode_round (driver.c:749) <- main (main.c:465). All 9 other threads idle in a blocking syscall at fault time (same as every prior capture) -- confirms again this is a stale READ of already-corrupted memory, not a live cross-thread write race at the fault site itself.\n\nMAJOR NEW FINDING (not identified or looked for in any of the 6 prior sessions): the scheduler's connection to the primary controller GENUINELY, REPEATEDLY DROPS AND RECONNECTS under this exact burst load -- confirmed independently on BOTH sides of the connection, not a hypothesis:\n - SCHEDULER side: this session's build included the bug-1760 partial fix (sched_check_pending_rejoin() called every round from main.c, logs on success/failure). During the ~12s burst window, it logged 'pending rejoin succeeded, cluster membership restored' SEVEN times (03:38:03-03:38:07), each preceded by scheduler.log's own `xcecli_retry_next: xcecli failover: attempt N -> localhost:99xx` lines showing the client library actively rotating through all 3 candidates.\n - CONTROLLER side (ctrl-1, the primary throughout -- confirmed via `RAFT[p0] term=2 event=...` staying at term=2 the whole burst, i.e. this is NOT a controller-cluster election/failover, ctrl-1 never lost leadership): sched.c's handle_scheduler_leave() ('scheduler leave') fires repeatedly, each one immediately followed by a fresh `server sock 4 accepted 13` (a brand-new TCP accept, confirmed via a different priv-data/endpoint pointer each time) -- i.e. genuinely new connections, not the same one persisting.\n - LIKELY TRIGGER, evidenced but not yet proven with byte-level certainty: ctrl-1's own persist_submit_job_array_async() logged 'lsn=6/7/8/9 appended but commit_submit_async registration failed (rc=-10013)' (E_XCE_NOT_READY -- see bug-1713's own decoding of this same errno) at 03:37:56.346, ~300ms before the scheduler's first observed failover attempt (03:37:56.632) -- i.e. the PRIMARY CONTROLLER itself was under registration/commit backpressure from the burst of 5 near-simultaneous 50-element array submissions at that exact moment. The most likely mechanism: ctrl-1, busy with WAL/commit backpressure, delays some response the scheduler's client library is waiting for past its own retry/timeout threshold; XCECLI_FAILOVER_CALL's client-side timeout-and-rotate logic (a deliberate, correct behavior in isolation) then treats this as 'candidate unresponsive' and fails over -- to OTHER, non-primary candidates, which correctly redirect it back, so it rejoins ctrl-1 again shortly after. This is a legitimate committed-backpressure symptom being misread as a connection failure, not memory corruption in itself.\n\nWHY THIS MATTERS FOR THIS BUG: every one of these reconnects fires on_scheduler_join() (sched.c:742) controller-side, which unconditionally re-sends a FULL xcesched_push_jobs() resync of every committed job via the ordinary (non-array) XceData_data_schedjobs wire path -- the EXACT mechanism the 2026-08-30 session's 'redelivery-storm' finding observed (array-job jobids redelivered via the single-job JOBS_PUSH path up to 18x per jobid) but could not explain the source of. This session's finding directly explains it: 7 reconnects in 12s here would scale to easily 18+ over a longer/heavier session. Each full resync constructs an entirely fresh set of job_submit_data_t/xce_job_t clones (decode_JobSubmitData_ptr(), independent heap allocations per PART 1's own prior static-analysis finding) for EVERY committed job, all safely discarded by Bug A's sched_add_job() dedup on the scheduler side -- but this churns a much higher volume of same-shaped job_submit_data_t alloc/free cycles under concurrent capnp-decode pressure than array-job load alone would produce, which is exactly the amplifying condition the 2026-08-29 watchpoint session proved is necessary for the malloc-reuse UAF (a freed job_submit_data_t chunk reused by an unrelated concurrent decode on another thread) to actually get hit.\n\nWHAT STILL IS NOT FOUND: the actual second, stale reader -- i.e. which specific code path retains a pointer to a job_submit_data_t (or its containing xce_job_t) PAST its own correct one-time processing+free, and reads it again later. This session did not have time to also capture a fresh gdb watchpoint trace (PHASE 2 style, 2026-08-29 precedent) to nail that down given how much of the session went into establishing the reconnect-storm causal chain above; the batch gdb run (-ex run -ex 'thread apply all bt full' -ex quit) auto-quit after the crash, so no live interactive follow-up was possible against this specific capture.\n\nNO FIX ATTEMPTED this session (per this entry's own established 'do not attempt a speculative fix without a confirmed root cause' guidance, followed again here) -- the reconnect-storm mechanism is a strong, well-evidenced AMPLIFYING factor, not yet the root cause of the UAF itself.\n\nNEXT STEPS, sharpened and now much more concrete than before:\n(1) The reconnect-storm itself may be its own separate, worthwhile fix regardless of bug-1714: investigate why ctrl-1's commit/registration backpressure under a burst of concurrent array submissions is severe enough to trip the scheduler client's failover timeout even though ctrl-1 never actually loses leadership -- possibly a client-side timeout tuned too aggressively for this load pattern, or a controller-side responsiveness gap under WAL/commit pressure worth its own investigation (cross-reference bug-1713's E_XCE_NOT_READY history). Fixing or tuning this would likely reduce (not necessarily eliminate) bug-1714's own reproduction rate as a side effect, the same way Bug A/B's landing seemed to reduce it, per the 2026-08-30 session's own observation.\n(2) To find the actual stale-pointer read site: repeat this session's exact recipe (now confirmed reliable again, ~12s to crash) but with a scripted gdb watchpoint pass (PHASE 2 precedent, 2026-08-29 session) armed BEFORE the burst starts, on several job_submit_data_t->project_name fields sampled from make_array_element() calls, to catch the actual write-after-free this time under the now-better-understood load conditions.\n(3) Given the crash this session hit event index 16 of a 67-event batch (previous captures: index 2 of 6, and index unspecified in the 2026-08-29 session) -- worth checking whether crash position scales with reconnect-storm-driven batch size (more concurrent JOBS_PUSH full-resync traffic -> larger translate_pending_events batches -> more job_submit_data_t churn per batch -> proportionally higher crash odds within a batch), which would further support the amplification theory quantitatively.\n\nCleanup: isolated build dir (src/xce.build.bug1714repro) and deploy dir (/tmp/xce-deploy-1714) left in place (reusable, no live-process footprint) -- all started processes (3x xce_controller, 1x xcecd_virtual, xce_scheduler + its gdb wrapper) confirmed killed via ps aux before this session ended.", "tags": [ "scheduler", "segfault", @@ -19534,14 +19534,20 @@ "redelivery-storm-found", "live-repro-not-captured-2026-08-30", "large-quarantine-asan-tried-no-repro-2026-08-30", - "redelivery-storm-also-not-reproduced-2026-08-30" + "redelivery-storm-also-not-reproduced-2026-08-30", + "reconnect-storm-confirmed", + "live-repro-2026-09-04", + "crash-reproduced", + "e-xce-not-ready-correlated", + "amplification-mechanism-found", + "stale-reader-still-unknown" ], "related_bugs": [ "bug-1699", "bug-1731" ], - "occurrences": 6, - "last_seen": "2026-08-30T14:00:00Z" + "occurrences": 7, + "last_seen": "2026-09-04T00:00:00Z" }, { "id": "bug-1715", @@ -20036,7 +20042,7 @@ "error_message": "PRIORITY: HIGH -- affects data the scheduler needs for resource-usage-aware scheduling decisions (see priority note below). Split 2026-08-30 from a broader initial report into this (core usage: memory + CPU time) and bug-1736 (display-only statistics: swap, task count, peak/efficiency percentages) at user request, since the two have very different urgency and the broader one should not block this one.\n\nUser-reported: job memory usage always shows 0 in the scheduler's simulation record file (.replay), despite the worker daemon presumably measuring real resource usage. User asked to check whether the worker even reports this data at all -- CONFIRMED: it does, but the value never survives to the controller due to a plain resource-name string mismatch, plus a second, independent gap in how the controller aggregates whatever it does receive.", "file": "src/worker/src/xcecd_cgroups.c (collect_job_rusages, line ~1418-1436 -- the worker-side cgroup-based measurement and resname assignment), src/controller/misc.c (update_host_runusage, line ~128-138 -- the controller-side parser), src/controller/job.c (update_job_rusages, line ~3200 -- pre-existing 'FIXME update other fields of job rusage later' comment), src/scheduler/include/sched/types.h:115 (xce_sched_job_t.rusages -- confirmed the scheduler stores/forwards the RAW xce_job_rusages_t wire report unmodified, does not itself re-parse or aggregate it), src/scheduler/src/recording_events.c:142 (wire.body.job_rusage = ev->u.job_rusage.rusages -- confirms the .replay file records whatever raw resname/value pairs it received, unchanged)", "root_cause": "TWO CONFIRMED, INDEPENDENT GAPS -- either alone would produce 'memory usage always 0'; both are real. Neither was live-verified this session (no real cgroup-backed xcecd deployment was exercised -- see the environment-limitation note below), but both are confirmed by direct code reading with exact citations, and there is NO translation/mapping layer anywhere between the two mismatched naming conventions (grepped the whole worker/controller/lib/scheduler source tree for both string sets -- only the two sites below reference them at all).\n\nFINDING 1 (the primary, most likely explanation): resource-name string mismatch between producer and consumer. collect_job_rusages() (xcecd_cgroups.c, the REAL, cgroup/systemd-backed worker's rusage collector -- queries a job's own 'xcecd-worker-.service' systemd unit via sd_bus_open_system()) reports exactly 4 resnames: 'cpu_time_sec', 'memory_rss', 'memory_swap', 'tasks_current'. update_host_runusage() (misc.c, the controller-side parser that receives this over the wire) only recognizes the LITERAL strings 'cputime' and 'mem' -- neither of which matches ANY of the 4 names the worker actually sends. Every rusage report from the real worker therefore falls through both `if (strcmp(...))` checks doing nothing, silently, for every single field -- host_runusage[j]->cpu_time and ->mem_usage stay at their calloc-zeroed default FOREVER, regardless of what the worker's cgroup query actually measured. No error, no log, no indication anything was dropped -- this is why it reads as 'always 0' rather than an obvious failure.\n\nFINDING 2 (independent, compounding): even if Finding 1 were fixed and host_runusage[]'s PER-HOST fields started populating correctly, the TOP-LEVEL AGGREGATE fields of xce_job_runusage_t (max_mem, avg_mem, used_mem, cpu_time, peak_cpu_time, peak_cpu_duration, mem_efficiency, avg_cpu_efficiency, peak_cpu_efficiency) are NEVER computed from the per-host breakdown anywhere -- update_job_rusages() (job.c) calls update_host_runusage() (which only touches host_runusage[]) then has an explicit, still-open '/* FIXME update other fields of job rusage later */' comment immediately after, with no code implementing that FIXME anywhere in this codebase (grepped). Any downstream consumer that reads the AGGREGATE fields (rather than iterating host_runusage[] itself) would see 0 regardless of Finding 1's fix.\n\nSCHEDULER-SIDE STRUCTURE NOTE (relevant context, not itself a bug): the scheduler does NOT receive or store the aggregated xce_job_runusage_t at all -- xce_sched_job_t.rusages (sched/types.h:115) is typed xce_job_rusages_t*, the SAME flat wire-report struct the worker originally sent (jobid/npids/pids/count/usages[] of raw {resname,value} pairs) -- forwarded/stored as-is, and recording_events.c's capnp encode for the .replay file writes that same raw struct unchanged. So the .replay file the user is inspecting genuinely contains whatever resname/value pairs the worker sent, byte for byte -- if Finding 1 is fixed (or the worker already sent matching names), the RAW data WOULD flow all the way into the recording faithfully. Grepped src/scheduler/src/repl*.c for any resname-aware rendering of memory usage in the interactive REPL/inspect commands and found NONE -- could not determine within this session's time budget whether the specific tool/view the user used to inspect the .replay file (unclear from the report whether it's the live REPL's own display, a separate dump/analysis tool, or something else) has ITS OWN resname expectation that might differ yet again from both 'mem' and 'memory_rss' -- flagged as an open question for whoever picks this up, not confirmed either way.\n\nENVIRONMENT LIMITATION NOTE: this session's own live burst-testing (bug-1714 investigation) exclusively used xcecd_virtual (the no-root virtual worker), never the real, cgroup/systemd-backed xcecd binary collect_job_rusages() lives in -- this sandbox has no D-Bus/systemd (already confirmed in this session's bug-1731 follow-up work: get_systemd_job_exit_code() always returns -1 here), so sd_bus_open_system() at collect_job_rusages()'s own first real step would itself fail immediately in this environment (returns NULL before ever reaching the resname assignment code) -- this bug could not have been, and was not, live-reproduced in this sandbox; it is a pure static-code finding, applicable specifically to the user's own real deployment (which does have real cgroups/systemd, matching the user's own 'live deployment' framing throughout this investigation).\n\nPRIORITY NOTE (2026-08-30, user request): this half of the original finding -- memory (memory_rss/'mem') and CPU time (cpu_time_sec/'cputime') specifically -- is the HIGH-PRIORITY half. These are exactly the two metrics xce_host_runusage_t already has dedicated fields for (cpu_time, mem_usage) and the two the controller's parser already has matching (if misspelled) if-branches for -- clearly the originally-intended 'core' usage metrics, as opposed to the swap/task-count/peak/efficiency fields split out to bug-1736, which have no controller-side field or computation logic at all today. IMPORTANT CAVEAT, checked directly this session: grepped the full scheduler source tree for any consumer of rusage/usage data in scheduling/picker/allocation logic and found NONE -- xce_sched_job_t.rusages (sched/types.h:115) is stored and forwarded into recordings but not read by any picker plugin or allocation code today. So this fix corrects the DATA PIPELINE (worker measurement -> controller aggregation -> scheduler storage/recording), the necessary prerequisite for any future usage-aware scheduling policy (e.g. backfill sizing, over-commit detection, preemption on real memory pressure) -- it does not itself wire usage data into a scheduling decision, since no such consumer exists yet. Marked high priority on that basis (unblocks correct data for future scheduling work, and is also simply a correctness bug in its own right for any operator-facing usage reporting), not because it changes scheduling behavior today.", - "fix": "NOT FIXED -- logged for follow-up, scope narrowed 2026-08-30 to memory + CPU time only (see bug-1736 for the split-off lower-priority statistics). RECOMMENDED FIX, Finding 1 (resname mismatch): align 'cpu_time_sec'/'memory_rss' (worker, xcecd_cgroups.c) with 'cputime'/'mem' (controller, misc.c) -- pick a direction (see the two options in the original finding, not repeated here) and apply consistently. RECOMMENDED FIX, Finding 2 (aggregation): implement update_job_rusages()'s (job.c) still-open FIXME specifically for max_mem/avg_mem/used_mem/cpu_time -- derive from host_runusage[]'s per-host entries each time a report merges in (max/avg/sum per field semantics). Both need TDD (unit tests, not just a live check) plus live verification against a REAL cgroup-backed xcecd deployment -- this session's sandbox has no D-Bus/systemd and cannot provide that verification itself (see the original environment-limitation note).", + "fix": "NOT FIXED -- logged for follow-up, scope narrowed 2026-08-30 to memory + CPU time only (see bug-1736 for the split-off lower-priority statistics). RECOMMENDED FIX, Finding 1 (resname mismatch): align 'cpu_time_sec'/'memory_rss' (worker, xcecd_cgroups.c) with 'cputime'/'mem' (controller, misc.c) -- pick a direction (see the two options in the original finding, not repeated here) and apply consistently. RECOMMENDED FIX, Finding 2 (aggregation): implement update_job_rusages()'s (job.c) still-open FIXME specifically for max_mem/avg_mem/used_mem/cpu_time -- derive from host_runusage[]'s per-host entries each time a report merges in (max/avg/sum per field semantics). Both need TDD (unit tests, not just a live check) plus live verification against a REAL cgroup-backed xcecd deployment -- this session's sandbox has no D-Bus/systemd and cannot provide that verification itself (see the original environment-limitation note).\n\nUPDATE (2026-09-03, verification session): CONFIRMED ALREADY FIXED. Both recommended fixes were implemented and committed 2026-08-30 (commit d8a37fa27 for this entry's resname-mismatch Finding 1; commit 5c2c6664e for bug-1736's sibling swap/task-count fields) but this entry was never marked fixed. update_host_runusage() (misc.c) now matches the worker's real resnames ('cpu_time_sec'/'memory_rss'), and aggregate_job_runusage() (misc.c) computes max_mem/avg_mem/used_mem/cpu_time/peak_cpu_time from the per-host breakdown, called from update_job_rusages() (job.c:3502) -- replacing the old FIXME. TDD unit tests exist (src/controller/testsuite/test_host_runusage.c, 7 tests covering resname matching, multi-host update-in-place, swap/task-count parsing, and aggregation single/multi-host/running-max-peak/null-safety). Re-verified this session: fresh /xce-build controller asan, all 6 controller test suites pass including 'host runusage test' (test_host_runusage.c). No code change was needed -- this session's action was verification + closing out the bug-log entry.", "tags": [ "worker", "controller", @@ -20046,7 +20052,6 @@ "resname-mismatch", "cgroups", "xcecd_cgroups", - "unfixed", "found-via-user-report", "static-analysis-only", "unreproduced-in-sandbox", @@ -20056,14 +20061,16 @@ "session-sibling-of-bug-1734", "priority-high", "split-2026-08-30", - "core-usage-metrics-only" + "core-usage-metrics-only", + "fixed", + "verified-2026-09-03" ], "related_bugs": [ "bug-1734", "bug-1736" ], "occurrences": 1, - "last_seen": "2026-08-30T10:45:00Z" + "last_seen": "2026-09-03T00:00:00Z" }, { "id": "bug-1736", @@ -20722,7 +20729,7 @@ "error_message": "Live-tested against a real 3-node HA cluster + xcecd_virtual worker + xce_scheduler (worker-rejoin-resync soak-harness development): after the CURRENT primary is killed and a NEW primary is elected+reconverged, a job submitted through the new primary stays PEND for 60+ seconds with ZERO scheduler.log activity of any kind (no WARN/INFO/ERROR, no reconnect attempt) -- not a slow recovery, a genuinely stuck one. Reproduced twice in a row with the same shape.", "file": "src/scheduler/src/scheduler.c (sched_needs_rejoin:487, sched_on_reconnect:507, sched_publish_check_rejoin:1474), src/scheduler/src/main.c", "root_cause": "CONFIRMED via source read (not yet live-instrumented/gdb-confirmed): the scheduler has NO periodic connection-liveness/reconnect check analogous to the worker daemon's checking_connection() (src/worker/src/controller_connector.c:505, called every xcecd_ctx.update_interval seconds from xcecd.c's main loop via xcecli_hello()). The scheduler's ONLY rejoin mechanism is sched_publish_check_rejoin() (scheduler.c:1474), which re-issues xcecli_join() ONLY as a side effect of its own NEXT SUCCESSFUL publish call (sched_publish_dispatch()/sched_publish_pend_reason() via sched_publish_retry_loop(), which calls sched_publish_check_rejoin() only after attempt_fn() already returned >=0). sched_needs_rejoin itself is set correctly by sched_on_reconnect() (the client library's own transparent-reconnect callback), so the SCHEDULER's own underlying connection to the cluster likely IS aware it reconnected somewhere -- but nothing forces a FRESH xcecli_join() against the actual NEW primary until the scheduler has something to publish. After a real controller failover, the scheduler has nothing queued to publish (no job ever reaches its picker/allocator, since the CONTROLLER-side registration of \"where the scheduler is\" is presumed to be live-connection-scoped state on whichever controller instance the scheduler last explicitly joined -- i.e. the dead primary -- and does not appear to carry over to the newly-elected primary), so the scheduler can never publish anything to trigger its own rejoin: a chicken-and-egg deadlock. NOT YET independently confirmed via gdb/live instrumentation which exact half of this loop is stuck (client-library-level reconnect vs. controller-side scheduler-registration loss) -- this is a plausible, evidence-consistent hypothesis from static reading + the observed symptom, not a fully root-caused finding.", - "fix": "NOT FIXED -- discovered as a side effect of unrelated worker-rejoin-resync soak-harness development; deliberately not investigated further or fixed in that session (explicit instruction: log and continue). This is a potentially serious standing HA-availability gap (every job submitted after ANY controller failover could stay PEND forever until the scheduler process is manually restarted) that deserves its own dedicated debugging investigation (e.g. /kiro-debug) scoped to component-failover-adoption's scheduler-rejoin design, ideally with live gdb/log instrumentation to confirm which half of the chicken-and-egg loop is actually broken. Pragmatic workaround adopted ONLY in the worker-rejoin-resync soak harness (.claude/skills/xce-test-ha/run-ha-soak.sh): restart the scheduler process after each round's controller failover, the same way the harness already restarts the downed CONTROLLER node -- a fresh scheduler process calls sched_init(), which tries all 3 candidates in order and joins whichever is actually reachable, sidestepping the stuck reactive-rejoin path entirely. This workaround is scoped to test infrastructure only and does NOT fix the underlying production behavior.", + "fix": "NOT FIXED -- discovered as a side effect of unrelated worker-rejoin-resync soak-harness development; deliberately not investigated further or fixed in that session (explicit instruction: log and continue). This is a potentially serious standing HA-availability gap (every job submitted after ANY controller failover could stay PEND forever until the scheduler process is manually restarted) that deserves its own dedicated debugging investigation (e.g. /kiro-debug) scoped to component-failover-adoption's scheduler-rejoin design, ideally with live gdb/log instrumentation to confirm which half of the chicken-and-egg loop is actually broken. Pragmatic workaround adopted ONLY in the worker-rejoin-resync soak harness (.claude/skills/xce-test-ha/run-ha-soak.sh): restart the scheduler process after each round's controller failover, the same way the harness already restarts the downed CONTROLLER node -- a fresh scheduler process calls sched_init(), which tries all 3 candidates in order and joins whichever is actually reachable, sidestepping the stuck reactive-rejoin path entirely. This workaround is scoped to test infrastructure only and does NOT fix the underlying production behavior.\n\nUPDATE (2026-09-04): FIXED. sched_publish_check_rejoin() (scheduler.c) renamed to sched_check_pending_rejoin() and exposed (was static) via scheduler.h. main.c's round loop (while(1) { xce_sched_driver_run_normal_mode_round(); ...; sleep(1); }) now calls sched_check_pending_rejoin(&sched) unconditionally once per ~1s round, in addition to the original reactive call sched_publish_retry_loop() still makes after a successful decision publish. This closes the chicken-and-egg deadlock: even when a round has nothing to publish (the common case right after a failover, since the new primary has no record of this scheduler having joined it), the rejoin is now retried on a bounded ~1s cadence regardless.\n\nDeliberately placed in main.c, not inside driver.c's xce_sched_driver_run_normal_mode_round() (the first attempt): driver.c is linked white-box by ~10 scheduler test binaries (sim/driver/admin-request tests) that never link scheduler.c (where sched_check_pending_rejoin/sched_needs_rejoin live) -- a driver.c call site broke all of those under -Wl,--no-undefined (undefined reference to sched_check_pending_rejoin). main.c is normal-mode-only and not linked into any test binary, so it has no such cross-boundary link cost.\n\nTDD: two new tests added to test_scheduler_decision_publish_retry.c. test_check_pending_rejoin_invoked_directly_without_a_publish() proves the renamed/exposed function works standalone (reconnect simulated via the captured xcecli_set_reconnect_handler callback, then sched_check_pending_rejoin() called directly with zero decisions ever published -- verifies retry-on-failure/clear-on-success via the existing __wrap_xcecli_join double). test_main_loop_checks_pending_rejoin_unconditionally() is a source-text scan (same technique as test_scheduler_decision_redelivery.c's existing test_no_worker_resync_symbols_in_scheduler_publish_path) proving main.c's round loop calls sched_check_pending_rejoin(&sched) unconditionally, positioned after core.stop's break check but before sleep(1) -- i.e. every live round, not gated on publish success. Full scheduler ASAN suite (fresh build, isolated build dir to avoid a concurrent session's own build in xce.build): 62/64 Ok, 1 pre-existing Fail (bug-1758, sched_core_events_test, unrelated -- belongs to scheduler-dispatch-commit spec per that entry), 1 pre-existing Timeout (scheduler backpressure test, documented known issue). sched_scheduler_decision_publish_retry_test itself: 8/8 tests pass (ASAN_OPTIONS=detect_leaks=0, this suite's established convention for fixtures that call the real sched_init() without teardown).\n\nNot independently live-verified against a real 3-node HA failover in this session (the fix is a straightforward, well-reasoned closing of a plainly-diagnosed gap -- a periodic check where only a reactive one existed -- verified by unit test rather than a live repro this time).\n\nUPDATE (2026-09-04, live-repro + partial fix session): Root cause CONFIRMED live, exactly as hypothesized. Deployed a fresh 3-node HA cluster (ports 9981-9983, /tmp/xce-deploy-bug1760), submitted a job pre-failover (dispatched and finished normally), killed the primary (ctrl-1), waited for a real PreVote election (ctrl-3 became CTRL_PRIMARY term=3), then submitted a job through the client library (which correctly redirected to the new primary -- confirmed jobsubmit ok). That job stayed PEND indefinitely with ZERO scheduler.log activity of any kind for the whole observation window, reproducing the original symptom exactly.\n\nPARTIAL FIX APPLIED: sched_publish_check_rejoin() (scheduler.c) renamed to sched_check_pending_rejoin(), made non-static (was static; now declared in scheduler.h), and called from a SECOND site: main()'s round loop (scheduler/src/main.c), unconditionally, once per ~1s round, in addition to its original reactive call from sched_publish_retry_loop() after a successful decision publish. This alone is a real, harmless improvement (any rejoin already flagged some other way is now retried within ~1s instead of only after a successful publish) but was PROVEN INSUFFICIENT by a second live test with this fix in place: the exact same stuck-PEND symptom reproduced identically, because sched_needs_rejoin was never set true in the first place -- see below.\n\nFULL ROOT CAUSE, now fully confirmed (both halves of the original open question resolved): sched_needs_rejoin is set ONLY by sched_on_reconnect(), the client library's transparent-reconnect callback, which itself only fires as a side effect of an ACTUAL xcecli_* call (XCECLI_FAILOVER_CALL/XCECLI_FF_CALL, client_internal.h) detecting a dead connection and rotating to a live candidate. An idle scheduler round -- no jobs, no queue/worker events, nothing to publish -- makes ZERO client-library calls of any kind. So after a controller failover, if the scheduler has nothing already queued, the dead connection is NEVER NOTICED by anything, sched_needs_rejoin never flips true, and no amount of checking that flag more often (the periodic-call half of the fix above) helps. This is a pure detection gap, not a retry-cadence gap.\n\nARCHITECTURAL CONFLICT DISCOVERED (this is the actual remaining blocker, not further coding): the obvious fix -- add an active liveness probe (xcecli_hello()) call to the same periodic round-loop site, mirroring the worker's own checking_connection()/xcecli_hello() pattern (controller_connector.c) -- was implemented, and DOES work: with it in place, a third live test showed the scheduler's reconnect-and-rejoin cycle firing correctly and the post-failover job dispatching. However, this directly violates an existing, deliberately-authored structural regression test: test_scheduler_connect.c's test_no_periodic_heartbeat_call_in_source (component-failover-adoption spec, task 3.3, Requirement 3 AC3), which source-text-scans scheduler.c for the literal strings 'xcecli_hello' and 'heartbeat' and fails if either appears, specifically to prevent introducing exactly this kind of periodic call. That test's own header comment reasoning: 'a stalled reconnect retry [inside such a call] could delay/stall the scheduler's own round loop' -- i.e. a probe call that blocks while the client library is mid-retry against a dead cluster could stall the ENTIRE scheduling loop (not just rejoin), which is a real, distinct hazard from the one this bug describes. Requirement 3 AC3's actual literal text ('reconnect retries shall not delay or prevent the component's own heartbeat RESPONSES to a connected controller') is about a different concern (the scheduler has no heartbeat-response obligation at all, unlike the worker, so that specific AC is satisfied trivially/by-construction for the scheduler) -- the test's blanket string-ban is a broader, self-imposed guard than the letter of that AC actually requires, and did not anticipate this bug's distinct 'the scheduler never even detects a dead connection while idle' scenario.\n\nDECISION MADE THIS SESSION: did NOT unilaterally override this existing, deliberately-tested design decision. Reverted the xcecli_hello probe (and its test-file/meson.build wrapping) back out, keeping only the harmless round-loop periodic flag-check. sched_check_pending_rejoin() now carries a doc comment explaining exactly this tension and pointing at this buglog entry.\n\nNEXT STEP (needs a design decision, not just code): either (a) amend component-failover-adoption's Requirement 3 AC3 and its guarding test to explicitly allow a BOUNDED/non-blocking reconnect-detection probe (distinct from an unbounded heartbeat-response obligation) -- e.g. a probe with a short, hard timeout that cannot stall the round loop for more than that bound -- or (b) find an alternative reconnect-detection mechanism that does not require any application-level call at all, e.g. async RDHUP-driven detection at the transport/iomgr layer for client-role (non-controller-peer) connections, matching how this project's controller-to-controller connections detect failure without polling (see ha-async-io.md) -- if such passive detection genuinely doesn't exist for client-role connections today, that itself would need to be added at the client-library layer (src/lib/client.c/xcectx.c), not scheduler.c. Whoever picks this up should re-read Requirement 3's full text (component-failover-adoption/requirements.md) and the Req-3-AC3 test's header comment before choosing, and treat this as a spec amendment, not a quiet code change.\n\nCleanup: cluster (ports 9981-9983, /tmp/xce-deploy-bug1760) fully torn down, all started processes killed, confirmed via ps aux. Full scheduler ASAN suite re-run after the revert: 63/64 pass, the sole failure being the already-logged, unrelated bug-1758.\n\nUPDATE (2026-09-04, live verification of the passive-detection fix): CONFIRMED FIXED end to end. The main session designed and implemented a second fix component this session (with the user, not unilaterally): a new public libxce accessor xcecli_is_connection_broken() (client.h/client.c) exposing the existing internal xcecli_ff_needs_reconnect() predicate (client_internal.h) -- a pure, socket-free, side-effect-free read of ctx->ctx.state == XCE_CTX_ERR, a flag ALREADY maintained asynchronously by handle_disconnect() (xcectx.c), the transport's RDHUP/EPOLLERR handler, with zero application calls involved. sched_check_pending_rejoin() (scheduler.c) now attempts xcecli_join() when EITHER sched_needs_rejoin is set OR xcecli_is_connection_broken(sched->apictx) reports true -- closing the idle-scheduler detection gap without adding any periodic active-probe call (no xcecli_hello, no heartbeat string anywhere in scheduler.c -- test_no_periodic_heartbeat_call_in_source, the Req-3-AC3 structural guard, passes unmodified).\n\nLive re-verification (fresh 3-node cluster, ports 9971-9973, ASAN build in src/xce.build.verify1760, same repro recipe as this entry's earlier 2026-09-04 live-repro session that proved the FIRST partial fix alone was insufficient): deployed cluster, confirmed a baseline job dispatches and completes normally (RUN then DONE) pre-failover. Killed ctrl-1 (the primary). New primary (ctrl-2, term=3) elected 15s later. Critically, with ZERO jobs submitted in the interim (genuinely idle scheduler, the exact scenario the first partial fix could not handle): scheduler.log shows \"sched_check_pending_rejoin: pending rejoin succeeded, cluster membership restored\" firing on its own, ~300ms after the new primary was elected -- the scheduler re-registered itself with the new primary entirely on its own initiative, with no job ever having been submitted to trigger it reactively. Confirmed this is the NEW passive-detection code path (not the old reactive one, which structurally cannot fire with zero app calls in flight). A fresh job submitted afterward through the new primary dispatched immediately (RUN within ~180ms of submission, DONE ~2s later per its own sleep duration) -- no stuck-PEND, no manual intervention. Full scheduler ASAN suite re-run in the same build: 63/64 pass, sole failure the already-logged unrelated bug-1758. New unit tests (test_is_connection_broken_* in lib/testsuite/test_libxce_retry.c; test_check_pending_rejoin_triggers_on_passive_broken_signal / test_check_pending_rejoin_no_op_when_healthy_and_no_flag in scheduler/testsuite/test_scheduler_decision_publish_retry.c) all pass. Cluster fully torn down, all processes killed, confirmed via ps aux -- zero xce_controller/xce_scheduler/xcecd processes remain.\n\nThis closes bug-1760 -- both halves (reactive + passive detection) are now live-verified, not just unit-tested.", "tags": [ "scheduler", "ha", @@ -20733,13 +20740,19 @@ "sched_publish_check_rejoin", "chicken-and-egg", "discovered-live", - "needs-debug", - "not-fixed", - "severity-high-suspected" + "severity-high-suspected", + "fixed", + "verified-2026-09-04", + "partially-diagnosed", + "live-repro-confirmed-2026-09-04", + "blocked-on-design-decision", + "req-3-ac3-conflict", + "needs-spec-amendment", + "live-verified-2026-09-04" ], "related_bugs": [], - "occurrences": 2, - "last_seen": "2026-09-02T04:10:00Z" + "occurrences": 3, + "last_seen": "2026-09-04T00:00:00Z" }, { "id": "bug-1761", @@ -20845,4 +20858,4 @@ "last_seen": "2026-09-03T14:51:54Z" } ] -} \ No newline at end of file +} diff --git a/src/include/client.h b/src/include/client.h index 7d77f071..39330fee 100644 --- a/src/include/client.h +++ b/src/include/client.h @@ -51,6 +51,20 @@ extern int xcecli_wakeup(xcecli_ctx_t, int); extern int xcecli_hello(xcecli_ctx_t, char*); extern int xcecli_nop(xcecli_ctx_t); extern int xcecli_heartbeat(xcecli_ctx_t, int); +/* + * xcecli_is_connection_broken (bug-1760) - PURE, socket-free, side-effect-free + * query: has the transport been detected dead since the last successful + * (re)connect? Mirrors the private xcecli_ff_needs_reconnect() predicate + * (client_internal.h) exactly, exposed publicly so a consumer's own idle + * loop can passively check for a dead connection -- with ZERO network I/O + * and zero blocking risk -- instead of periodically probing a possibly- + * healthy one. The underlying signal (ctx->state == XCE_CTX_ERR) is set + * asynchronously by the transport's own RDHUP/EPOLLERR handler + * (handle_disconnect(), xcectx.c) the instant the connection drops, with no + * application call involved -- this function only ever reads that + * already-computed flag. Returns false for a NULL ctx. + */ +extern bool xcecli_is_connection_broken(xcecli_ctx_t); extern int xcecli_shutdown(xcecli_ctx_t); extern int xcecli_reslist(xcecli_ctx_t, xce_resource_t***); extern int xcecli_join(xcecli_ctx_t, int, hostattrs_t*); diff --git a/src/lib/client.c b/src/lib/client.c index 4caeea0d..b7ba33cf 100644 --- a/src/lib/client.c +++ b/src/lib/client.c @@ -264,6 +264,15 @@ int xcecli_heartbeat(xcecli_ctx_t c, int hb_interval) return XCECLI_FF_CALL(ctx, xce_heartbeat(&(ctx->ctx), hb_interval)); } +bool xcecli_is_connection_broken(xcecli_ctx_t c) +{ + /* Delegates to the exact predicate XCECLI_FF_CALL already uses + * internally (client_internal.h) -- same NULL-safe, socket-free, + * side-effect-free read of ctx->ctx.state, just exposed publicly (see + * client.h's doc comment for the full rationale, bug-1760). */ + return xcecli_ff_needs_reconnect((api_ctx_t*)c); +} + int xcecli_shutdown(xcecli_ctx_t c) { api_ctx_t* ctx = (api_ctx_t*)c; diff --git a/src/lib/testsuite/test_libxce_retry.c b/src/lib/testsuite/test_libxce_retry.c index 41933716..aed94bfe 100644 --- a/src/lib/testsuite/test_libxce_retry.c +++ b/src/lib/testsuite/test_libxce_retry.c @@ -1700,6 +1700,46 @@ static void test_ff_needs_reconnect_null_safe(void) printf("test_ff_needs_reconnect_null_safe: PASS\n"); } +/* ════════════════════════════════════════════════════════════════════════ + * bug-1760 — xcecli_is_connection_broken(): the public, xcecli_ctx_t-typed + * wrapper around xcecli_ff_needs_reconnect() above (client.c), letting an + * idle consumer loop (e.g. the Scheduler's round loop) passively check for + * a transport already known-dead via the async RDHUP disconnect path + * (handle_disconnect(), xcectx.c) -- zero network I/O, zero blocking risk -- + * instead of periodically probing a possibly-healthy connection. Same + * ERR/RUN/DOWN/INIT state matrix as the tests immediately above; this group + * only proves the public wrapper delegates correctly, not the predicate + * logic itself (already fully covered above). + * ════════════════════════════════════════════════════════════════════════ */ + +static void test_is_connection_broken_true_on_err(void) +{ + api_ctx_t ac; + memset(&ac, 0, sizeof(ac)); + ac.ctx.state = XCE_CTX_ERR; + + TEST_ASSERT_TRUE(xcecli_is_connection_broken((xcecli_ctx_t)&ac)); + + printf("test_is_connection_broken_true_on_err: PASS\n"); +} + +static void test_is_connection_broken_false_on_run(void) +{ + api_ctx_t ac; + memset(&ac, 0, sizeof(ac)); + ac.ctx.state = XCE_CTX_RUN; + + TEST_ASSERT_FALSE(xcecli_is_connection_broken((xcecli_ctx_t)&ac)); + + printf("test_is_connection_broken_false_on_run: PASS\n"); +} + +static void test_is_connection_broken_null_safe(void) +{ + TEST_ASSERT_FALSE(xcecli_is_connection_broken(NULL)); + printf("test_is_connection_broken_null_safe: PASS\n"); +} + /* Req 5.3 (structural): the fire-and-forget path is single-shot — it makes AT * MOST ONE reconnect attempt and NEVER consumes the no-primary retry budget / * sleeps. We prove this structurally: the FF macro drives the body exactly once @@ -1800,6 +1840,9 @@ void test_libxce_retry(void) RUN_TEST(test_ff_no_reconnect_on_run); RUN_TEST(test_ff_no_reconnect_on_down_or_init); RUN_TEST(test_ff_needs_reconnect_null_safe); + RUN_TEST(test_is_connection_broken_true_on_err); + RUN_TEST(test_is_connection_broken_false_on_run); + RUN_TEST(test_is_connection_broken_null_safe); RUN_TEST(test_ff_call_is_single_shot_no_budget); UNITY_END(); } diff --git a/src/scheduler/include/scheduler.h b/src/scheduler/include/scheduler.h index cec42f48..feec1a6f 100644 --- a/src/scheduler/include/scheduler.h +++ b/src/scheduler/include/scheduler.h @@ -271,6 +271,12 @@ extern int sched_apply_job_rusage(xce_scheduler_t*, xce_job_rusages_t*); extern int sched_commit_decision(xce_scheduler_t*, xce_decision_t*); extern int sched_publish_pend_reason(xce_scheduler_t*, xce_preason_set_t*); extern int sched_publish_dispatch(xce_scheduler_t*, xce_job_dispatch_t*); +/* bug-1760: exposed (was `static sched_publish_check_rejoin`) so + * xce_sched_driver_run_normal_mode_round() (driver.c) can call it + * unconditionally once per round, not only as a side effect of a + * successful decision publish -- see scheduler.c's doc comment on this + * function for the chicken-and-egg deadlock this closes. */ +extern void sched_check_pending_rejoin(xce_scheduler_t*); extern void sched_worker_release_host_ctx(xce_sched_worker_t*); extern int sched_meet_host_selection(xce_scheduler_t*, xce_sched_worker_t*, xce_select_t*); diff --git a/src/scheduler/src/main.c b/src/scheduler/src/main.c index d9f68f62..3b67d9b5 100644 --- a/src/scheduler/src/main.c +++ b/src/scheduler/src/main.c @@ -468,6 +468,30 @@ int main(int argc, char* argv[]) break; } + /* bug-1760: check for a pending rejoin UNCONDITIONALLY, once per + * ~1s round, regardless of whether this round published anything. + * sched_check_pending_rejoin() was previously only invoked + * reactively, as a side effect of a successful decision publish + * (sched_publish_retry_loop(), scheduler.c) -- but after a + * controller failover, the scheduler can have nothing queued to + * publish at all (the new primary has no record of this scheduler + * ever having joined it, so it never routes any job to this + * scheduler's picker), so the reactive-only call could never fire + * and a pending rejoin could be stuck forever: a chicken-and-egg + * deadlock -- closed by sched_check_pending_rejoin() itself now + * also checking a passive, zero-I/O "connection already known + * dead" signal in addition to this flag; see that function's own + * doc comment (scheduler.c) for the full mechanism. Placed here + * (main.c), not inside driver.c's mode-agnostic + * xce_sched_driver_run_normal_mode_round(), because + * driver.c is linked by several sim-mode test binaries that never + * link scheduler.c (where this function and sched_needs_rejoin + * live) -- calling a scheduler.c symbol from driver.c broke those + * links under -Wl,--no-undefined. main.c is normal-mode-only and + * not linked into any test binary, so this call site has no such + * cross-boundary cost. */ + sched_check_pending_rejoin(&sched); + sleep(1); } diff --git a/src/scheduler/src/scheduler.c b/src/scheduler/src/scheduler.c index 6e8b7632..e292549d 100644 --- a/src/scheduler/src/scheduler.c +++ b/src/scheduler/src/scheduler.c @@ -1455,34 +1455,70 @@ int sched_commit_decision(xce_scheduler_t* sched, xce_decision_t* decision) } /* - * sched_publish_check_rejoin - after a decision publish call finally - * succeeds, re-issue xcecli_join() as a separate follow-up if the client - * library's reconnect callback (sched_on_reconnect(), above) flagged a - * pending rejoin (component-failover-adoption, task 3.2, Req 2 AC5). + * sched_check_pending_rejoin - re-issue xcecli_join() as a follow-up if + * either (a) the client library's reconnect callback (sched_on_reconnect(), + * above) flagged a pending rejoin (component-failover-adoption, task 3.2, + * Req 2 AC5), or (b) the connection is passively known to be broken right + * now (bug-1760, see below) -- either condition alone is sufficient. + * + * Called from TWO places: sched_publish_retry_loop() below calls it + * reactively right after a successful decision publish (the original task + * 3.2 behavior, lowest possible rejoin latency when there IS something to + * publish); main()'s round loop (main.c) ALSO calls it unconditionally, + * once per ~1s scheduling round, regardless of whether that round + * publishes anything. + * + * bug-1760 fix, condition (b): sched_needs_rejoin ALONE cannot close the + * chicken-and-egg deadlock where the scheduler has nothing queued to + * publish -- it is only ever set by sched_on_reconnect(), which itself + * only fires as a side effect of an ACTUAL xcecli_* call detecting a dead + * connection (XCECLI_FAILOVER_CALL/XCECLI_FF_CALL, client_internal.h), and + * an idle round makes no such call. Confirmed live (2026-09-04, 3-node HA + * cluster): with condition (a) alone, a post-failover job submitted to the + * new primary stayed PEND indefinitely with zero scheduler.log rejoin + * activity, even though this function was already being called every + * round. + * + * Condition (b) -- xcecli_is_connection_broken(sched->apictx) -- closes + * this without adding any periodic active-liveness-probe call (which would + * trip test_scheduler_connect.c's Req-3-AC3 structural guard against + * introducing the worker's own periodic-probe pattern here, and carries a + * real, separate hazard: a stalled reconnect retry inside such a probe + * could itself delay/stall the scheduler's own round loop). Instead it + * reads a flag the transport ALREADY maintains for free: handle_disconnect() + * (xcectx.c) sets ctx->state = XCE_CTX_ERR asynchronously, from the iomgr's + * own epoll/RDHUP handling, the instant the connection drops -- zero + * application calls, zero blocking. xcecli_is_connection_broken() (client.h) + * is a pure, socket-free, side-effect-free read of that flag. A healthy, + * idle scheduler therefore makes zero extra calls of any kind; this branch + * only ever reaches xcecli_join() below when the transport is ALREADY + * known-dead, at which point blocking through xcecli_join()'s own + * XCECLI_FAILOVER_CALL retry/rotate logic is the same cost the round loop + * already accepts whenever it has a live decision to publish during a + * failover -- not a new category of stall. * * Deliberately NOT its own retry loop: on failure, sched_needs_rejoin - * stays set, so the NEXT decision's publish call retries this same - * rejoin -- the per-decision retry cadence sched_publish_retry_loop() - * below already establishes IS the retry mechanism (design.md's - * "Rejoin-check interaction" note). + * stays set (if it was already set) and/or xcecli_is_connection_broken() + * keeps reporting true until a real reconnect succeeds, so the NEXT call + * (whichever call site reaches it first) retries this same rejoin. * * Uses the same rc<0-is-the-only-failure-test convention sched_init()'s * own xcecli_join() check uses above (component-failover-adoption task * 2.3's worker lesson: a successful join returns the assigned slot index * as reply.status, which is not always exactly 0). */ -static void sched_publish_check_rejoin(xce_scheduler_t* sched) +void sched_check_pending_rejoin(xce_scheduler_t* sched) { int rc; - if (!sched_needs_rejoin) { + if (!sched_needs_rejoin && !xcecli_is_connection_broken(sched->apictx)) { return; } rc = xcecli_join(sched->apictx, HostRole_scheduler, NULL); if (rc < 0) { WARN("%s: pending rejoin retry failed (rc=%d) -- will retry on the " - "next decision publish", + "next check", __func__, rc); return; } @@ -1562,7 +1598,7 @@ static int sched_publish_retry_loop(xce_scheduler_t* sched, void* payload, } if (rc >= 0) { - sched_publish_check_rejoin(sched); + sched_check_pending_rejoin(sched); } return rc; diff --git a/src/scheduler/testsuite/meson.build b/src/scheduler/testsuite/meson.build index 28a39b61..dfbd33cc 100644 --- a/src/scheduler/testsuite/meson.build +++ b/src/scheduler/testsuite/meson.build @@ -1313,11 +1313,15 @@ sched_scheduler_decision_publish_retry_test = executable( scheduler_decision_publish_retry_test_srcs, include_directories:[incdir], dependencies: [scheduler_deps, unity_dep], + c_args: ['-DXCE_MAIN_C_PATH="' + + (meson.current_source_dir() / '..' / 'src' / 'main.c') + + '"'], link_args: ['-Wl,--wrap=xcecli_jobdispatch', '-Wl,--wrap=xcecli_set_pend_reason', '-Wl,--wrap=xcecli_join', '-Wl,--wrap=xcecli_start', - '-Wl,--wrap=xcecli_set_reconnect_handler'], + '-Wl,--wrap=xcecli_set_reconnect_handler', + '-Wl,--wrap=xcecli_is_connection_broken'], install: false) # Worst-case decision/allocation backpressure test (component-failover- diff --git a/src/scheduler/testsuite/test_scheduler_decision_publish_retry.c b/src/scheduler/testsuite/test_scheduler_decision_publish_retry.c index 800af87a..426ea2b1 100644 --- a/src/scheduler/testsuite/test_scheduler_decision_publish_retry.c +++ b/src/scheduler/testsuite/test_scheduler_decision_publish_retry.c @@ -182,6 +182,28 @@ int __wrap_xcecli_join(xcecli_ctx_t c, int role, hostattrs_t* attrs) return rc; } +/* ════════════════════════════════════════════════════════════════════════ + * Test double: __wrap_xcecli_is_connection_broken (bug-1760) + * + * Defaults to false so every EXISTING test in this file (which never + * touches this double) sees the connection as healthy, exactly matching + * this file's pre-bug-1760 behavior -- sched_check_pending_rejoin()'s new + * OR'd condition is a pure no-op unless a test explicitly sets this true. + * ════════════════════════════════════════════════════════════════════════ */ + +static bool g_connection_broken; + +static void reset_connection_broken_double(void) +{ + g_connection_broken = false; +} + +bool __wrap_xcecli_is_connection_broken(xcecli_ctx_t c) +{ + (void)c; + return g_connection_broken; +} + /* ════════════════════════════════════════════════════════════════════════ * Test doubles: __wrap_xcecli_start / __wrap_xcecli_set_reconnect_handler * -- setup-only doubles for the real sched_init() call the rejoin- @@ -215,6 +237,7 @@ void setUp(void) reset_dispatch_double(); reset_pend_double(); reset_join_double(); + reset_connection_broken_double(); } void tearDown(void) { return; } @@ -562,6 +585,243 @@ static void test_rejoin_composition_retries_across_publish_calls(void) printf("test_rejoin_composition_retries_across_publish_calls: PASS\n"); } +/* ════════════════════════════════════════════════════════════════════════ + * bug-1760 — sched_check_pending_rejoin() must work as a standalone public + * entry point, invocable with NO decision ever having been published. + * This is the direct proof that the chicken-and-egg deadlock (a pending + * rejoin that could only ever be checked as a side effect of a successful + * publish) is closed: the function is now callable, and does the right + * thing, entirely independent of publish activity. The actual production + * call site added by this fix (xce_sched_driver_run_normal_mode_round(), + * driver.c, called unconditionally once per ~1s round) is verified by + * source-text scan below, since driving that function through a full round + * would require live picker/allocator threads this fixture deliberately + * never starts (see this file's header comment). + * ════════════════════════════════════════════════════════════════════════ */ + +static void test_check_pending_rejoin_invoked_directly_without_a_publish(void) +{ + xce_scheduler_t sched; + xce_client_config_t config; + xce_cluster_config_t cluster_cfg; + int rc; + + /* Same fixture setup as test_rejoin_composition_retries_across_publish_ + * calls above: reach a real sched_init() far enough to register the + * reconnect handler, force its own join to fail so no picker/allocator + * thread starts, then simulate a transparent reconnect. */ + memset(&config, 0, sizeof(config)); + config.nmasters = 1; + config.masters[0] = "127.0.0.1"; + config.master_ports[0] = 19999; + config.from = "sched_pubretry_direct_test"; + config.key = "keepsecret$"; + + memset(&cluster_cfg, 0, sizeof(cluster_cfg)); + cluster_cfg.candidates_count = 1; + strncpy(cluster_cfg.candidates[0].hostname, "127.0.0.1", + XCE_MAXHOSTNAME_LEN - 1); + cluster_cfg.candidates[0].port = 19999; + strncpy(cluster_cfg.identity, "sched_pubretry_direct_test", + sizeof(cluster_cfg.identity) - 1); + + g_join_returns[0] = -EINVAL; /* sched_init()'s own join: fail on purpose */ + g_join_nreturns = 1; + + memset(&sched, 0, sizeof(sched)); + rc = sched_init(&sched, &config, &cluster_cfg, scheduler_req_handler); + TEST_ASSERT_TRUE_MESSAGE( + rc < 0, + "fixture: sched_init()'s own join was deliberately made to fail so " + "no picker/allocator thread is spun up by this setup step"); + TEST_ASSERT_NOT_NULL_MESSAGE( + g_captured_reconnect_cb, + "fixture: sched_init() must register the reconnect handler before " + "its xcecli_join() call"); + + /* No decision has EVER been published at this point -- unlike every + * other test in this file, sched_publish_dispatch()/ + * sched_publish_pend_reason() are never called here at all. */ + g_captured_reconnect_cb(sched.apictx, g_captured_reconnect_arg); + + reset_join_double(); + g_join_returns[0] = -E_XCE_NOT_READY; /* first direct check: still fails */ + g_join_nreturns = 1; + + sched_check_pending_rejoin(&sched); + TEST_ASSERT_EQUAL_INT_MESSAGE( + 1, g_join_call_count, + "sched_check_pending_rejoin() must be callable on its own and " + "attempt xcecli_join() when a rejoin is pending, with zero " + "decisions ever published"); + + g_join_returns[1] = 0; /* second direct check: succeeds */ + g_join_nreturns = 2; + + sched_check_pending_rejoin(&sched); + TEST_ASSERT_EQUAL_INT_MESSAGE( + 2, g_join_call_count, + "a still-pending rejoin must be retried on the next direct call"); + + /* Flag must now be clear -- a further direct call must not re-attempt + * the join. */ + sched_check_pending_rejoin(&sched); + TEST_ASSERT_EQUAL_INT_MESSAGE( + 2, g_join_call_count, + "once the rejoin has succeeded, a further direct call must be a " + "no-op -- no third xcecli_join() call"); + + printf("test_check_pending_rejoin_invoked_directly_without_a_publish: " + "PASS\n"); +} + +/* ════════════════════════════════════════════════════════════════════════ + * bug-1760 — passive-detection condition: sched_check_pending_rejoin() must + * attempt xcecli_join() when the transport is passively known-broken, even + * when sched_needs_rejoin was NEVER set (the exact idle-scheduler scenario + * a reactive-only check cannot detect on its own) -- and must make ZERO + * calls when neither condition holds, so a healthy idle scheduler never + * probes its connection. Uses a minimal zeroed fixture (no sched_init() + * needed): sched_check_pending_rejoin() only reads sched->apictx to pass + * verbatim into the wrapped xcecli_join()/xcecli_is_connection_broken() + * doubles, neither of which dereferences it. + * ════════════════════════════════════════════════════════════════════════ */ + +static void test_check_pending_rejoin_triggers_on_passive_broken_signal(void) +{ + xce_scheduler_t sched; + + memset(&sched, 0, sizeof(sched)); + + g_connection_broken = true; + g_join_returns[0] = 0; + g_join_nreturns = 1; + + sched_check_pending_rejoin(&sched); + + TEST_ASSERT_EQUAL_INT_MESSAGE( + 1, g_join_call_count, + "a passively-detected broken connection must trigger xcecli_join() " + "even when sched_needs_rejoin was never set -- this closes the " + "idle-scheduler chicken-and-egg gap a reactive-only check cannot"); + + printf("test_check_pending_rejoin_triggers_on_passive_broken_signal: " + "PASS\n"); +} + +static void test_check_pending_rejoin_no_op_when_healthy_and_no_flag(void) +{ + xce_scheduler_t sched; + + memset(&sched, 0, sizeof(sched)); + /* g_connection_broken defaults to false (setUp); sched_needs_rejoin + * (scheduler.c-private) is not touched by this test and is already + * false by this point in the file's test order. */ + + sched_check_pending_rejoin(&sched); + + TEST_ASSERT_EQUAL_INT_MESSAGE( + 0, g_join_call_count, + "a healthy, idle scheduler (no flag set, connection reports " + "healthy) must make ZERO xcecli_join() calls -- this is the " + "no-periodic-probe-to-a-healthy-connection guarantee"); + + printf("test_check_pending_rejoin_no_op_when_healthy_and_no_flag: " + "PASS\n"); +} + +/* ════════════════════════════════════════════════════════════════════════ + * bug-1760 — production wiring: main()'s round loop (scheduler/src/main.c) + * must call sched_check_pending_rejoin() UNCONDITIONALLY on every + * iteration, not only as a side effect of a successful decision publish. + * Verified by source-text scan (same technique test_scheduler_decision_ + * redelivery.c's test_no_worker_resync_symbols_in_scheduler_publish_path + * uses) rather than driving main() itself, which isn't linked into any + * test binary (main.c is excluded from every scheduler_srcs test target + * in meson.build -- see this file's own foreach-exclusion, shared by + * every test target in this directory). + * ════════════════════════════════════════════════════════════════════════ */ + +static char* read_whole_file(const char* path) +{ + FILE* f = fopen(path, "r"); + long size; + char* buf; + size_t nread; + + if (!f) { + return NULL; + } + + fseek(f, 0, SEEK_END); + size = ftell(f); + fseek(f, 0, SEEK_SET); + if (size < 0) { + fclose(f); + return NULL; + } + + buf = (char*)malloc((size_t)size + 1); + if (!buf) { + fclose(f); + return NULL; + } + + nread = fread(buf, 1, (size_t)size, f); + buf[nread] = '\0'; + fclose(f); + return buf; +} + +static void test_main_loop_checks_pending_rejoin_unconditionally(void) +{ + char* main_src = read_whole_file(XCE_MAIN_C_PATH); + const char* func_sig = "int main(int argc, char* argv[])"; + const char* call = "sched_check_pending_rejoin(&sched);"; + const char* round_call + = "xce_sched_driver_run_normal_mode_round(&sched);"; + const char* stop_check = "if (sched.core.stop)"; + char* func_start; + char* call_pos; + char* round_pos; + char* stop_pos; + + TEST_ASSERT_NOT_NULL_MESSAGE(main_src, + "could not read main.c source for scan"); + + func_start = strstr(main_src, func_sig); + TEST_ASSERT_NOT_NULL_MESSAGE(func_start, + "main.c must still define int main(...)"); + + round_pos = strstr(func_start, round_call); + stop_pos = strstr(func_start, stop_check); + call_pos = strstr(func_start, call); + + TEST_ASSERT_NOT_NULL_MESSAGE( + round_pos, "sanity: the round loop's xce_sched_driver_run_normal_" + "mode_round(&sched) call must still exist"); + TEST_ASSERT_NOT_NULL_MESSAGE( + stop_pos, "sanity: the round loop's core.stop check must still " + "exist"); + TEST_ASSERT_NOT_NULL_MESSAGE( + call_pos, + "bug-1760: main()'s round loop must call " + "sched_check_pending_rejoin(&sched) on every iteration -- without " + "this, a pending rejoin after a controller failover can only ever " + "be retried as a side effect of a successful decision publish, " + "which may never happen (chicken-and-egg deadlock)"); + TEST_ASSERT_TRUE_MESSAGE( + (round_pos < call_pos) && (stop_pos < call_pos), + "sched_check_pending_rejoin() must run AFTER the round's own " + "stop-check (never called on the iteration that is about to " + "break/shut down) but is placed unconditionally on every " + "surviving iteration regardless of what that round scheduled"); + + free(main_src); + printf("test_main_loop_checks_pending_rejoin_unconditionally: " + "PASS\n"); +} + int main(void) { UNITY_BEGIN(); @@ -571,5 +831,9 @@ int main(void) RUN_TEST(test_extended_retry_success_logs_distinctly); RUN_TEST(test_first_attempt_success_does_not_log_extended_retry); RUN_TEST(test_rejoin_composition_retries_across_publish_calls); + RUN_TEST(test_check_pending_rejoin_invoked_directly_without_a_publish); + RUN_TEST(test_check_pending_rejoin_triggers_on_passive_broken_signal); + RUN_TEST(test_check_pending_rejoin_no_op_when_healthy_and_no_flag); + RUN_TEST(test_main_loop_checks_pending_rejoin_unconditionally); return UNITY_END(); }