lei.chen/myxce
1
0
Fork 1
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

docs(buglog): bug-1932 fixed (0317c7af)

Browse source 
Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
This commit is contained in:
Rongsong Shen 2026-10-09 08:02:42 +00:00
parent 0317c7af98
commit c7d82cac92
Signed by untrusted user: rshen
GPG key ID: 80533536B0EB651C
2 changed files with 16 additions and 10 deletions
Download patch file Download diff file Expand all files Collapse all files

10
.wolf/buglog.json
View file

@ -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 <job> 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 <job> 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 <replay> --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"
}
]

16
.wolf/bugs/bug-1932.md
View file

@ -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 <replay> --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