diff --git a/.wolf/buglog.json b/.wolf/buglog.json index f6493ba6..8fa67927 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -19494,8 +19494,8 @@ "timestamp": "2026-08-26T18:35:00Z", "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.", - "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.", + "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).", + "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.", "tags": [ "scheduler", "segfault", @@ -19507,14 +19507,20 @@ "needs-live-repro", "needs-owner", "unfixed", - "kernel-confirmed" + "kernel-confirmed", + "reproduced-post-fix", + "asan-confirmed", + "uaf-mechanism-confirmed", + "malloc-reuse-confirmed", + "watchpoint-captured", + "side-bugs-fixed" ], "related_bugs": [ "bug-1699", "bug-1731" ], - "occurrences": 2, - "last_seen": "2026-08-29T05:21:00Z" + "occurrences": 4, + "last_seen": "2026-08-29T15:05:00Z" }, { "id": "bug-1715", diff --git a/src/scheduler/src/core_events.c b/src/scheduler/src/core_events.c index 7b0eeaa8..4bd863b3 100644 --- a/src/scheduler/src/core_events.c +++ b/src/scheduler/src/core_events.c @@ -723,6 +723,7 @@ int xce_core_push_events(xce_sched_core_t* core, xce_core_event_t* events, for (j = 0; j < ev->u.jobs_push.njobs; j++) { xce_sched_job_t* job = core_build_job(core, ev->u.jobs_push.jobs[j]); + int add_rc; if (job == NULL) { WARN("%s JOBS_PUSH: failed to build job (batch index %d)", @@ -730,7 +731,35 @@ int xce_core_push_events(xce_sched_core_t* core, xce_core_event_t* events, continue; } - sched_add_job(core, job); + add_rc = sched_add_job(core, job); + if (add_rc < 0) { + /* bug-1714 follow-up (Bug A): key_add() failed -- almost + * always a duplicate jobid (sched_on_job_array()'s + * per-element dedup check in handler.c is a best-effort + * optimization, not an atomic guarantee -- see that + * function's own comment), but this is the authoritative + * uniqueness boundary regardless of cause. `job` was + * NEVER registered in core->jobs, so it must not be + * handed to the picker: doing so would leave the picker + * tracking an orphaned xce_sched_job_t that no + * core->jobs-keyed lookup (sched_get_job() included) can + * ever find again. Free it instead, at the same + * granularity core_build_job()'s own early-failure paths + * above already use (resreq/schedobj/job itself via + * FREEUP()) -- job->user/queue/project are kvmgr-owned + * get-or-create lookups, not owned by this job instance, + * so they are left alone; job->allocs/accounts are left + * alone too (out of scope here -- see xce_sched_job_t's + * documented-incomplete destructor gap, kill_sched_job() + * in schedobj.c). */ + WARN("%s JOBS_PUSH: sched_add_job failed for jobid %llu " + "(rc=%d), discarding duplicate/orphaned job", + __func__, (unsigned long long)job->jobid, add_rc); + FREEUP(job->resreq); + FREEUP(job->schedobj); + FREEUP(job); + continue; + } if (picker != NULL) { picker->picker_iface->on_job_push(picker, job); diff --git a/src/scheduler/src/handler.c b/src/scheduler/src/handler.c index 88ceaf11..a2d707e6 100644 --- a/src/scheduler/src/handler.c +++ b/src/scheduler/src/handler.c @@ -208,7 +208,33 @@ static int sched_on_job_array(xce_scheduler_t* sched, * sched->jobs) the ordinary single-job path relies on downstream * (sched_add_job -> key_add -> -EEXIST), applied here per-element so * an already-materialized element is never re-queued. Not a new - * dedup mechanism. */ + * dedup mechanism. + * + * bug-1714 follow-up (Bug B): this check has a TOCTOU race window, + * and is a best-effort optimization for the common case, NOT an + * atomic correctness boundary. This function runs on whatever + * thread handles the incoming network request; a job is only + * actually inserted into sched->core.jobs later, when the separate + * DRIVER thread drains the pending-update queue this function + * enqueues into (via sched_on_jobs()/enq_pend_update()) and calls + * xce_core_push_events() -> the JOBS_PUSH case (core_events.c) -> + * sched_add_job(). Between this function enqueueing a batch and the + * driver thread actually processing it, sched_get_job() cannot see + * those jobids yet -- so a redelivered (e.g. network-retried) copy + * of the same array push arriving on the request thread during that + * window is NOT caught here, and a second, independent set of + * xce_job_t/job_submit_data_t clones for the same jobids gets + * constructed and enqueued too. This is safe, not just tolerated: + * the redelivered duplicate still gets fully constructed and pushed + * through the pipeline, but is correctly and safely rejected at the + * ACTUAL authoritative uniqueness boundary -- sched_add_job()'s + * key_add() in core.c, whose failure return is now checked by + * core_events.c's JOBS_PUSH handler (Bug A fix) -- which frees the + * orphaned duplicate and never hands it to the picker. Do not treat + * this early check as a correctness guarantee, and do not "fix" the + * race here (e.g. via a new synchronized pending-jobids set) without + * first re-deriving why that's unnecessary now that Bug A closes the + * actual hazard. */ if (sched_get_job(&(sched->core), jobid) != NULL) { continue; } diff --git a/src/scheduler/testsuite/test_core_events.c b/src/scheduler/testsuite/test_core_events.c index a97cb53f..ac6b68c4 100644 --- a/src/scheduler/testsuite/test_core_events.c +++ b/src/scheduler/testsuite/test_core_events.c @@ -466,6 +466,67 @@ static void test_jobs_push_fires_on_job_push_once_per_job(void) TEST_ASSERT_NOT_NULL(sched_get_job(&core, 3)); } +/* bug-1714 follow-up (Bug A): xce_core_push_events()'s JOBS_PUSH case never + * checked sched_add_job()'s return value, so a redelivered duplicate jobid + * (sched_add_job -> key_add -> -EEXIST) was still handed to + * picker->picker_iface->on_job_push() even though it was never actually + * registered in core->jobs -- an orphaned xce_sched_job_t the picker now + * tracks but no core->jobs-keyed lookup (sched_get_job() included) can ever + * find again. Asserts: (1) baseline single push fires on_job_push exactly + * once and registers the job; (2) a SECOND JOBS_PUSH batch carrying the SAME + * jobid must NOT fire on_job_push again (spy count stays at the baseline, + * last-seen job pointer unchanged) and sched_get_job() for that jobid must + * still return the ORIGINAL job object, not the orphaned duplicate. */ +static void +test_jobs_push_duplicate_jobid_does_not_call_on_job_push_or_leak(void) +{ + xce_sched_core_t core; + xce_core_event_t event; + xce_job_t* job1; + xce_job_t* dup_job; + xce_sched_job_t* original; + int rc; + + fixture_init(&core, &g_full_plugin); + + job1 = make_job(55, JOB_STAT_PEND, "normal", "alice", "proj1"); + + memset(&event, 0, sizeof(event)); + event.type = XCE_CORE_EVENT_JOBS_PUSH; + event.u.jobs_push.njobs = 1; + event.u.jobs_push.jobs = &job1; + + rc = xce_core_push_events(&core, &event, 1); + TEST_ASSERT_EQUAL_INT(0, rc); + TEST_ASSERT_EQUAL_INT(1, g_counts.job_push_calls); + + original = sched_get_job(&core, 55); + TEST_ASSERT_NOT_NULL(original); + TEST_ASSERT_EQUAL_PTR(original, g_counts.last_job_push); + + /* Redelivered duplicate: a second, independently-built xce_job_t with + * the SAME jobid, in its own JOBS_PUSH batch -- mirrors what + * sched_on_job_array()'s TOCTOU race window (Bug B, handler.c) can let + * through to this layer. */ + dup_job = make_job(55, JOB_STAT_PEND, "normal", "alice", "proj1"); + + memset(&event, 0, sizeof(event)); + event.type = XCE_CORE_EVENT_JOBS_PUSH; + event.u.jobs_push.njobs = 1; + event.u.jobs_push.jobs = &dup_job; + + rc = xce_core_push_events(&core, &event, 1); + TEST_ASSERT_EQUAL_INT(0, rc); + + /* on_job_push must NOT fire a second time for the duplicate. */ + TEST_ASSERT_EQUAL_INT(1, g_counts.job_push_calls); + TEST_ASSERT_EQUAL_PTR(original, g_counts.last_job_push); + + /* core->jobs must still resolve to the ORIGINAL job -- not an orphaned + * duplicate that a naive re-lookup might otherwise stumble into. */ + TEST_ASSERT_EQUAL_PTR(original, sched_get_job(&core, 55)); +} + /* JOB_UPDATE (core_events.c's live wire-shape mirror of JOB_STATE_CHANGE -- * the notify-driven single-job path a real controller's HOOK_DETAIL_JOB_UPDATE * fire reaches, per handler.c's own XCE_SCHED_OP_UPDATE_JOB_FIELDS comment) @@ -1039,6 +1100,7 @@ int main(void) UNITY_BEGIN(); RUN_TEST(test_push_events_fires_each_hook_once_per_event_with_picker_idle); RUN_TEST(test_jobs_push_fires_on_job_push_once_per_job); + RUN_TEST(test_jobs_push_duplicate_jobid_does_not_call_on_job_push_or_leak); RUN_TEST(test_job_update_to_terminal_state_frees_accounts_and_allocs); RUN_TEST(test_non_picker_events_mutate_state_but_never_call_hooks); RUN_TEST(test_workers_push_twice_updates_existing_worker_in_place);