diff --git a/.wolf/buglog.json b/.wolf/buglog.json index f9a5dbcc..50808a12 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -17693,9 +17693,9 @@ }, { "id": "bug-1932", - "status": "open", + "status": "fixed", "status_updated": "2026-10-09", - "status_note": "newly logged", + "status_note": "", "component": "scheduler", "severity": "wrong-result", "timestamp": "2026-10-09T07:23:52Z", @@ -17704,7 +17704,7 @@ "error_message": "xce_scheduler unsatisfiable-request cache drops pend reasons on a hit and is unused in sim\n\n**Observed:** in a `xce_scheduler --sim` session, array elements `[5]` and `[6]` have identical requests (`tasks 2..5`, mem 400 KB, same user/queue/project). `[5]` exhausts all 5 plans and pends; `[6]` then repeats the exact same search instead of reusing `[5]`'s verdict:\n```\n[sim] PEND jobid=0-5-1791529946-0[5]\n ...\n plans: 5 generated, 5 tried, 0 discarded, 0 not tried; no plan could be placed\n outcome: PEND\n main reason: none\n host pc13v: resource slots: NO_RESOURCE\n[sim] PEND jobid=0-5-1791529946-0[6]\n ... (same 5 plans, same host verdicts)\n plans: 5 generated, 5 tried, 0 discarded, 0 not tried; no plan could be placed\n```\n**Expected:** a request already proved unsatisfiable in this session pends at once, with the same pend reasons (main and per-host) the original attempt recorded, and the trace says it was skipped because of that earlier verdict. The live scheduler and the simulator should behave alike.\n**Impact:** the defect is in the normal (production) scheduler; the simulator's decision trace is what exposed it. Two defects in the session-level unsatisfiable-resreq cache (`alloc_cache.c`, scheduler-allocation Req 7):\n1. (normal scheduler, primary) see 2 below. (simulator) The simulator never registers the cache hooks (`main.c:527-528` registers them only in normal mode; `scheduler.c:247-256` treats NULL hooks as \"always compute fresh\"), so sim cost and sim decision traces differ from production: each identical pending element pays a full plan/host search.\n2. (normal scheduler) A cache hit reports only the stored main-reason category: `sched_pend_from_cached_reason_()` (`scheduler.c:173-184`) calls `add_job_preason(reasons, category, NULL, NULL)`, which erases host/resource reasons and sets `main_reason`. When the original attempt's main reason is 0 (\"none\") and its real cause is a per-host reason (as here: `pc13v: resource slots: NO_RESOURCE`), every later identical job pends with an empty reason, misleading operators (contrary to Req 7.5, \"report the same reason category\").\nWrong result (missing pend reasons) plus wasted scheduling time; no crash.\n**Found by:** user review of the sim decision trace (2026-10-09); defect 2 found by code review while investigating it.\n\nUPDATE (2026-10-09): per the user, the fix must cover the normal scheduler, not just the simulator: a cache hit must carry the original attempt's full pend reason (main, per-host and per-resource) in production, and the simulator must use the same cache so its traces match production.\n\nUPDATE (2026-10-09): production evidence already existed. `sim_verify.c`'s bug-1845 comment records a real captured `.replay` in which a live cache-hit PEND was recorded as `{main_reason=0, nhost_reasons=0, nres_reasons=0}` while the full computation for the same job gave `{main_reason=0, nres_reasons=2}`: the empty-reason hit of defect 2, on a real deployment.", "file": "src/scheduler/src/scheduler.c, src/scheduler/src/alloc_cache.c, src/scheduler/src/main.c", "root_cause": "Two separate gaps around the session-level unsatisfiable-resreq cache (`alloc_cache.c`, scheduler-allocation Req 7):\n\n1. **Only the main reason was cached.** `sched_make_primary_alloc_()` (`scheduler.c`) populated the cache with `ctx->reason->reasons->main_reason` (an `int`), and a hit went through `sched_pend_from_cached_reason_()`, i.e. `add_job_preason(reasons, category, NULL, NULL)`, whose main-reason branch erases the lists and sets only `main_reason`. The allocators record shortfalls as per-host/per-resource entries and leave `main_reason` at 0, so every hit pended its job with an entirely empty reason. Present since the cache was introduced (scheduler-allocation task 2.2/5.1); affects every normal-mode scheduler.\n2. **The simulator had no cache.** The table lived on `xce_scheduler_t` (`scheduler.h`), which a simulation core does not have, and the scheduler-sim-live-allocation spec made \"simulation isolation\" a non-goal: `sim_loop.c`/`sim.c` registered none of the hooks. So `xce_scheduler --sim` searched every identical pending job again, and its decision traces and pend reasons differed from production. This also forced the main-only `--sim-verify` PEND compare (bug-1845).", - "fix": "- **Cache entries hold the full reason.** A cache value is now an owned entry (`cache_entry_t`, `alloc_cache.c`): a deep copy of the exhausted attempt's whole `xce_job_preason_t` (main, per-host, per-resource; strings `strdup`ed via `add_job_preason`, main reason first because that branch erases) plus the job id that proved it. The table's datakiller frees entries on clear/destroy; a failed `key_add` frees the rejected copy. `cache_lookup()` fills a caller-supplied reason; the scheduler looks up into a local and, only on a hit, moves it into `ctx->reason`, so a miss leaves `ctx->reason` exactly as before.\n- **The table lives on the core.** `xce_sched_core_t.unsatisfiable_cache` replaces `xce_scheduler_t.unsatisfiable_cache`; `cache_lookup/insert/clear` and the three hook adapters take `xce_sched_core_t*` with no cast to a driver struct (the round-1 cast is what once clobbered `alt_events_file`). `sched_init()` builds it, `cache_clear()` rebuilds it every session, `xce_sched_core_fini()` destroys it.\n- **Both drivers register the hooks.** `main.c` registers them on the live core as before and passes the same three adapters to the simulator through new `sched_sim_args_t` fields; `sched_sim_driver_start()` sets them on the simulation core (plain field writes, since white-box tests `#include` `sim.c` without `core_session.c`/`alloc_cache.c` and leave them NULL).\n- **Hook signatures** (`core.h`): lookup returns the reason and the source job id; populate takes the reason and job id. `sched_allocator()` (`sched_election.c`) sets `core->alloc_jobid` around `sched_make_allocation()` so the populate knows the job.\n- **Decision trace:** a hit adds a `NO_PLAN` entry with the new reason `XCE_TRACE_NOPLAN_KNOWN_UNSAT` and the source job (`sched_trace_known_unsat()`), rendered as `no plan generated: skipped, same request as proved unsatisfiable earlier this session`; the outcome lines then show the restored reasons. `trace.h` stays at 796 lines.\n- `sim_verify.c` keeps its main-only PEND compare (old recordings still carry main-only hits, and a hit carries the proving job's reasons); its comment, `preason.h`'s, `core.h`'s and the scheduler-sim-live-allocation design.md (superseded note) were updated.\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", + "fix": "- **Cache entries hold the full reason.** A cache value is now an owned entry (`cache_entry_t`, `alloc_cache.c`): a deep copy of the exhausted attempt's whole `xce_job_preason_t` (main, per-host, per-resource; strings `strdup`ed via `add_job_preason`, main reason first because that branch erases) plus the job id that proved it. The table's datakiller frees entries on clear/destroy; a failed `key_add` frees the rejected copy. `cache_lookup()` fills a caller-supplied reason; the scheduler looks up into a local and, only on a hit, moves it into `ctx->reason`, so a miss leaves `ctx->reason` exactly as before.\n- **The table lives on the core.** `xce_sched_core_t.unsatisfiable_cache` replaces `xce_scheduler_t.unsatisfiable_cache`; `cache_lookup/insert/clear` and the three hook adapters take `xce_sched_core_t*` with no cast to a driver struct (the round-1 cast is what once clobbered `alt_events_file`). `sched_init()` builds it, `cache_clear()` rebuilds it every session, `xce_sched_core_fini()` destroys it.\n- **Both drivers register the hooks.** `main.c` registers them on the live core as before and passes the same three adapters to the simulator through new `sched_sim_args_t` fields; `sched_sim_driver_start()` sets them on the simulation core (plain field writes, since white-box tests `#include` `sim.c` without `core_session.c`/`alloc_cache.c` and leave them NULL).\n- **Hook signatures** (`core.h`): lookup returns the reason and the source job id; populate takes the reason and job id. `sched_allocator()` (`sched_election.c`) sets `core->alloc_jobid` around `sched_make_allocation()` so the populate knows the job.\n- **Decision trace:** a hit adds a `NO_PLAN` entry with the new reason `XCE_TRACE_NOPLAN_KNOWN_UNSAT` and the source job (`sched_trace_known_unsat()`), rendered as `no plan generated: skipped, same request as proved unsatisfiable earlier this session`; the outcome lines then show the restored reasons. `trace.h` stays at 796 lines.\n- `sim_verify.c` keeps its main-only PEND compare (old recordings still carry main-only hits, and a hit carries the proving job's reasons); its comment, `preason.h`'s, `core.h`'s and the scheduler-sim-live-allocation design.md (superseded note) were updated.\n\nVerification:\n- Test: `test_standalone_primary_cache_hit_skips_allocator` in `src/scheduler/testsuite/test_scheduler_cache_dispatch.c` (live scheduler, real `sched_init()`/allocator thread): RED before the fix, run against the unmodified scheduler -- `test_scheduler_cache_dispatch.c:456 ... FAIL: bug-1932: a cache hit must restore the original attempt's FULL pend reason (main, per-host and per-resource), not only its main reason` (job 1's reason had one per-resource entry, job 2's hit had none); GREEN after. Same assertion added to `test_scheduler_cache_dispatch_compound.c` (GREEN).\n- Test: `test_known_unsatisfiable_request_skipped_with_full_reasons` in `src/scheduler/testsuite/test_repl_trace_e2e.c` (real `xce_scheduler --sim -i`, new jobs 204/205 in the extra replay): RED before -- `missing (or out of order): no plan generated: skipped, same request as 0-0-0-204 proved unsatisfiable earlier this session` (204's full search assertions passed, 205 searched again); GREEN after, with 205's outcome lines byte-equal to 204's (`host w01: resource mem: NO_RESOURCE`, `host w02: ...`).\n- Test: `test_alloc_cache.c` (18 tests: deep copy independent of the original and of earlier lookups, NULL reason stored empty, clear frees entries, duplicate insert frees the rejected copy -- ASAN clean), `test_core_session_cache_clear.c`, `test_sim_cache_clear_isolation.c` (new: a sim core with the registered clear hook builds the core table and leaves `alt_events_file` alone), `test_trace_render.c` (`test_known_unsatisfiable_names_source_job`), `test_maxtasks_wiring_ingest.c` (ported).\n- Suites: `xce-build.sh scheduler` (asan, fresh `xce.build`) 118/118 OK; after the last edit, `meson test --suite scheduler` 118/118 OK; libxce `libxce test` 748 tests + `libxce alloc OOM test` OK (`preason.h` comment changed).\n- Live: `xce_scheduler --sim --sim-verify` (debug profile) on the two real captured replays in `data/` (`scheduler-replay-20260925-133708.replay`, `scheduler-replay-20260928-064842.replay`), pre-fix binary (temporary worktree at a64d0846) vs fixed binary: identical mismatch sets (35 and 4848 lines, compared line by line without log prefixes) and rc 0 both -- those mismatches are pre-existing and unchanged. No HA soak: the change is confined to the scheduler's allocation path and simulator.", "tags": [ "scheduler", "sim", @@ -17712,7 +17712,9 @@ "pend-reason" ], "related_bugs": [], - "fix_commits": [], + "fix_commits": [ + "0317c7af" + ], "record": ".wolf/bugs/bug-1932.md" } ] diff --git a/.wolf/bugs/bug-1932.md b/.wolf/bugs/bug-1932.md index 39da4796..95e09c6b 100644 --- a/.wolf/bugs/bug-1932.md +++ b/.wolf/bugs/bug-1932.md @@ -1,8 +1,8 @@ --- id: "bug-1932" -status: "open" +status: "fixed" status_updated: "2026-10-09" -status_note: "newly logged" +status_note: "" component: "scheduler" severity: "wrong-result" timestamp: "2026-10-09T07:23:52Z" @@ -11,6 +11,7 @@ occurrences: 1 files: ["src/scheduler/src/scheduler.c", "src/scheduler/src/alloc_cache.c", "src/scheduler/src/main.c"] tags: ["scheduler", "sim", "alloc-cache", "pend-reason"] related: [] +fix_commits: ["0317c7af"] --- # bug-1932: xce_scheduler unsatisfiable-request cache drops pend reasons on a hit and is unused in sim @@ -69,10 +70,13 @@ Two separate gaps around the session-level unsatisfiable-resreq cache (`alloc_ca - `sim_verify.c` keeps its main-only PEND compare (old recordings still carry main-only hits, and a hit carries the proving job's reasons); its comment, `preason.h`'s, `core.h`'s and the scheduler-sim-live-allocation design.md (superseded note) were updated. ## 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_standalone_primary_cache_hit_skips_allocator` in `src/scheduler/testsuite/test_scheduler_cache_dispatch.c` (live scheduler, real `sched_init()`/allocator thread): RED before the fix, run against the unmodified scheduler -- `test_scheduler_cache_dispatch.c:456 ... FAIL: bug-1932: a cache hit must restore the original attempt's FULL pend reason (main, per-host and per-resource), not only its main reason` (job 1's reason had one per-resource entry, job 2's hit had none); GREEN after. Same assertion added to `test_scheduler_cache_dispatch_compound.c` (GREEN). +- Test: `test_known_unsatisfiable_request_skipped_with_full_reasons` in `src/scheduler/testsuite/test_repl_trace_e2e.c` (real `xce_scheduler --sim -i`, new jobs 204/205 in the extra replay): RED before -- `missing (or out of order): no plan generated: skipped, same request as 0-0-0-204 proved unsatisfiable earlier this session` (204's full search assertions passed, 205 searched again); GREEN after, with 205's outcome lines byte-equal to 204's (`host w01: resource mem: NO_RESOURCE`, `host w02: ...`). +- Test: `test_alloc_cache.c` (18 tests: deep copy independent of the original and of earlier lookups, NULL reason stored empty, clear frees entries, duplicate insert frees the rejected copy -- ASAN clean), `test_core_session_cache_clear.c`, `test_sim_cache_clear_isolation.c` (new: a sim core with the registered clear hook builds the core table and leaves `alt_events_file` alone), `test_trace_render.c` (`test_known_unsatisfiable_names_source_job`), `test_maxtasks_wiring_ingest.c` (ported). +- Suites: `xce-build.sh scheduler` (asan, fresh `xce.build`) 118/118 OK; after the last edit, `meson test --suite scheduler` 118/118 OK; libxce `libxce test` 748 tests + `libxce alloc OOM test` OK (`preason.h` comment changed). +- Live: `xce_scheduler --sim --sim-verify` (debug profile) on the two real captured replays in `data/` (`scheduler-replay-20260925-133708.replay`, `scheduler-replay-20260928-064842.replay`), pre-fix binary (temporary worktree at a64d0846) vs fixed binary: identical mismatch sets (35 and 4848 lines, compared line by line without log prefixes) and rc 0 both -- those mismatches are pre-existing and unchanged. No HA soak: the change is confined to the scheduler's allocation path and simulator. ## References - Related: bug-1931 (same trace; parjob ignores minTasks), bug-1927 (pend reasons recorded once per job) -- Docs: .kiro/specs/scheduler-allocation/requirements.md (Req 7), .kiro/specs/scheduler-sim-live-allocation/ (task 2.2, cache callback seam) +- Docs: .kiro/specs/scheduler-allocation/requirements.md (Req 7), .kiro/specs/scheduler-sim-live-allocation/design.md (task 2.2 cache callback seam; superseded-non-goals note added by this fix) +- Fix commit: 0317c7af