diff --git a/.wolf/buglog.json b/.wolf/buglog.json index 0cd7aa17..45fb859a 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.\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.", + "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.\n\nUPDATE (2026-09-04, static-only session, ~30 min): Pursued a new, previously-unchecked lead -- traced full ownership of j->submit->resreq (the raw wire string) through parse_resreq() -> parse_resreq_primary() (resreq.c:307) -> parse_section() (splits select[]/rusage[]/span[]/same[]/affinity[] substrings, MOVE_PTR'd into a local xce_resreq_data_t) -> parse_select() (resreq.c:205, builds the actual xce_select_t AST attached to job->resreq long-term) -> the select-expression PEG parser itself (xce_select.peg/xce_select.c). Hypothesis: if any hop stores a RAW pointer into the short-lived job_submit_data_t/its derived substrings instead of an owned copy, job->resreq (long-lived, read on every subsequent scheduling round) would hold a dangling pointer once job_submit_data_t is freed post-push -- a different, more delayed UAF trigger than the push-time-only theories every prior session chased.\n\nRULED OUT, with exact citations. (1) Every SEL_STR string-literal node in the select AST is makeString()-interned (xstring-refcounted, heap-independent) at the exact grammar action that parses it, BEFORE being stored -- xce_select.peg:161 (\"char* s = makeString(buf);\") and xce_select.peg:261 (\"char* s = makeString((char*)$0);\" -- $0 is the PEG grammar's own captured-token metavariable, not a shell variable), confirmed by makeSelectNode()'s own SEL_STR handling (xce_select.c) explicitly calling dereference()/reference() on op1, i.e. treating it as an xstring, not a raw pointer. (2) Every attribute/resource-name reference (e.g. the `type` in `type == \"x86_64\"`) resolves via resolve_resname() (xce_select.peg:17-55), which does key_find(auxil->resmgr, (void*)name, ...) -- the raw parsed token is used ONLY as a transient lookup key; the node stores the LOOKUP RESULT, a record owned by resmgr itself (long-lived, cluster-wide, unconditionally outlives any single job), never the job's own substring. (3) parse_resreq_primary() (resreq.c:307-349) only frees the intermediate section-split strings (kill_resreq_data(&data), line 346) AFTER parse_select()/parse_rusage() have already synchronously consumed them within the same function call -- no cross-call aliasing window exists there either. Net: job->resreq's entire AST is fully self-contained/independently-owned by the time core_build_job() returns; this lead does not explain bug-1714's crash and should not be re-chased.\n\nNo fix attempted (none needed -- hypothesis ruled out, not confirmed). No live repro attempted this session (static tracing alone was sufficient to close this specific lead; the actual stale-second-reader for j->submit itself, as opposed to any of its parsed derivatives, remains unfound -- see this entry's existing NEXT STEP notes, still the sharpest open leads).\n\nUPDATE (2026-09-04, later same session): a second static lead was checked and RULED OUT -- whether the SAME xce_job_t* object (not just a duplicate jobid via independent clones, already covered by Bug A) could be drained/processed twice via the pend_updates dataq double-buffer swap (driver.c's xce_sched_driver_translate_pending_events(), handler.c's enq_pend_update()/sched_on_jobs(), lib/dataq.c). Traced dataq_enq()/dataq_deq() (mylock.c-style single mutex per queue, dataq.c) and the pend_updates[0]/[1] swap-under-core->lock pattern line by line: dataq_deq_head() unconditionally unlinks the returned item (b->next = NULL, q->head advanced) before returning it, so a given enqueued data_item_t can structurally never be dequeued twice without an intervening fresh dataq_enq() of that same pointer -- and no such re-enqueue site exists (sched_on_jobs()/sched_handle_admin_request() both calloc() a fresh xce_sched_update_request_t per call, enq_pend_update() is their only caller). The swap itself (pend_updates[0] <-> [1]) and the concurrent producer-side enq_pend_update() both hold core->lock, so there is no window for the drain loop to observe a queue the producer is still mutating. This path is clean; does not explain bug-1714.\n\nRunning tally of candidates now RULED OUT across all sessions (do not re-chase without new evidence): (1) XceData_data_schedjobs dataset->rows aliasing (2026-08-30). (2) core_build_schedobj()'s user/queue/project handling -- confirmed makeString() deep copies (2026-09-04). (3) resreq/select-expression string ownership through parse_resreq() -- confirmed fully independent AST, makeString()-interned literals, resmgr-owned resname lookups (2026-09-04). (4) pend_updates dataq double-enqueue/double-drain (this update). Sharpest remaining unexplored angle: the controller-side HOOK_DETAIL_JOB_NEW/xcesched_push_joblist() live trace (2026-08-30's own NEXT STEP, never actually run live) and the connection-flap-driven resync amplification mechanism (found 2026-09-04, this session's earlier fork) -- both point at the CONTROLLER side re-pushing job data the scheduler already has, not at anything in the scheduler's own translate/build/free pipeline (now thoroughly checked and clean). A future session should pursue the controller side next, not re-audit scheduler.c/core_events.c/driver.c string or pointer ownership again.", "tags": [ "scheduler", "segfault", @@ -19540,7 +19540,9 @@ "crash-reproduced", "e-xce-not-ready-correlated", "amplification-mechanism-found", - "stale-reader-still-unknown" + "stale-reader-still-unknown", + "resreq-select-ast-ruled-out-2026-09-04", + "dataq-path-ruled-out" ], "related_bugs": [ "bug-1699",