From fcf119b4ac1ed207950d6f8e12381375abc7517f Mon Sep 17 00:00:00 2001 From: Rongsong Shen Date: Wed, 23 Sep 2026 13:40:16 +0000 Subject: [PATCH] fix(scheduler): 3 --sim-verify false positives + snapshot resreq_fp gap (bug-1844/1845/1772) /xce-audit-invariants scheduler dimension-1/4 audit, prompted by a fresh user-captured .replay file that still showed massive --sim-verify mismatch volume after bug-1843's fix. Root-caused via temporary diagnostic instrumentation against the real capture (reverted, never committed) rather than trusting the surface symptom. bug-1844: sim_verify_alloc_eq() (sim_verify.c) compared `instid`, a bare per-process monotonic counter (scheduler.c's sched_get_id(), core->nextid) stamped at allocation-build time -- not semantic content. The original recording's counter and a fresh replay's counter have no reason to reach the same value for "the same" dispatch. Live-verified: every DISPATCH mismatch showed identical value/duration/resname/reserve, differing only in instid (e.g. 826 vs 1). Dropped from the comparison, same treatment as bug-1842's `from` exclusion. bug-1845: sim_verify_job_preason_eq() required PEND decisions' full host/resource reason-detail lists to match. core.h documents "simulation isolation" as deliberate design: sim/replay never registers core->unsatisfiable_lookup_cb, so it can never hit the unsatisfiable-cache main.c's normal-mode branch registers. A live cache hit (sched_pend_from_cached_reason_()) records only main_reason with zero detail; replay always falls through to the full per-host computation and always produces detail. Same semantic outcome (PEND, same main_reason) at two architecturally-legitimate detail levels. Relaxed the comparator to main_reason only. Separately verified the cache itself is sound (key is safe within a round since capacity only decreases and the cache clears every round) -- ruling it out as the cause of a second, still-open divergence (bug-1846: one job genuinely dispatches one round early in replay vs. the original recording -- a suspected resource-accounting parity gap, not yet root-caused, logged for follow-up). bug-1772 (previously deferred, incorrectly tagged "fixed"): re-found independently by a dimension-4 snapshot-field-completeness audit subagent. snapshot_build_primary_schedobj() (snapshot_load.c) never computed resreq_fp, unlike its declared model core_build_primary_schedobj() (core_events.c) -- every snapshot-restored job got a zeroed fingerprint, which alloc_cache.c's cache key folds in directly alongside user/queue/project, so two distinct restored jobs sharing those three fields could silently share an incorrect unsatisfiable-cache verdict. Added the same 4-field computation the live path uses. TDD throughout: each fix has a dedicated regression test, and each was verified via genuine red (revert fix, confirm the new test fails) then green (restore, full 85/85 scheduler suite). Also ran three parallel dimension audits (core I/O isolation, picker/allocator jbuf rendezvous) -- both clean, no violations found. Co-Authored-By: Claude Sonnet 5 --- .wolf/buglog.json | 92 ++++++++++++++++++- .wolf/cerebrum.md | 2 + src/scheduler/src/sim_verify.c | 89 +++++++++--------- src/scheduler/src/snapshot_load.c | 19 ++++ src/scheduler/testsuite/test_sim_verify.c | 88 ++++++++++++++++++ .../testsuite/test_snapshot_save_load.c | 69 ++++++++++++++ 6 files changed, 309 insertions(+), 50 deletions(-) diff --git a/.wolf/buglog.json b/.wolf/buglog.json index 7700233f..e05f6013 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -23026,7 +23026,7 @@ "timestamp": "2026-09-05T00:00:00Z", "error_message": "OPEN, NOT A CRASH -- pre-existing, out-of-scope gap discovered during requirements scoping for the resreq-maxtasks-wiring spec (bug-1770's fix). snapshot_build_primary_schedobj() (src/scheduler/src/snapshot_load.c:81-96) never computes primary->resreq_fp at all, unlike core_build_primary_schedobj() (src/scheduler/src/core_events.c:130-135), which sets resreq_fp.min_tasks/max_tasks/select_node_id/rusage_hash from the parsed xce_primary_resreq_t immediately after parsing. Every job reconstructed from a snapshot (post-restart or post-failover restore) therefore gets a zeroed resreq_fp -- the same class of gap as bug-1767's broader 'recurring schedobj-reconstruction-duplication' pattern (snapshot_load.c independently re-implements core_events.c's schedobj construction rather than sharing it, and each independent copy has repeatedly drifted field-by-field). TRIGGER CORRECTION (2026-09-05, resreq-maxtasks-wiring design review): this entry's original phrasing ('post-restart or post-failover restore') overstates the live trigger. xce_sched_core_load_snapshot()'s ONLY real (non-test) caller anywhere in src/ is sim.c's sim_locate_and_load_snapshot(), reachable only via main.c's --sim FILE offline replay flag. Normal-mode main.c has no snapshot-load call or flag at all; a live scheduler restart (including post-failover, e.g. run-ha-soak.sh's restart_scheduler_for_new_primary()) starts with empty in-memory state and rejoins via on_scheduler_join() -> the same core_build_job() path fresh ingest uses -- never touching snapshot_load.c. The accurate trigger is: a job in a .replay-recorded snapshot loaded by the --sim simulation/replay driver, not any live-cluster crash-recovery or failover scenario. This does not change the bug's validity or fix (the gap is real for --sim/replay fidelity, which matters per this project's driver-equivalence invariant since --sim drives the identical allocator dispatch) -- it only corrects when it's actually reachable, which matters for scoping test coverage (an HA soak does NOT exercise this path at all).", "root_cause": "snapshot_load.c's snapshot_build_primary_schedobj() is a hand-duplicated, field-for-field port of core_events.c's core_build_primary_schedobj() (kept independent because core_build_primary_schedobj() is static and the two files are compiled as separate objects -- see bug-1767's own root-cause text for the deliberate-duplication rationale). The port was written before task 1.2 (scheduler-allocation feature) added resreq_fp/hash_rusages() wiring to the core_events.c original, and the snapshot_load.c copy was never updated to match. Effect: a snapshot-restored job's unsatisfiable-resreq cache fingerprint (used by scheduler-allocation's alloc_cache.c) is always the zero value, which is a valid-looking but WRONG fingerprint -- it could produce a false cache hit against an unrelated job that also happens to have a zeroed fingerprint (extremely unlikely today since real jobs always populate resreq_fp correctly at first ingest, but a snapshot-restored job's own fingerprint stays wrong for its entire post-restore lifetime, and any code that later relies on comparing/keying by resreq_fp for a restored job silently gets 0/0/0/0). Discovered while scoping resreq-maxtasks-wiring (bug-1770's fix spec) because that fix will make resreq_fp carry real, meaningful, non-degenerate maxTasks values for the first time -- increasing the practical consequence of this gap versus its current all-zero-everywhere baseline.", - "fix": "NOT FIXED -- logged for its own follow-up, deliberately kept out of the resreq-maxtasks-wiring spec's scope (per that spec's own requirements-phase scoping decision, 2026-09-05) to avoid absorbing an unrelated schedobj-reconstruction-duplication gap into a narrowly-scoped bug fix. Fix should add the same resreq_fp computation core_build_primary_schedobj() does (or better, per bug-1767's own recommended remediation, export core_build_primary_schedobj()/core_build_schedobj() and have snapshot_load.c call the real function instead of maintaining a third independent duplicate).", + "fix": "FIXED (2026-09-23, TDD, /xce-audit-invariants scheduler dimension-4 audit -- independently re-found by both a dedicated subagent and direct investigation into bug-1845; this entry's own prior 'fixed'/'closed-by-scheduler-sim-live-allocation' tags were STALE/WRONG -- direct code inspection confirmed snapshot_build_primary_schedobj() still had no resreq_fp computation immediately before this fix). Added the same four-field resreq_fp computation core_build_primary_schedobj() (core_events.c) performs -- min_tasks/max_tasks/select_node_id/rusage_hash -- to snapshot_build_primary_schedobj() (snapshot_load.c), matching that function's own documented 'field-for-field port' contract, which had simply never included this field. Added test_snapshot_load_computes_resreq_fingerprint_for_restored_primary() (test_snapshot_save_load.c) -- a job restored from a snapshot with mintasks=4/maxtasks=6 must have schedobj->u.primary->resreq_fp.min_tasks/max_tasks reflect those real values, not {0,0,0,0}. Verified genuine red->green: temporarily reverted just the new resreq_fp assignment and reran -- scheduler snapshot save load test FAILED (exit 1); restored the fix and reran -- full 85/85 scheduler suite green.", "tags": [ "scheduler", "snapshot-restore", @@ -23036,14 +23036,15 @@ "schedobj-duplication", "severity-medium", "fixed", - "closed-by-scheduler-sim-live-allocation" + "tdd", + "audit-reopened" ], "related_bugs": [ "bug-1767", "bug-1770" ], "occurrences": 1, - "last_seen": "2026-09-19T09:00:00Z" + "last_seen": "2026-09-23T10:05:00Z" }, { "id": "bug-1773", @@ -25020,6 +25021,91 @@ ], "occurrences": 1, "last_seen": "2026-09-23T08:00:00Z" + }, + { + "id": "bug-1844", + "timestamp": "2026-09-23T09:15:00Z", + "error_message": "User-reported follow-up to bug-1843: replaying a fresh capture (scheduler-replay-20260923-085356.replay, built after bug-1843's fix) with --sim --sim-verify still shows a huge volume of MISMATCH lines (4881 in one run) on DISPATCH decisions whose printed description is IDENTICAL on both sides -- e.g. 'expected: DISPATCH jobid=...[40] nhosts=1 -- actual: DISPATCH jobid=...[40] nhosts=1' still flagged as a mismatch.", + "file": "src/scheduler/src/sim_verify.c (sim_verify_alloc_eq())", + "root_cause": "CONFIRMED via temporary field-by-field diagnostic instrumentation in sim_verify_alloc_eq() (added, verified, then reverted -- not part of the fix) replayed against the real captured .replay file: `instid` was the ONLY field ever differing (value/duration/resname/reserve matched exactly every single time, e.g. recorded instid=826 vs replay instid=1, both otherwise byte-identical). `instid` is stamped from `sched->core.nextid++` (scheduler.c's sched_get_id()) at allocation-build time -- a bare per-process monotonic counter tracking how many allocation instances THIS core has built over its own entire execution history, not a semantic property of what got allocated. The ORIGINAL recording's counter (running, and building allocations, for potentially far longer before this capture window started) and a fresh replay's own counter (starting from whatever its loaded snapshot's nextid happens to be) have no reason to reach the same value for 'the same' dispatch. Exact same class of bug as bug-1838-followup/bug-1842's `from` field (also non-deterministic bookkeeping, already excluded) -- this comparator simply had a second field of the same kind left in.", + "fix": "FIXED (2026-09-23, TDD). Dropped the `a->instid == b->instid` clause from sim_verify_alloc_eq() (sim_verify.c), same treatment as bug-1842's `from` exclusion. Updated that function's doc comment to document the exclusion and cite the real captured-file evidence (826 vs 1). Added test_dispatch_decisions_differing_instid_still_match() (test_sim_verify.c), mirroring the existing test_dispatch_decisions_differing_from_timestamp_still_match() pattern -- two allocations identical in every field except instid (826 vs 1, matching the real observed divergence) must still compare equal. Verified genuine red->green: temporarily re-added the instid comparison and reran -- scheduler sim verify test FAILED (exit 1); restored the fix and reran -- full 85/85 scheduler suite green. NOTE: this fix does NOT address the second, separate anomaly found in the same replay file during this investigation (see bug-1845): a genuine one-round-early DISPATCH timing difference for one job (a resource-accounting/capacity divergence between live and replay, not a field-comparison issue) -- open, tracked separately.", + "tags": [ + "scheduler", + "sim", + "sim-verify", + "replay", + "instid", + "nextid", + "monotonic-counter", + "non-deterministic-field", + "fixed", + "tdd" + ], + "related_bugs": [ + "bug-1842", + "bug-1838-followup", + "bug-1843", + "bug-1845" + ], + "occurrences": 1, + "last_seen": "2026-09-23T09:15:00Z" + }, + { + "id": "bug-1845", + "timestamp": "2026-09-23T10:00:00Z", + "error_message": "Follow-up to bug-1843/bug-1844: replaying a fresh capture (scheduler-replay-20260923-085356.replay) with --sim --sim-verify still showed a large volume of MISMATCH lines on PEND decisions where recorded and replay agreed on jobid/main_reason but the deep host/resource reason-detail comparison disagreed (e.g. recorded {main_reason=0, nhost_reasons=0, nres_reasons=0} vs replay {main_reason=0, nhost_reasons=0, nres_reasons=2}), live-inspected via gdb by the user.", + "file": "src/scheduler/src/sim_verify.c (sim_verify_job_preason_eq())", + "root_cause": "CONFIRMED (2026-09-23) as a documented, intentional architectural asymmetry, not a defect: core.h states outright that 'a simulation-mode session never touches the real cache implementation at all' (simulation isolation). core->unsatisfiable_lookup_cb/unsatisfiable_populate_cb (alloc_cache.c's xce_alloc_cache_lookup_cb/populate_cb) are registered only by main.c's normal-mode branch -- sim_loop.c never registers them. sched_make_primary_alloc_() (scheduler.c) consults that cache FIRST; on a hit it records reason detail via sched_pend_from_cached_reason_(), which sets ONLY main_reason (no host/resource detail at all -- skipping that expensive per-host computation is the entire point of the cache). Replay, having no cache, always falls through to the full per-host computation (sched_try_alloc_on_host_(), resource.c) and therefore always produces full detail. Two independent, architecturally-legitimate detail levels for the exact same semantic outcome (this job is PEND, for this main reason), not a decision correctness signal. Separately verified the cache mechanism itself is SOUND (not a distinct bug): its key (alloc_cache.c's build_key_(): resreq_fp + user + queue + project, no host/capacity dimension) is safe within a round because capacity only decreases monotonically as earlier jobs dispatch and the cache is cleared fresh every round (xce_alloc_cache_clear_cb() at begin_session) -- a cached 'unsatisfiable' verdict from an earlier job this round remains valid for a later job sharing the same key.", + "fix": "FIXED (2026-09-23, TDD). sim_verify_job_preason_eq() (sim_verify.c) now compares ONLY main_reason, dropping the nhost_reasons/nres_reasons/host_based_reasons/res_based_reasons deep comparison entirely (that deep check was added as an optional 'cheap to add' enhancement, never proven necessary by a dedicated test, and is provably wrong given the cache-isolation asymmetry above). Doc comment updated to explain why. Added test_pend_decisions_differing_reason_detail_still_match() (test_sim_verify.c) -- two PEND decisions with the same jobid/main_reason but one with empty (cache-hit-shaped) and one with populated (full-computation-shaped) host/resource reason detail must still compare equal. Verified genuine red->green: temporarily re-added the deep comparison and reran -- scheduler sim verify test FAILED; restored the fix and reran -- full 85/85 scheduler suite green.", + "tags": [ + "scheduler", + "sim", + "sim-verify", + "replay", + "pend-reason", + "unsatisfiable-cache", + "alloc_cache", + "simulation-isolation", + "fixed", + "tdd" + ], + "related_bugs": [ + "bug-1843", + "bug-1844", + "bug-1842", + "bug-1846" + ], + "occurrences": 1, + "last_seen": "2026-09-23T10:00:00Z" + }, + { + "id": "bug-1846", + "timestamp": "2026-09-23T10:05:00Z", + "error_message": "OPEN, NOT YET ROOT-CAUSED. Same replay session as bug-1844/1845 (scheduler-replay-20260923-085356.replay): after excluding instid (bug-1844) and reason-detail (bug-1845), --sim-verify still shows one job (jobid=0-8-1790154325-0[39] in the observed capture) genuinely DISPATCHING one round earlier in replay than in the original live recording -- not a false-positive field comparison, a real positional divergence: replay's round begin_round=...436582151823 dispatches a 13-job batch (jobs [27]..[39]) while the SAME round in the original recording only dispatched 12 (jobs [27]..[38]); job [39]'s recorded dispatch instead lands in the NEXT round, cascading into ~40+ downstream positional MISMATCH lines for that round pair alone.", + "file": "src/scheduler/src/resource.c (sched_account_jobs, sched_charge_account/sched_uncharge_account), src/scheduler/src/sim_loop.c (sim_reconcile_unaccounted_jobs, sim_reconcile_toggle_prior_charges) -- suspected, not confirmed", + "root_cause": "NOT YET ROOT-CAUSED. Ruled out as explanations: (1) sim_loop.c's event-buffer-then-push-before-begin_session mechanism -- verified byte-for-byte faithful to the recorder's own file ordering during the bug-1843 investigation, no live-vs-replay discretization gap there; (2) the unsatisfiable-cache (alloc_cache.c) -- verified sound within a round (see bug-1845's root_cause) and, being purely additive skip-logic on top of the SAME full computation replay always performs, cannot itself cause replay to admit an EXTRA job a full check would have rejected. Leading hypothesis (UNCONFIRMED): a resource-accounting (resInUse/sharedInUse) state divergence between the live recorder and replay by this point in the run -- the class of bug scheduler-driver-equivalence.md documents as bug-1611/bug-1613's lineage (accounting-state parity is load-bearing, not incidental, and invisible at the decision level until contention makes it decision-visible, exactly this scenario: a 12-vs-13-job batch is a marginal-capacity difference). Not yet instrumented: w->resInUse/core->sharedInUse for the specific worker/resource this job batch consumes, round-by-round, to find where (if at all) replay's accounting genuinely differs from what the recorded decisions imply the original live run's accounting held at the equivalent round. Note bug-1611/bug-1613 are independently documented as FIXED (scheduler-driver-equivalence.md's 2026-09-19 update, re-verified via /xce-audit-invariants scheduler) -- if this is real, it is either a NEW instance of the same bug class (e.g. an accounting gap in the newer sim_reconcile_unaccounted_jobs()/bug-1836 charge-peek logic, which postdates that fix) or a currently-undocumented edge case the 2026-09-19 re-verification's fixture didn't exercise.", + "fix": "NOT FIXED -- open, reported for follow-up. Next step: instrument w->resInUse (and core->sharedInUse if the relevant resource is shared) for the specific worker(s) this job batch targets, logged at the start of every round (after sched_account_jobs(), before xce_core_signal_go()) in sim_loop.c, replayed against this exact .replay file, to find the first round (if any) where replay's own accounting state provably differs from what the ORIGINAL recording's decision sequence implies live's accounting held. If confirmed, the fix belongs wherever driver.c and sim_loop.c's per-round accounting calls diverge (scheduler-driver-equivalence.md's own audit method: enumerate every non-core call driver.c's round makes, confirm sim_loop.c's round makes the equivalent one in the same window, and the reverse).", + "tags": [ + "scheduler", + "sim", + "sim-verify", + "replay", + "resource-accounting", + "resInUse", + "driver-equivalence", + "unfixed", + "needs-diagnosis", + "open" + ], + "related_bugs": [ + "bug-1843", + "bug-1844", + "bug-1845", + "bug-1611", + "bug-1613" + ], + "occurrences": 1, + "last_seen": "2026-09-23T10:05:00Z" } ] } diff --git a/.wolf/cerebrum.md b/.wolf/cerebrum.md index a0e12a3c..ce75d347 100644 --- a/.wolf/cerebrum.md +++ b/.wolf/cerebrum.md @@ -245,4 +245,6 @@ - **(2026-09-21, bug-1836, `/xce-audit-invariants scheduler`) A driver-equivalence audit needs to check every DECISION-PRODUCING path, not just the "obvious" live one — a second, backstop mechanism (Recorded-Decision Reconciliation, `sim_reconcile_unaccounted_jobs()`, sim_loop.c) can silently bypass the SAME admission-check plumbing the primary path (`sched_allocator()`/`sched_try_alloc_on_host_()`) correctly uses, and a design doc's own stated assumption ("once resInUse is correctly populated in sim mode, the existing capacity-check code path produces the same outcome normal mode would") can be TRUE for the primary path and silently FALSE for a secondary one added by a LATER spec that never re-verified it.** Symptom was a live user report (44 single-slot jobs dispatched onto a 22-slot host during `xce_scheduler -i -s `) that superficially looked like a resource-accounting display bug (`used=22.00` looked self-consistent) but was actually an admission-control bypass: the reconciliation backstop force-applied recorded DISPATCH decisions from a `.replay` file's OWN history with zero live capacity re-validation. Fix pattern: re-run the SAME `sched_check_host_satisfy()`/`sched_check_shared_satisfy()` calls the live path uses, resolving the candidate's resnames fresh against `core->resmgr` (a decoded/recorded allocation carries only names+values, not resolved indices). - **When a fix needs to peek/seed then undo a resource-accounting baseline (e.g. "temporarily charge every already-running job so a capacity check sees real usage, then undo it before returning"), do NOT reach for the SAME by-name accounting entry point (`sched_account_jobs()`) an existing test elsewhere specifically instruments and call-count-asserts as a protected invariant ("must be called exactly once per round").** Doubling that exact symbol's call count broke `test_sim_contention_parity.c`'s `g_round_idx` mechanism — and the failure was initially confusing because a coincidental fixed-size counter array (`g_round_resinuse[8]`) CAPPED the observed count, making a 2-round fixture's true delta (+2, correctly proportional) look identical to a 5-round fixture's true delta (which should have been +5 but was capped at the array's own ceiling, also showing "+2" after the cap) — always check whether an assertion's input value could itself be silently clamped by an array bound before concluding two different-sized reproductions "coincidentally" show the same delta. Fix: build a small `static` local helper in the SAME file doing the identical `sched_charge_account()`/`sched_uncharge_account()` iteration, deliberately NOT calling the protected symbol by name, so the call-count invariant elsewhere stays intact while the underlying accounting effect is identical. - **Adding a genuine admission/capacity check to test-owning code can turn dozens of PRE-EXISTING tests red for a completely mechanical, expected reason: their fixtures name a resource/host in a mock allocation without ever registering a real object of that name, because nothing previously validated it.** 12 tests across 2 files broke this way when bug-1836's fix added a `sched_get_worker(hostname) == NULL` check — each one just needed a real (or, in a file that stubs the checker entirely and never even reaches the worker lookup meaningfully, a bare/minimal) worker registered for whichever hostname its fixture already referenced, with generous capacity (these tests were about ownership/dedup/timing mechanics, not capacity limits). This class of breakage is a sign the new check is doing its job, not a sign the check is wrong — verify each failure's root cause individually before assuming a batch of new failures means the production fix itself is flawed. +- **(2026-09-23, bug-1843/1844/1845/1772, `/xce-audit-invariants scheduler`) When a prior session's buglog entry already proposes a root-cause hypothesis for a `--sim-verify` mismatch, EMPIRICALLY RE-VERIFY it against a real captured `.replay` file before extending the fix — a plausible-sounding hypothesis inherited from a prior investigation can be flatly wrong, and trusting it wastes effort fixing the wrong layer.** bug-1843's prior session concluded the mismatch was `sim_loop.c`'s event-batching-granularity (a job's first appearance landing one round early in replay). Adding temporary per-round diagnostic `WARN()` logging (reverted after use, never committed) and replaying the ORIGINAL capture the bug was filed against instead showed the true mechanism was the opposite layer entirely: `sched_record_session_add_decision()` (recording_session.c) silently truncated a round's decisions on a `realloc()` failure, with nothing marking the round incomplete — a live-recorder data-loss bug, not a replay-side timing artifact. The same instrument-first discipline then found THREE more distinct `--sim-verify` false-positive classes in one session, each with a different, narrow, well-precedented fix: `instid` (bug-1844, a bare per-process monotonic counter with no reason to match between two separate process runs — same treatment as `from`, bug-1842), PEND reason host/resource DETAIL (bug-1845, sim mode's documented "simulation isolation" from the unsatisfiable-cache, `core.h`'s own comment, means live can record a cache-hit's sparse reason while replay always computes full detail — relax the comparator to `main_reason` only, drop the deep list-compare), and a genuinely separate, still-OPEN resource-accounting divergence (bug-1846) that instrumentation ruled OUT the first two mechanisms for but hasn't yet root-caused. **General pattern for this specific comparator (`sim_verify_alloc_eq`/`sim_verify_job_preason_eq`, sim_verify.c): before comparing ANY field between a live-produced and a recorded-then-replayed value, ask whether that field is semantic content (job/host/resource identity, requested amount) or per-process/per-run BOOKKEEPING (a monotonic counter, a wall-clock stamp, a cache-driven diagnostic-detail level) — only the former belongs in the comparison.** Every fix in this family followed strict TDD with a REAL red→green cycle (temporarily revert just the production fix, rebuild, confirm the new test fails, restore, rebuild, confirm the full suite is green) rather than trusting a passing test written after the fix. +- **A buglog entry's own `tags` field can silently claim "fixed"/"closed-by-..." while its `fix` text still says "NOT FIXED" — the two fields can drift independently, and either can be wrong.** bug-1772 (snapshot-restored jobs never computing `resreq_fp`) carried both `"fixed"` and `"closed-by-scheduler-sim-live-allocation"` tags from an earlier session, but its `fix` field still read "NOT FIXED -- logged for its own follow-up" and direct code inspection confirmed the gap was still live (`snapshot_build_primary_schedobj()` had no `resreq_fp` assignment at all). Independently re-found by both a dedicated dimension-4 audit subagent and direct manual investigation into bug-1845's cache-key mechanism, before either checked the buglog for a pre-existing entry. **When investigating a suspected-new bug in an area with buglog history, grep the buglog for the SAME symbol/function BEFORE writing a fresh entry — a "new" finding may be a previously-deferred bug whose stale tags say "fixed" while its own fix text says otherwise; trust the `fix` text and current code over `tags` alone, and correct the stale tags once genuinely fixed rather than leaving the contradiction for the next session to rediscover.** - **(2026-09-21, bug-1838) When a design revision removes a secondary decision-producing shortcut so more work routes through "the real path," don't assume every test file's "real path" IS real — some test files deliberately stub the exact mechanism you're now relying on, for reasons unrelated to what you're testing.** Predicted two failing tests' root cause as "fixture never registered a real worker" (correct pattern from the bug-1836 experience immediately above) — actually wrong for both: `test_sim_verify.c` and `test_sim_contention_parity.c` each stub `sched_job_picker()`/`sched_allocator()` to a deliberately PEND-only pair, used to keep those files' OTHER tests decoupled from real dispatch logic. Narrowing `sim_reconcile_unaccounted_jobs()`'s trigger to stop force-applying a PEND job's recorded decision meant those fixtures' jobs now correctly stay PEND forever (nothing in that file can ever dispatch them) — the fix wasn't adding a missing worker, it was inverting the test's own assertion to lock in the new, correct behavior ("still PEND, `--sim-verify` correctly reports the resulting MISMATCH, since this minimal harness has no real capacity-tracked path to reproduce a historical dispatch"). **Lesson: before assuming a test failure needs a "make the fixture more realistic" fix, grep the failing test's OWN file for whether the specific mechanism your change now depends on (a picker, an allocator, a resource check) is the REAL production implementation or a same-named local override/stub — a same-file `grep -n "^void\* sched_job_picker\|^int sched_check_host_satisfy"` etc. before touching the test.** A prior, adjacent, and still-correct architectural point (a design doc's own "Live/Recorded Authority Rule" can be stated but never actually enforced by the code's real ordering) is a separate, valid finding from this same investigation — don't conflate "the design doc says X should happen" with "therefore the live mechanism in THIS test file is capable of making X happen." diff --git a/src/scheduler/src/sim_verify.c b/src/scheduler/src/sim_verify.c index 928c5bf8..9f6904c0 100644 --- a/src/scheduler/src/sim_verify.c +++ b/src/scheduler/src/sim_verify.c @@ -109,6 +109,21 @@ static int sim_verify_str_eq(const char* a, const char* b) * expiry/accounting purposes), not part of the decision's own identity -- * unlike `duration`, which IS a deterministic, request-derived value and * stays part of this comparison. + * + * `instid` is ALSO deliberately excluded (bug-1844, same class of issue as + * `from` above): stamped from `sched->core.nextid++` (scheduler.c's + * sched_get_id()) at allocation-build time -- a bare per-process monotonic + * counter, not a semantic property of what got allocated. It counts how + * many allocation instances THIS core has built over its own entire + * execution history, so the ORIGINAL recording's counter (which may have + * been running, and building allocations, for far longer before this + * particular capture window even started) and a fresh replay's own counter + * (starting from whatever its loaded snapshot's nextid happens to be) have + * no reason to reach the same value for "the same" dispatch, even when + * every other field -- value, duration, resname, reserve, host -- matches + * exactly. Live-verified: a real captured .replay file showed every single + * DISPATCH's `instid` differing (e.g. recorded=826 vs replay=1, both + * otherwise byte-identical) while zero other fields ever differed. */ static int sim_verify_alloc_eq(const xce_alloc_t* a, const xce_alloc_t* b) { @@ -119,8 +134,7 @@ static int sim_verify_alloc_eq(const xce_alloc_t* a, const xce_alloc_t* b) return 0; } - return (a->instid == b->instid) && (a->value == b->value) - && (a->duration == b->duration) + return (a->value == b->value) && (a->duration == b->duration) && sim_verify_str_eq(a->resname, b->resname) && sim_verify_str_eq(a->reserve, b->reserve); } @@ -200,62 +214,43 @@ static int sim_verify_job_alloc_eq(const xce_job_alloc_t* a, /* * sim_verify_job_preason_eq - xce_job_preason_t (a PEND decision's reason - * payload) equality: main_reason plus (as a deeper, not-strictly-mandatory - * but cheap-to-add check per this task's own "don't leave an obviously- - * wrong shallow check if the deep one is a few extra lines" guidance) the - * full host-based and resource-based reason lists. + * payload) equality: main_reason ONLY. + * + * bug-1845 fix: this used to also require the full host-based/resource- + * based reason detail lists to match (added as an optional "cheap to add" + * deepening of the check, never proven necessary by a dedicated test). + * That is wrong: core.h documents, as a deliberate "simulation isolation" + * design decision, that "a simulation-mode session never touches the real + * cache implementation at all" -- core->unsatisfiable_lookup_cb/ + * unsatisfiable_populate_cb are registered only by main.c's normal-mode + * branch (alloc_cache.c), never by sim_loop.c. sched_make_primary_alloc_() + * (scheduler.c) consults that cache FIRST; on a hit it records only + * main_reason via sched_pend_from_cached_reason_() (no host/resource + * detail at all -- that is the entire point of the cache, skipping the + * expensive per-host iteration that would normally produce that detail). + * Replay, having no cache, always falls through to the full per-host + * computation and therefore always produces full detail. Two independent, + * architecturally-intentional detail levels for the exact same semantic + * outcome (this job is PEND, for this main reason) -- not a decision + * correctness signal, and requiring them to match produced systematic + * false MISMATCH reports on every cache-hit PEND decision in the original + * recording. Live-verified against a real captured .replay file: expected + * (recorded, cache-hit) reason showed + * {main_reason=0, nhost_reasons=0, nres_reasons=0}; actual (replay, full + * computation) showed {main_reason=0, nhost_reasons=0, nres_reasons=2} -- + * main_reason matched, detail did not, and never architecturally can. */ static int sim_verify_job_preason_eq(const xce_job_preason_t* a, const xce_job_preason_t* b) { - int i; - if (a == b) { return 1; } if ((a == NULL) || (b == NULL)) { return 0; } - if ((a->main_reason != b->main_reason) - || (a->nhost_reasons != b->nhost_reasons) - || (a->nres_reasons != b->nres_reasons)) { - return 0; - } - for (i = 0; i < a->nhost_reasons; i++) { - const xce_host_reason_t* ha = a->host_based_reasons[i]; - const xce_host_reason_t* hb = b->host_based_reasons[i]; - - if (ha == hb) { - continue; - } - if ((ha == NULL) || (hb == NULL)) { - return 0; - } - if ((ha->reason != hb->reason) - || !sim_verify_str_eq(ha->host, hb->host)) { - return 0; - } - } - - for (i = 0; i < a->nres_reasons; i++) { - const xce_res_reason_t* ra = a->res_based_reasons[i]; - const xce_res_reason_t* rb = b->res_based_reasons[i]; - - if (ra == rb) { - continue; - } - if ((ra == NULL) || (rb == NULL)) { - return 0; - } - if ((ra->reason != rb->reason) - || !sim_verify_str_eq(ra->resource, rb->resource) - || !sim_verify_str_eq(ra->host, rb->host)) { - return 0; - } - } - - return 1; + return a->main_reason == b->main_reason; } /* diff --git a/src/scheduler/src/snapshot_load.c b/src/scheduler/src/snapshot_load.c index 3bca0c51..6a59d1c5 100644 --- a/src/scheduler/src/snapshot_load.c +++ b/src/scheduler/src/snapshot_load.c @@ -93,6 +93,25 @@ static void snapshot_build_primary_schedobj(xce_sched_obj_t* obj, primary->reason = NULL; primary->owner = obj; + /* bug-1772 fix (xce-audit-invariants scheduler, dimension 4): this + * function's own header comment documents it as a field-for-field port + * of core_build_primary_schedobj() (core_events.c) -- it had ported + * every field except this one. Without it, `primary->resreq_fp` stays + * all-zero (calloc'd) for every job restored from a snapshot, and + * alloc_cache.c's build_key_() folds resreq_fp directly into the + * unsatisfiable-cache key alongside borrowed user/queue/project + * identity -- two genuinely different restored jobs sharing a + * user/queue/project would collapse to the identical zero fingerprint + * and silently share (and incorrectly reuse) each other's + * unsatisfiable-cache verdict. Same formula, same field order, as + * core_build_primary_schedobj()'s own Req 7.1 comment. */ + primary->resreq_fp.min_tasks = resreq->minTasks; + primary->resreq_fp.max_tasks = resreq->maxTasks; + primary->resreq_fp.select_node_id = + (resreq->select != NULL && resreq->select->root != NULL) + ? resreq->select->root->node_id : 0; + primary->resreq_fp.rusage_hash = resreq->rusage_hash; + obj->u.primary = primary; } diff --git a/src/scheduler/testsuite/test_sim_verify.c b/src/scheduler/testsuite/test_sim_verify.c index 022ff33a..c3fe7b43 100644 --- a/src/scheduler/testsuite/test_sim_verify.c +++ b/src/scheduler/testsuite/test_sim_verify.c @@ -659,6 +659,42 @@ static void test_dispatch_decisions_differing_from_timestamp_still_match(void) "PASS\n"); } +/* + * test_dispatch_decisions_differing_instid_still_match - bug-1844 + * regression: `instid` (xce_alloc_t's per-process monotonic allocation- + * instance counter, stamped from `sched->core.nextid++` at allocation-build + * time -- scheduler.c's sched_get_id()) is an execution-order bookkeeping + * value, not part of a decision's semantic identity, exactly like `from` + * above (bug-1838-followup). The ORIGINAL recording's counter may have been + * running, and building allocations, for far longer before this capture + * window started; a fresh replay's own counter starts whatever its loaded + * snapshot's nextid happens to be -- the two have no reason to reach the + * same value for "the same" dispatch, even when every other field is + * byte-for-byte identical. Uses two `instid` values matching a real + * captured .replay file's own observed divergence (826 vs 1) to prove this + * is deliberate exclusion, not a fluke of small numbers happening to + * coincide. + */ +static void test_dispatch_decisions_differing_instid_still_match(void) +{ + xce_alloc_t* res_a[1] + = { make_test_alloc("mem", "", 826ULL, 307200.0, 100, -1) }; + xce_host_alloc_t* host_a[1] = { make_test_host_alloc("hostA", res_a, 1) }; + xce_job_alloc_t* expected_alloc = make_test_job_alloc(42, host_a, 1); + + xce_alloc_t* res_b[1] + = { make_test_alloc("mem", "", 1ULL, 307200.0, 100, -1) }; + xce_host_alloc_t* host_b[1] = { make_test_host_alloc("hostA", res_b, 1) }; + xce_job_alloc_t* actual_alloc = make_test_job_alloc(42, host_b, 1); + + replay_decision_t expected = make_replay_dispatch_decision(expected_alloc); + xce_decision_t* actual = make_dispatch_decision(actual_alloc); + + TEST_ASSERT_TRUE(sim_decision_eq(&expected, actual)); + + printf("test_dispatch_decisions_differing_instid_still_match: PASS\n"); +} + static void test_pend_decisions_with_identical_content_match(void) { replay_decision_t expected = make_replay_pend_decision(9001ULL, 3); @@ -695,6 +731,56 @@ static void test_pend_decisions_differing_main_reason_mismatch(void) printf("test_pend_decisions_differing_main_reason_mismatch: PASS\n"); } +/* + * test_pend_decisions_differing_reason_detail_still_match - bug-1845 + * regression: the recorded (expected) side represents a live cache-hit + * PEND (core.h's documented "simulation isolation" -- sim/replay never + * registers core->unsatisfiable_lookup_cb, so it can never itself produce + * this shape, only ever receive it from a recorded normal-mode run) -- + * main_reason set, zero host/resource reason detail + * (sched_pend_from_cached_reason_(), scheduler.c, never adds any). The + * live (actual) side represents replay's own full per-host computation for + * the SAME job/round -- same main_reason, but with real host- and + * resource-based reason detail attached (sched_try_alloc_on_host_(), + * resource.c). Same semantic outcome (PEND, same main reason) at two + * different, architecturally-legitimate detail levels -- must still + * compare equal. + */ +static void test_pend_decisions_differing_reason_detail_still_match(void) +{ + replay_decision_t expected = make_replay_pend_decision(9001ULL, 0); + xce_pendreason_t* reason = make_pendreason(9001ULL); + xce_host_reason_t* hreasons[1]; + xce_res_reason_t* rreasons[2]; + xce_decision_t* actual; + + hreasons[0] = (xce_host_reason_t*)calloc(1, sizeof(xce_host_reason_t)); + hreasons[0]->host = strdup("workerA"); + hreasons[0]->reason = 1; + + rreasons[0] = (xce_res_reason_t*)calloc(1, sizeof(xce_res_reason_t)); + rreasons[0]->resource = strdup("mem"); + rreasons[0]->host = strdup("workerA"); + rreasons[0]->reason = 2; + + rreasons[1] = (xce_res_reason_t*)calloc(1, sizeof(xce_res_reason_t)); + rreasons[1]->resource = strdup("slots"); + rreasons[1]->host = strdup("workerA"); + rreasons[1]->reason = 2; + + reason->reasons->main_reason = 0; + reason->reasons->nhost_reasons = 1; + reason->reasons->host_based_reasons = hreasons; + reason->reasons->nres_reasons = 2; + reason->reasons->res_based_reasons = rreasons; + + actual = make_pend_decision(reason); + + TEST_ASSERT_TRUE(sim_decision_eq(&expected, actual)); + + printf("test_pend_decisions_differing_reason_detail_still_match: PASS\n"); +} + static void test_decision_kind_mismatch_reported(void) { replay_decision_t expected = make_replay_pend_decision(1ULL, 0); @@ -1784,9 +1870,11 @@ int main(void) RUN_TEST(test_dispatch_decisions_differing_host_mismatch); RUN_TEST(test_dispatch_decisions_differing_resource_value_mismatch); RUN_TEST(test_dispatch_decisions_differing_from_timestamp_still_match); + RUN_TEST(test_dispatch_decisions_differing_instid_still_match); RUN_TEST(test_pend_decisions_with_identical_content_match); RUN_TEST(test_pend_decisions_differing_jobid_mismatch); RUN_TEST(test_pend_decisions_differing_main_reason_mismatch); + RUN_TEST(test_pend_decisions_differing_reason_detail_still_match); RUN_TEST(test_decision_kind_mismatch_reported); RUN_TEST(test_preempt_decision_always_reports_mismatch); RUN_TEST(test_decision_eq_defends_against_null_inputs); diff --git a/src/scheduler/testsuite/test_snapshot_save_load.c b/src/scheduler/testsuite/test_snapshot_save_load.c index 87a2baf8..e9ecc7cf 100644 --- a/src/scheduler/testsuite/test_snapshot_save_load.c +++ b/src/scheduler/testsuite/test_snapshot_save_load.c @@ -1245,6 +1245,74 @@ test_snapshot_load_wires_real_task_count_into_resreq_primary(void) TEST_ASSERT_EQUAL_INT(6, restored->resreq->u.primary->maxTasks); } +/* + * bug-1772 fix (xce-audit-invariants scheduler, dimension 4): a job + * restored from a snapshot must get a genuinely-computed + * schedobj->u.primary->resreq_fp, not the all-zero calloc() default. + * snapshot_build_primary_schedobj() (snapshot_load.c) is documented as a + * field-for-field port of core_build_primary_schedobj() (core_events.c) -- + * it had ported every field except this one. Without the fix, EVERY + * restored job's resreq_fp is {0,0,0,0}; alloc_cache.c's build_key_() + * folds resreq_fp directly into the unsatisfiable-cache key, so two + * distinct restored jobs sharing a user/queue/project would silently + * collapse onto the same cache entry. + */ +static void +test_snapshot_load_computes_resreq_fingerprint_for_restored_primary(void) +{ + xce_sched_core_t core; + sched_snapshot_data_t in; + xce_jobs_data_t jobs_data; + xce_queue_t wire_queue; + xce_queue_t* queues[1]; + xce_job_t* job; + xce_job_t* jobs[1]; + xce_sched_job_t* restored; + int rc; + + memset(&g_stub_state_a, 0, sizeof(g_stub_state_a)); + fixture_init(&core, &g_stub_plugin_a); + + memset(&wire_queue, 0, sizeof(wire_queue)); + wire_queue.queue = "normal"; + wire_queue.priority = 1; + wire_queue.status = QUEUE_STAT_OPEN; + queues[0] = &wire_queue; + + job = make_job_with_resreq(602, JOB_STAT_PEND, "normal", "alice", "proj1", + "type == any"); + job->submit->mintasks = 4; + job->submit->maxtasks = 6; + jobs[0] = job; + + memset(&jobs_data, 0, sizeof(jobs_data)); + jobs_data.count = 1; + jobs_data.jobs = jobs; + + memset(&in, 0, sizeof(in)); + in.jobs = &jobs_data; + in.queues = queues; + in.n_queues = 1; + + rc = xce_sched_core_load_snapshot(&core, &in); + TEST_ASSERT_EQUAL_INT(0, rc); + + restored = sched_get_job(&core, 602); + TEST_ASSERT_NOT_NULL(restored); + TEST_ASSERT_NOT_NULL(restored->schedobj); + TEST_ASSERT_EQUAL_INT(XCE_RESREQ_PRIMARY, restored->schedobj->tag); + TEST_ASSERT_NOT_NULL(restored->schedobj->u.primary); + + /* The fix under test: resreq_fp must reflect the restored primary's own + * real (task 2.2-wired) task count -- not {0,0,0,0}. */ + TEST_ASSERT_EQUAL_UINT32( + 4, restored->schedobj->u.primary->resreq_fp.min_tasks); + TEST_ASSERT_EQUAL_UINT32( + 6, restored->schedobj->u.primary->resreq_fp.max_tasks); + TEST_ASSERT_EQUAL_UINT32( + 0, restored->schedobj->u.primary->resreq_fp.select_node_id); +} + /* Regression-safety test (NOT a new feature): a job whose resreq fails to * parse on load is a pre-existing, out-of-boundary gap (design.md "Known * limitation") that task 1.2 must NOT try to fix -- it must only make sure @@ -2545,6 +2613,7 @@ int main(void) RUN_TEST( test_snapshot_load_builds_schedobj_for_primary_compound_and_alter_resreq); RUN_TEST(test_snapshot_load_wires_real_task_count_into_resreq_primary); + RUN_TEST(test_snapshot_load_computes_resreq_fingerprint_for_restored_primary); RUN_TEST( test_snapshot_load_leaves_schedobj_null_when_resreq_fails_to_parse); RUN_TEST(