diff --git a/.wolf/buglog.json b/.wolf/buglog.json index 9db8e3a3..b5aac78d 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -16966,6 +16966,33 @@ "related_bugs": [], "occurrences": 1, "last_seen": "2026-08-17T10:31:46.356Z" + }, + { + "id": "bug-1569", + "timestamp": "2026-08-17T10:50:00Z", + "error_message": "TWO related, still-open problems on a live normal-mode (non-sim) deployment, found while verifying bug-1567/bug-1568's fixes actually let a real job dispatch: (A) 'info worker'/xceadmin-recorded snapshot still shows 0.00 for 'mem'/'r1m'/'r15m'/'r15s'/'ut'/'pg'/'ls'/'it'/'swp'/'io'/'tmp' (the 11 periodic resource_sync 'load index' metrics) even though xce_test's live 'resval -n mem -m pc13v' / 'resval -n r15s -m pc13v' show correct non-zero values on the SAME worker at the SAME time -- hostattrs-derived resources (slots/maxcpus/maxmem/maxswap/maxtmp/cpuf/ndisks, all fixed correctly by bug-1568) display fine; only the periodic/dynamic ones are still wrong. (B) A submitted job (single or array, queue 'xce', resreq 'type == any', worker 'pc13v' with 22 real slots available) never leaves PEND -- xce_sched_driver_run_normal_mode_round logs 'decision = (nil)' on EVERY round, forever (60+ consecutive rounds observed), meaning the scheduler never produces even a PEND decision, let alone DISPATCH, for any job.", + "root_cause": "(A) FULLY ROOT-CAUSED AND FIXED. The periodic resval update path is DIFFERENT from the join-time hostattrs push bug-1568 fixed: src/controller/opupd.c's do_update_resvals() applies a worker's periodic report locally using the CORRECT connection-resolved worker `w`, but then re-fires HOOK_DETAIL_RESOURCE_UPDATE with the wire `resvals` list's OWN unmodified `.host` field, forwarded unchanged by src/controller/sched.c's sched_resource_hook_fun() -> notify() -> scheduler's handler.c/driver.c/core_events.c XCE_CORE_EVENT_RESVALS_DELTA case, which does `sched_get_worker(core, rv->host)`. The true source of the wrong `.host` was WORKER-side, not xcecd_virtual-specific: src/worker/src/resource_sync.c's collect_load_indices() tagged every periodic report with gethostname() (the raw OS/container hostname -- 'xce' in this sandbox) instead of xcecd_ctx.virtual_name (the worker's actual join identity from -n/--name, e.g. 'pc13v'), which is what every OTHER worker-keyed lookup (mark_host_res()/sched_get_worker()) uses. FIXED (this session): collect_load_indices() now tags .host with xcecd_ctx.virtual_name, falling back to gethostname() only when virtual_name is unset. IMPORTANT CORRECTION to this entry's earlier note: after applying this fix, 'info worker'/'resval' via the INTERACTIVE REPL (`xce_scheduler -i -s `) appeared to still show 0.00 for mem/r1m/r15m/r15s/ut/pg/ls/it/swp/io/tmp -- this was a TEST-METHODOLOGY ARTIFACT, not a residual bug: the REPL starts PAUSED at the initial snapshot and requires an explicit `step`/`continue` command to advance the simulated clock past the recorded resvalsDelta ReplayEvent before querying state; querying immediately after load (as this investigation's own test scripts did, e.g. `echo -e \"info worker pc13v\\nquit\"` with no step/continue first) only ever shows the pre-periodic-report baseline. Live-confirmed end-to-end via -vvv scheduler.log (schedUpdateResvals notify arrives, zero 'unknown worker'/'unknown resource' WARNs, xceadmin scheduler dump shows the resvalsDelta event correctly captured with all 11 metrics @pc13v) AND via `step N` in the REPL (mem=16786444288.00, r1m=0.64, r15m=0.99, r15s=0.64, ut=2.08, pg=463.20, it=3341.19, tmp=65732259840.00 -- all correct; ls/swp/io legitimately 0 on this idle sandbox). (B) STILL OPEN, root cause NOT found. B1 (legacy xce_sched_fcfs picker active) was RULED OUT via the main.c diagnostic INFO log -- live-confirmed 'active job picker plugin: builtin_fcfs'. B2 (resource-starvation: dynamic resvals never reaching live core state so every candidate fails a resource-sufficiency check) is NOW ALSO RULED OUT: re-verified against the SAME live deployment used to confirm (A)'s fix, with dynamic resvals CONFIRMED correctly flowing into the live (non-replay) scheduler core (338+ consecutive driver rounds, schedUpdateResvals notifies landing every ~15s, no WARNs) -- yet a freshly submitted job (queue 'xce', resreq 'type == any', worker 'pc13v' online with 22 free slots) still never leaves PEND; xce_sched_driver_run_normal_mode_round still logs 'decision = (nil)' on every single round. True root cause for (B) is UNKNOWN -- candidates not yet investigated: on_queue_update()/on_job_push() picker hooks not actually firing or not populating builtin_fcfs's internal candidate list correctly, sched_job_is_ready()/sched_queue_is_ready() unexpectedly evaluating false, or sched_allocator()/sched_make_allocation() itself silently failing before ever reaching the picker.", + "fix": "(A) FIXED -- src/worker/src/resource_sync.c's collect_load_indices() now tags .host with xcecd_ctx.virtual_name (fallback: gethostname() if unset). TDD: RED test confirmed the bug (test_collect_load_indices_tags_host_with_virtual_name_not_gethostname expected 'pc13v', got 'xce'), GREEN after fix; new src/worker/testsuite/test_resource_sync.c (2 tests) added to src/worker/testsuite/meson.build, full worker suite green (3/3). Live-validated on a real 3-process deployment (controller+scheduler+xcecd_virtual): 'unknown worker' WARN eliminated, resvalsDelta event correctly recorded/replayed with real values. (B) NOT YET FIXED -- root cause still unknown after ruling out both B1 (legacy picker) and B2 (resource starvation). Needs a fresh investigation pass into the picker-hook-firing / candidate-eligibility / allocator path specifically.", + "tags": [ + "scheduler", + "controller", + "worker", + "normal-mode", + "resource-values", + "job-dispatch", + "job-pick-plugin", + "resval-host-mismatch", + "thread-a-fixed", + "thread-b-open", + "needs-investigation", + "test-methodology-artifact" + ], + "related_bugs": [ + "bug-1567", + "bug-1568" + ], + "occurrences": 3, + "last_seen": "2026-08-17T11:59:00Z" } ] }