docs(buglog): bug-1927 fixed (9f9b63dd)

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>

.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"

.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