sched_job_exit_fun() (renamed sched_job_finish_fun, sched.c) subscribes
to HOOK_DETAIL_JOB_EXIT, which fires for EVERY job finish, both success
and failure -- record_job_finish_fact() (job.c) decides DONE vs EXIT
from finish->exit_code BEFORE firing this same hook detail either way
(mirrors persist.c's own HOOK_DETAIL_JOB_EXIT -> WAL_JOB_FINISH
mapping). This function discarded info->exit_code and sent only a bare
jobid, forcing sched_handle_notify() (scheduler/src/handler.c) to
unconditionally map EVERY finish -- including a clean, successful one
-- to JOB_STAT_EXIT. A subsequent HOOK_DETAIL_JOB_UPDATE notify usually
self-corrected this moments later via the full job state, but if that
second notify was dropped during a scheduler reconnect gap (the same
window bug-1731/bug-1734 already documented), the scheduler was left
permanently stuck showing EXIT for a job the controller correctly
recorded as DONE.
Live-reproduced on a real 3-node HA cluster + worker: job
0-8-1788143749-0[38] genuinely completed successfully (worker log:
"completed successfully", controller joblist: DONE) but the
scheduler's own replay showed EXIT.
Fix: carry {jobid, exit_code} across the wire via the existing
JobFinishInfo shape (the same struct apiserver_job_exit_fun already
reuses for this identical hook) instead of a bare UInt64, so
sched_handle_notify() can make the identical exit_code==0-vs-not
decision job.c itself makes. Renamed sched_job_exit_fun to
sched_job_finish_fun to reflect what it actually does.
Live-verified: a 51-job run (all exit 0) showed 100% DONE on the
scheduler side after the fix.
Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_019QxaSzHRB7pmYFp4cVnwkA
apply_committed_entry() (persist.c), the single seam that applies every
committed WAL entry, only ever fired the generic HOOK_DETAIL_JOB_UPDATE
for job-state changes -- HOOK_DETAIL_JOB_START/JOB_EXIT were
permanently dead code, since job.c only ever fires them at
HOOK_BEFORE_EVENT (for WAL-append purposes). This left sched_job_start_
fun/sched_job_exit_fun (sched.c) and apiserver_job_start_fun/
apiserver_job_exit_fun (apiserver.c) unreachable, and the Go apiserver's
already-wired OnJobFinished handler permanently starved of data -- a
finished job's state could stay stuck (e.g. showing RUN) in the
scheduler's own view and the apiserver never learned a job finished.
The wire format was already enriched by bug-1697/bug-1689 with the
pidinfo/exit_info data these hooks need, so this closes the gap rather
than requiring new wire work. WAL_JOB_FINISH now fires
HOOK_DETAIL_JOB_EXIT; WAL_JOB_START now fires HOOK_DETAIL_JOB_START,
gated on a call-scoped decode flag rather than the transition result
(WAL_JOB_START applies as a no-op duplicate for every real job in
production per bug-1697, so gating on the transition result would make
it dead code again). WAL_JOB_FAIL -> HOOK_DETAIL_JOB_FAIL has the same
gap and is left as a follow-up.
Also includes this investigation's supporting changes: a DEBUG3 log-
retention bump (main.c, both controller and scheduler) so race-condition
evidence survives a live burst without rotating out, and DEBUG3-gated
diagnostic trace logging at the two points a job-update notification
can fire or silently drop (job.c, sched.c).
Live-verified end to end on a real deployed cluster: scheduler-side
sched_job_state_change now fires for RUN and EXIT states, and the
apiserver's OnJobFinished -- previously never invoked in production --
now correctly updates job status on completion.
Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_019QxaSzHRB7pmYFp4cVnwkA
Violates this project's own recorded Decision Log entry: "No client
reply-wait timeout as a fix for a hung request -- fail loud at the real
transport/source instead of masking with a deadline backstop."
OPCode_schedAdmin (cluster.c) and on_fetchfile (job.c, the worker proxy
-- cluster.c's own comment says schedAdmin "mirrors on_fetchfile's proxy
pattern", confirming one shared design mistake, not two independent
bugs) both blocked on a multi-second pthread_cond_timedwait, replying
"timeout" on expiry. handle_scheduler_leave()/handle_worker_leave() (the
actual disconnect handlers) only nulled the endpoint pointer -- neither
ever signaled the pending waiter, so a mid-wait disconnect was invisible
until the deadline lapsed. The timeout was the ONLY failure-detection
mechanism, exactly what the decision forbids.
Both sites already had a working signal function on their success path
(schedadmin_signal(), fetchfile_signal()) -- just never wired to the
disconnect handlers. Fixed by calling them from
handle_scheduler_leave()/handle_worker_leave() with a distinguishable
-ECONNRESET outcome, so the waiter wakes immediately on disconnect
instead of only on the deadline. Timeouts kept as defensive backstops
for a genuinely wedged peer that never disconnects cleanly either --
this fix is about not relying SOLELY on the timeout, not removing it.
schedadmin_signal_disconnect() must be called BEFORE handle_scheduler_leave()
acquires c->sched.lock -- the dispatch wait holds that same lock for its
entire duration, so signaling after acquiring it would deadlock.
Found by an /xce-audit-invariants controller pass (Decision Log fidelity
dimension). New test_fetchfile_disconnect.c plus extensions to
test_sched_admin_dispatch.c/test_sched_worker_change.c; RED/GREEN
independently verified against real elapsed-time assertions (pre-fix:
5001ms full-timeout wait; post-fix: <1s immediate wake). Full controller
suite: 1181 tests, 2 failures -- both the pre-existing, unrelated
bug-1561 overlayfs sandbox flake, confirmed via a clean meson-driven run.
Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01AgYRU3zDTqNGV5Jk8aiKLg
sched_worker_change() aliased w->host.resvals_to_sched to a local xlist_t's
backing array, pushed it to the scheduler, then freed that array via
xlist_fini() without resetting the alias - leaving a dangling pointer for
the rest of the worker's life. On disconnect (handle_worker_leave ->
mark_worker_unavail -> persist_worker_hook_fun -> capnp_encode_worker ->
encode_Worker -> encode_NameValue_list), this dereferenced freed memory and
crashed the controller - but only once a scheduler had ever connected
(on_scheduler_join gates the hook registration), which made it easy to miss
in isolated worker-only testing.
The correct reset already existed in the function but was dead-code'd
behind #if 0 /*FIXME*/ - apparently from a prior fix attempt that got
wrapped instead of landed. Fix mirrors the proven-correct pattern already
used by the sibling apiserver_worker_change(): null the alias before
xlist_fini() frees the backing array, rather than double-freeing via
free_name_val_list() first.
Adds test_sched_worker_change.c, a regression test driving the real
production hook-dispatch path (xce_run_hooks -> sched_worker_hook_fun ->
sched_worker_dead -> sched_worker_change) and the real encode_Worker()
encoder the original crash traversed - confirmed to reproduce the exact
ASAN heap-use-after-free when the fix is reverted, and pass clean when
restored, closing the gap that let this regress silently once already.
Found while live-testing the resource-value-verification feature (deploying
a scheduler + injecting worker resource values via xce_test, then
disconnecting) - unrelated to that feature's own changes.
Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
xce_scheduler -i -s <replay>: "info worker <name>" showed
total=0.00 available=0.00 for every resource, even though the live
cluster (xce_test resval/workerlist) reported real non-zero values
for the same worker.
Two independent root causes, both live-traced end-to-end against a
real deployed cluster (value-level TRACE at every hop: controller
push, scheduler apply, snapshot save, snapshot load/decode):
1. src/scheduler/src/core_events.c: XCE_CORE_EVENT_WORKERS_PUSH
called sched_add_worker() -- a plain key_add(), add-only --
unconditionally on every push. A worker connecting triggers
multiple WORKERS_PUSH events in quick succession (an early push
before the controller finishes writing real capacity values,
carrying stale/zero data, followed moments later by a push
carrying the real values). The FIRST push always won the race;
every push after it for the same worker name silently failed
-EEXIST and its resource values were discarded -- not just at
join, for the rest of the process's lifetime (unlike jobs, there
was no "update an existing worker" event path at all). Fixed via
a new core_upsert_worker() (mirrors the existing
core_upsert_queue() add-or-update precedent): looks up the
worker by name first, updates status+resvals in place if found,
else builds+adds a new one as before.
2. src/scheduler/src/repl_info.c: repl_info_worker_one()/
repl_info_resource_one() checked `xce_val_t.which ==
XCE_VAL_NUMERIC` -- but XCE_VAL_NUMERIC (xce/types.h, value 1)
is a resource-DEFINITION value-type constant
(xce_resource_t.valtype's own enum), a completely different enum
from xce_val_t.which's real domain, Value_u_which
(controller.capnp.h, Value_u_fvalue=5). Every producer in this
codebase sets xce_val_t.which to Value_u_fvalue, never
XCE_VAL_NUMERIC, so the comparison was always false -- every
genuinely-numeric resval displayed as 0.00 unconditionally,
independent of fix (1). Corrected all 4 occurrences to
Value_u_fvalue.
Both fixed via TDD (RED test before each fix, GREEN after):
test_core_events.c's test_workers_push_twice_updates_existing_
worker_in_place (two pushes, same name, different values -- both
must apply) and test_repl_breakpoints_inspection.c's
test_info_worker_reports_resource_values (a real numeric resval
must display, not fall back to 0.00).
Live-validated by reproducing the user's exact original scenario
end-to-end (deploy a real cluster, record, `xce_scheduler -i -s
<replay>`, `info worker <name>`) -- now shows slots=22.00,
maxmem=33182089216.00 (30.9GB), mem=17151664128.00 (16GB), matching
the user's own live xce_test resval/workerlist numbers exactly.
Full scheduler suite green (41/41, excluding pre-existing unrelated
bug-1560); controller suite green (1102/1104, the same pre-existing
bug-1561 pair, confirmed unrelated to this change).
Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
xcesched_push_configs() sent two hardcoded limit1/limits2 test
literals to the scheduler (behind a #if 0/FIXME "we use builtin limit
currently"), ignoring whatever was actually loaded from cluster_config.
Migrate those literals into limits.yaml as real entries and wire
conf4sched->nlimits/limits from c->myconf->cluster_config directly.
cluster_init_phase2 also downgrades its "cluster_config not loaded"
ERROR to INFO — a standby legitimately reaching phase2 before the
primary's config-push has delivered bytes yet is normal cold-boot
behavior, not a failure; it already matches load_primary_config's
INFO-level framing for the same condition.
controller.capnp declared `struct Data $C.mapname("xce_data_t")` (an
OPCode_get query-result tagged union) at file scope, which shadows
Cap'n Proto's builtin Data blob type for every later `: Data` field in
the same file. This silently miscompiled 7 fields across 6 structs as
a struct-pointer type instead of a raw byte blob: UpgradeConfigRequest
.sha256/.bytes, ReplConfigReply.sha256/.bytes, ReplConfigPushRequest
.sha256/.bytes, ReplEnvelope.payload, SnapshotTransfer's chunk
payload, WalCatchupEntry.payload/.batchPayloads, and CtrlHelloRequest
.key. Production C code had already routed around it for years via
hand-rolled raw capn_ptr manipulation (see request.c's own comments);
nothing before now needed the generated codec/accessors to actually
work for these fields.
Renamed the local struct to XceData (capnp-level name only; the
$C.mapname("xce_data_t") C typedef is unchanged) and explicitly
repointed getdata/pushmsg at XceData by name, since those two fields
correctly want the local tagged union. Updated every derived
generated-identifier reference across 19 hand-written files spanning
controller, lib, scheduler, and the Go apiserver/xcecli CGo bindings.
Fixed 5 call sites in lib/request.c that had been typed against the
old workaround alias but now legitimately receive the correct
capn_data type (a pure type-name swap -- Data_ptr/XceData_ptr and
capn_data share the identical {capn_ptr p} layout).
Verified via full rebuild+test: lib (1/1), controller (3/3, incl. the
job-array push regression tests), scheduler (15/15), Go apiserver +
xcecli (all packages green), and a direct pycapnp round-trip proving
UpgradeConfigRequest.sha256/.bytes now encode/decode correctly.
Bug: bug-1461 (.wolf/buglog.json). Unblocks admin-config-tool task 3.3.
Adds xcesched_push_jobarray() (sched.c), encoding one compact
(base jobid, array_size, one spec) Data.jobArray descriptor -- reusing
the JobSubmit capnp struct already added to the Data union in task 1.2
-- instead of N individually-encoded job structs. sched_job_new_fun()
branches on l->count > 1 to call it; the existing single-job path
(l->count == 1 -> xcesched_push_joblist()) is byte-for-byte unchanged.
Sends via direct xce_request()/OPCode_push/Request_body_pushmsg rather
than the existing xce_push_data_req() helper, which hard-rejects any
payload outside jobs/workers/resources/resvals and cannot carry a
single non-list descriptor. design.md corrected to record this
transport deviation for task 5.2 to follow.
New standalone sched_push_unit_test binary (registered in
meson.build): sched.c/dataex.c/egress.c were never linked into
controller_unit_test, and two existing test files there ship local
fakes of on_scheduler_join()/notify()/collect_confvars() that would
collide with the real definitions at link time.
Task 5.1 of job-array-single-wal-record (Requirements 6.1, 6.3, 6.4).
Crash: encode_NameValue_list called with count=21, s=NULL on worker
rejoin, causing SIGSEGV in persist_worker_hook_fun.
Root cause: free_name_val_list(xce_name_val_t***, int) accepted count by
value. It zeroed *vals (resvals_to_sched = NULL) but could not zero
nresvals_to_sched. Any caller that freed the scheduler resource snapshot
(opget.c workerlist, reply.c clusterconf, dataex.c, sched.c dispatch)
left nresvals_to_sched stale. When the worker later rejoined and the
WAL HOOK fired, the WAL encoder read count=21 with a NULL pointer.
Fix: change signature to free_name_val_list(xce_name_val_t***, int*)
so both fields are zeroed atomically. Update all 7 call sites.
