diff --git a/.wolf/buglog.json b/.wolf/buglog.json index 1a1e9d6a..a658cb91 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -17545,9 +17545,9 @@ }, { "id": "bug-1927", - "status": "open", - "status_updated": "2026-10-08", - "status_note": "newly logged", + "status": "fixed", + "status_updated": "2026-10-09", + "status_note": "", "component": "scheduler", "severity": "noise", "timestamp": "2026-10-08T17:12:08Z", @@ -17555,8 +17555,8 @@ "occurrences": 1, "error_message": "scheduler pend reasons repeat one NO_RESOURCE entry per host per plan (no dedup in add_res_preason)\n\n**Observed:** a pending parallel job's pend-reason set holds one identical `NO_RESOURCE` entry per host per placement plan tried, with no de-duplication. In the scheduler-sim-decision-trace bounds test (1000 workers, maxTasks=64, the job pends after 64 plans), the traced pend outcome shows:\n```\n host bh0000: resource slots: NO_RESOURCE, resource slots: NO_RESOURCE, ... (63 times, 1842 chars)\n ...\n omitted hosts' pend reasons: NO_RESOURCE x87232\n ... 950 hosts omitted\n```\nThat is about 93k heap-allocated `xce_res_reason_t` entries (each with strdup'd host and resource strings) for what is semantically about 1000 distinct (host, resource, code) reasons.\n\n**Expected:** each distinct (host, resource, code) reason appears once in a job's pend-reason set.\n\n**Impact:** noise / payload inflation; no wrong scheduling decision. The set is rebuilt for each attempt (scheduler.c:328 and :419 free the old `obj->reason` before installing the new one), so it does not accumulate across sessions. But each pend carries plans × hosts entries: the allocation cost on the allocator thread, the `sched_publish_pend_reason` payload sent to the controller, and anything that displays pend reasons (the decision trace's pend outcome; the trace caps it at 50 hosts) all scale with that product.\n\n**Found by:** spec task scheduler-sim-decision-trace 6.4 (bounds test) and its review.\n\nSuspected: `add_res_preason()` (src/lib/preason.c ~93-143) always appends, and `resource.c` (~601) calls `add_job_preason(..., PREASON_NO_RESOURCE, w->name, r->name)` for every unmet resource on every per-host evaluation. The runner re-evaluates the same hosts for each plan, so the same entry is appended once per plan. Related code, but not this defect: bug-1692, bug-1845.", "file": "src/lib/preason.c, src/scheduler/src/resource.c, src/scheduler/src/scheduler.c", - "root_cause": "TODO: required for fixed/partial", - "fix": "TODO: required for fixed/partial\n\nVerification:\n- Test: TODO: name + file; RED before the fix, GREEN after\n- Suites: TODO: suite results and build profile\n- Live: TODO: soak/deploy run, or n/a and why", + "root_cause": "`add_job_preason()` (src/lib/preason.c) is a pure list append: `add_res_preason()` and `add_host_preason()` strdup and append every entry, with no check for an identical one already in `xce_job_preason_t`. The scheduler builds one job's reason set across a whole allocation attempt (one `xce_sched_ctx_t`, `ctx->reason`), and `sched_allocator_run()` (alloc_runner.c) tries every plan the plugin generates; each plan's bucket search calls `sched_try_alloc_on_host_()` (resource.c) for every candidate host, which appends `PREASON_NO_RESOURCE (host, resource)` for each unmet resource (resource.c ~601) or `PREASON_MATCH_FAIL (host)` (~559). A host that is short in plan 1 is short again in plan 2..N, so the identical entry is appended once per plan: in the bounds test 64 plans over 1000 hosts gave 93,232 entries, 92,232 of them duplicates (measured by the new assertion, RED output below). The shared precheck (`sched_alloc_prepare_shared_()`) has the same shape for a COMPOUND whose later primary is short on the same pool.\n\nSince when: pre-existing; `add_res_preason()` has always appended unconditionally. The multiplicity grew with spec scheduler-allocator-runner (Req 3.6/3.7: every short candidate of every bucket search now records its reason instead of only the first), and `test_alloc_equivalence_parjob.c` pinned the duplicated lists (6 and 5 entries) as expected output.\n\nScope (checked): every production caller of `add_job_preason` is in the scheduler (resource.c x2, alloc_runner.c x1, scheduler.c:183 main reason only). The controller never builds reasons: `do_set_preason()`/`set_preason()` (job.c) adopt the capnp-decoded list as sent, the WAL fact (bug-1692) encodes it verbatim, and nothing in the controller, apiserver or xcecli (no Go code reads pend-reason detail) gives order or multiplicity a meaning. The harness `setpend` command builds operator-typed reasons with `add_job_preason()`. `sim_verify` compares PEND decisions by main reason only (bug-1845); `job_preason_eq()` is order-sensitive but live and sim build the list with the same code.", + "fix": "De-duplicate at the scheduler's build site, through a new libxce builder, rather than changing `add_job_preason()` itself.\n- src/include/preason.h, src/lib/preason.c: `add_job_preason_once(reasons, index, code, host, res)` and `erase_preason_index()`, with a caller-owned `xce_preason_index_t`: an open-addressing table (linear probing, load <= 1/2, FNV-1a over kind, code, host, resource) of list positions. A hit is confirmed against the list entry at that position, so the index can never go stale: after a main reason erases the lists (or plain `add_job_preason()` calls in between) an erased entry is simply added again. Expected O(1) per add; first-add order is kept, so the list is exactly the old list with later repeats removed. Returns the new count when appended, 0 when already present.\n- src/scheduler/include/sched/types.h, schedobj.c: `xce_sched_ctx_t.reason_index`, zeroed by `sched_ctx_init()`'s memset and freed by `sched_ctx_fini()`; the index lives exactly as long as the attempt that builds `ctx->reason` (COMPOUND primaries share it, each ALTER alternative has its own ctx).\n- resource.c (`sched_try_alloc_on_host_`, both sites) and alloc_runner.c (`sched_alloc_prepare_shared_`) call `add_job_preason_once()`.\n\nWhy this removes the cause: every scheduler add for a key already present in this attempt's set is now a lookup, not an append, so a job's set holds each (host, resource, code) and (host, code) once, whatever the number of plans.\n\nRejected alternatives: (1) de-duplicating inside `add_job_preason()` -- `xce_job_preason_t` is the wire-mapped `JobPendReason` struct (controller.capnp `$C.mapname`), so it has no room for an index, and a linear scan per insert is O(n*d) (~46M string compares in the bounds test, under ASAN); it would also change the harness `setpend` primitive for no gain. (2) sort + unique when the set is finalized -- keeps the ~93k transient strdup/calloc/realloc per pend on the allocator thread (and needs care to keep first-occurrence order). (3) a per-ctx bitmap keyed by worker x resource index -- sized by cluster size per attempt, not by the number of reasons.\n\nBehaviour change: pend-reason lists sent to the controller (`sched_publish_pend_reason`) and shown by the decision trace shrink to distinct entries; main reasons, decisions, host choice and accounting are unchanged. No wire, WAL or snapshot format change. No committed fixture or recording changed (fixtures/repl_trace_baseline/* untouched; baseline, trace e2e and trace equivalence tests pass unmodified).\n\nVerification:\n- Test: `test_short_host_reason_recorded_once_across_plans` in src/scheduler/testsuite/test_alloc_runner_search.c (two scripted plans re-checking three short hosts): RED before the fix `Expected 3 Was 6`, GREEN after. `test_trace_bounds.c` tightened (`assert_reasons_distinct()` on the PEND decision's reason set, plus the rendered pend outcome `host bh0000: resource slots: NO_RESOURCE` and `omitted hosts' pend reasons: NO_RESOURCE x950`): RED before `Expected 0 Was 92232. duplicate pend reason entries`, GREEN after (`pend reasons: 1000 resource entries, 0 duplicates`). Six libxce unit tests `test_once_*` in src/lib/testsuite/test_preason.c (identical res/host adds kept once, distinct keys and first-add order, re-add after a main-reason erase, 64 passes over 2000 hosts, bad arguments): RED as a build failure (`add_job_preason_once` / `xce_preason_index_t` undeclared), GREEN after (libxce test 748/748). `test_parjob_host_reasons_every_short_host` (test_alloc_equivalence_parjob.c) pinned the duplicated lists; it failed with the fix (`Expected 6 Was 4`) and was updated to the set semantics (4 and 3 entries, same first-check order). Evidence: /home/claude/tmp/bug-1927/red.log, green-targeted.log.\n- Suites: `bash src/tools/xce-build.sh all --jobs 12 --incremental` (asan, xce.build, scheduler-framework @ 6c3393aa-dirty): meson 148/148 OK (scheduler 118, worker 15, harness 7, controller 5, libxce 2, apiserver 1), xceadmin pytest 373 passed, apiserver and xcecli `go test` all ok. Log: /home/claude/tmp/bug-1927/build-all.log.\n- Live: n/a for a deployment (allocator-only change, same code in live and sim); the reproduction itself was re-run. `XCE_TRACE_BOUNDS_DUMP=1 ASAN_OPTIONS=detect_leaks=0 src/xce.build/scheduler/testsuite/sched_trace_bounds_test` before: host lines repeat `resource slots: NO_RESOURCE` 63 times, `omitted hosts' pend reasons: NO_RESOURCE x87232`, 18.5-19.1 s, 7.28 GB max RSS (3 runs); after: `host bh0000: resource slots: NO_RESOURCE`, `NO_RESOURCE x950`, 1.86-2.00 s, 2.58 GB max RSS (3 runs). Dumps: /home/claude/tmp/bug-1927/bounds-dump-before.out, bounds-dump-after.out, before-time*.txt, after-time.txt.", "tags": [ "preason", "parallel-job", @@ -17567,7 +17567,9 @@ "bug-1692", "bug-1845" ], - "fix_commits": [], + "fix_commits": [ + "9f9b63dd" + ], "record": ".wolf/bugs/bug-1927.md", "gitea_issue": 352, "gitea_synced_status": "open" diff --git a/.wolf/bugs/bug-1927.md b/.wolf/bugs/bug-1927.md index 233537d3..ae8c66c8 100644 --- a/.wolf/bugs/bug-1927.md +++ b/.wolf/bugs/bug-1927.md @@ -1,8 +1,8 @@ --- id: "bug-1927" -status: "open" -status_updated: "2026-10-08" -status_note: "newly logged" +status: "fixed" +status_updated: "2026-10-09" +status_note: "" component: "scheduler" severity: "noise" timestamp: "2026-10-08T17:12:08Z" @@ -11,6 +11,7 @@ occurrences: 1 files: ["src/lib/preason.c", "src/scheduler/src/resource.c", "src/scheduler/src/scheduler.c"] tags: ["preason", "parallel-job", "pend-reason", "payload"] related: ["bug-1692", "bug-1845"] +fix_commits: ["9f9b63dd"] gitea_issue: 352 gitea_synced_status: "open" gitea_synced_hash: "2a0d743e5de9" @@ -52,15 +53,29 @@ Suspected: `add_res_preason()` (src/lib/preason.c ~93-143) always appends, and ` - Evidence: `/home/claude/tmp/bug-1927/bounds-dump.out` ## Root cause -TODO: required for fixed/partial +`add_job_preason()` (src/lib/preason.c) is a pure list append: `add_res_preason()` and `add_host_preason()` strdup and append every entry, with no check for an identical one already in `xce_job_preason_t`. The scheduler builds one job's reason set across a whole allocation attempt (one `xce_sched_ctx_t`, `ctx->reason`), and `sched_allocator_run()` (alloc_runner.c) tries every plan the plugin generates; each plan's bucket search calls `sched_try_alloc_on_host_()` (resource.c) for every candidate host, which appends `PREASON_NO_RESOURCE (host, resource)` for each unmet resource (resource.c ~601) or `PREASON_MATCH_FAIL (host)` (~559). A host that is short in plan 1 is short again in plan 2..N, so the identical entry is appended once per plan: in the bounds test 64 plans over 1000 hosts gave 93,232 entries, 92,232 of them duplicates (measured by the new assertion, RED output below). The shared precheck (`sched_alloc_prepare_shared_()`) has the same shape for a COMPOUND whose later primary is short on the same pool. + +Since when: pre-existing; `add_res_preason()` has always appended unconditionally. The multiplicity grew with spec scheduler-allocator-runner (Req 3.6/3.7: every short candidate of every bucket search now records its reason instead of only the first), and `test_alloc_equivalence_parjob.c` pinned the duplicated lists (6 and 5 entries) as expected output. + +Scope (checked): every production caller of `add_job_preason` is in the scheduler (resource.c x2, alloc_runner.c x1, scheduler.c:183 main reason only). The controller never builds reasons: `do_set_preason()`/`set_preason()` (job.c) adopt the capnp-decoded list as sent, the WAL fact (bug-1692) encodes it verbatim, and nothing in the controller, apiserver or xcecli (no Go code reads pend-reason detail) gives order or multiplicity a meaning. The harness `setpend` command builds operator-typed reasons with `add_job_preason()`. `sim_verify` compares PEND decisions by main reason only (bug-1845); `job_preason_eq()` is order-sensitive but live and sim build the list with the same code. ## Fix -TODO: required for fixed/partial +De-duplicate at the scheduler's build site, through a new libxce builder, rather than changing `add_job_preason()` itself. +- src/include/preason.h, src/lib/preason.c: `add_job_preason_once(reasons, index, code, host, res)` and `erase_preason_index()`, with a caller-owned `xce_preason_index_t`: an open-addressing table (linear probing, load <= 1/2, FNV-1a over kind, code, host, resource) of list positions. A hit is confirmed against the list entry at that position, so the index can never go stale: after a main reason erases the lists (or plain `add_job_preason()` calls in between) an erased entry is simply added again. Expected O(1) per add; first-add order is kept, so the list is exactly the old list with later repeats removed. Returns the new count when appended, 0 when already present. +- src/scheduler/include/sched/types.h, schedobj.c: `xce_sched_ctx_t.reason_index`, zeroed by `sched_ctx_init()`'s memset and freed by `sched_ctx_fini()`; the index lives exactly as long as the attempt that builds `ctx->reason` (COMPOUND primaries share it, each ALTER alternative has its own ctx). +- resource.c (`sched_try_alloc_on_host_`, both sites) and alloc_runner.c (`sched_alloc_prepare_shared_`) call `add_job_preason_once()`. + +Why this removes the cause: every scheduler add for a key already present in this attempt's set is now a lookup, not an append, so a job's set holds each (host, resource, code) and (host, code) once, whatever the number of plans. + +Rejected alternatives: (1) de-duplicating inside `add_job_preason()` -- `xce_job_preason_t` is the wire-mapped `JobPendReason` struct (controller.capnp `$C.mapname`), so it has no room for an index, and a linear scan per insert is O(n*d) (~46M string compares in the bounds test, under ASAN); it would also change the harness `setpend` primitive for no gain. (2) sort + unique when the set is finalized -- keeps the ~93k transient strdup/calloc/realloc per pend on the allocator thread (and needs care to keep first-occurrence order). (3) a per-ctx bitmap keyed by worker x resource index -- sized by cluster size per attempt, not by the number of reasons. + +Behaviour change: pend-reason lists sent to the controller (`sched_publish_pend_reason`) and shown by the decision trace shrink to distinct entries; main reasons, decisions, host choice and accounting are unchanged. No wire, WAL or snapshot format change. No committed fixture or recording changed (fixtures/repl_trace_baseline/* untouched; baseline, trace e2e and trace equivalence tests pass unmodified). ## Verification -- Test: TODO: name + file; RED before the fix, GREEN after -- Suites: TODO: suite results and build profile -- Live: TODO: soak/deploy run, or n/a and why +- Test: `test_short_host_reason_recorded_once_across_plans` in src/scheduler/testsuite/test_alloc_runner_search.c (two scripted plans re-checking three short hosts): RED before the fix `Expected 3 Was 6`, GREEN after. `test_trace_bounds.c` tightened (`assert_reasons_distinct()` on the PEND decision's reason set, plus the rendered pend outcome `host bh0000: resource slots: NO_RESOURCE` and `omitted hosts' pend reasons: NO_RESOURCE x950`): RED before `Expected 0 Was 92232. duplicate pend reason entries`, GREEN after (`pend reasons: 1000 resource entries, 0 duplicates`). Six libxce unit tests `test_once_*` in src/lib/testsuite/test_preason.c (identical res/host adds kept once, distinct keys and first-add order, re-add after a main-reason erase, 64 passes over 2000 hosts, bad arguments): RED as a build failure (`add_job_preason_once` / `xce_preason_index_t` undeclared), GREEN after (libxce test 748/748). `test_parjob_host_reasons_every_short_host` (test_alloc_equivalence_parjob.c) pinned the duplicated lists; it failed with the fix (`Expected 6 Was 4`) and was updated to the set semantics (4 and 3 entries, same first-check order). Evidence: /home/claude/tmp/bug-1927/red.log, green-targeted.log. +- Suites: `bash src/tools/xce-build.sh all --jobs 12 --incremental` (asan, xce.build, scheduler-framework @ 6c3393aa-dirty): meson 148/148 OK (scheduler 118, worker 15, harness 7, controller 5, libxce 2, apiserver 1), xceadmin pytest 373 passed, apiserver and xcecli `go test` all ok. Log: /home/claude/tmp/bug-1927/build-all.log. +- Live: n/a for a deployment (allocator-only change, same code in live and sim); the reproduction itself was re-run. `XCE_TRACE_BOUNDS_DUMP=1 ASAN_OPTIONS=detect_leaks=0 src/xce.build/scheduler/testsuite/sched_trace_bounds_test` before: host lines repeat `resource slots: NO_RESOURCE` 63 times, `omitted hosts' pend reasons: NO_RESOURCE x87232`, 18.5-19.1 s, 7.28 GB max RSS (3 runs); after: `host bh0000: resource slots: NO_RESOURCE`, `NO_RESOURCE x950`, 1.86-2.00 s, 2.58 GB max RSS (3 runs). Dumps: /home/claude/tmp/bug-1927/bounds-dump-before.out, bounds-dump-after.out, before-time*.txt, after-time.txt. ## References -- Related: none +- Related: bug-1692 (WAL fact that persists the published set, unchanged), bug-1845 (sim_verify compares PEND main reasons only), bug-1893 (shared-resource reasons, same builder) +- Docs: src/include/preason.h (add_job_preason_once contract), .kiro/specs/scheduler-allocator-runner/requirements.md Req 3.6/3.7