From e06bdc290b4a1aaa3e3caaa8bc136f60e2c1f775 Mon Sep 17 00:00:00 2001 From: Rongsong Shen Date: Thu, 8 Oct 2026 08:11:37 +0000 Subject: [PATCH] docs(buglog): bug-1923 fixed (16616d96), synced to Gitea #348 Co-Authored-By: Claude Opus 5.5 (1M context) --- .wolf/buglog.json | 14 ++++++++------ .wolf/bugs/bug-1923.md | 32 ++++++++++++++++++++++---------- .wolf/cerebrum.md | 2 +- 3 files changed, 31 insertions(+), 17 deletions(-) diff --git a/.wolf/buglog.json b/.wolf/buglog.json index 3d3e9131..d9bd2762 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -17427,9 +17427,9 @@ }, { "id": "bug-1923", - "status": "open", + "status": "fixed", "status_updated": "2026-10-08", - "status_note": "newly logged", + "status_note": "", "component": "scheduler", "severity": "wrong-result", "timestamp": "2026-10-08T07:17:34Z", @@ -17437,8 +17437,8 @@ "occurrences": 1, "error_message": "xce_scheduler --sim drops shared resource values from the snapshot (license shows value=(none))\n\n**Observed:** a shared (cluster-wide, `GLOBAL|SHARED|CONSUMABLE`) resource value that is present in a recording's `SnapshotEntry` is not loaded by `xce_scheduler --sim`. `info resource license`, after `step` or straight after load, shows:\n```\n[sim] resource license: desc= valtype=numeric ordtype=incr flags=GLOBAL,SHARED,CONSUMABLE interval=0\n[sim] value=(none)\n[sim] DISPATCH jobid=0-0-0-101\n[sim] PEND jobid=0-0-0-102\n[sim] PEND jobid=0-0-0-103\n[sim] PEND jobid=0-0-0-104\n```\nWhen the same value arrives as a `RESVALS_FULL` replay event, it loads (`value=2.00 used=2.00`), and jobs 102 and 103 dispatch.\n\n**Expected:** every shared resource value in the snapshot is loaded into `core->sharedInst`, so the simulator starts with the same shared pool the recorder had.\n\n**Impact:** wrong result in the simulator. A replay whose shared resource values were set before recording started, and never re-sent as a `RESVALS_FULL` event during the recording, simulates with no license pool. Jobs needing the resource pend instead of dispatching, so a sim replay diverges from what live did. Nothing is logged when the value is dropped.\n\n**Found by:** spec task scheduler-sim-decision-trace 1.1, while building the trace-off REPL baseline fixture (`src/scheduler/testsuite/test_repl_trace_baseline.c`). That fixture now sends the license value as a `RESVALS_FULL` event to work around this bug.\n\nTwo separate defects were found (see Reproduction, variants A and C):\n- **Read side, confirmed with gdb and a decoder:** `snapshot_load.c:129` skips the entry when `rv->host != NULL`. After the capnp round trip, a host that was written as NULL decodes as `\"\"`, so every shared resval in a snapshot is skipped and line 140's `zarray_put` is never reached. The `RESVALS_FULL` path (`core_events.c:1124-1147`) has no such host check.\n- **Write side, Suspected (from code reading, matches the decoder output):** `snapshot.c:431` loops `for (i = 0; i < core->sharedInst.count; i++)`, but `zarray_put_ex` (`src/lib/zarray.c:291-330`) counts filled slots, not the highest index plus one. A sparse `sharedInst` therefore drops values at higher indices: with the license at idx 2 and `count == 1`, the snapshot carries `resvals count=0`. The same pattern may affect per-worker resvals at `snapshot_wire.c:242` (`w->resvals.count`); not checked.", "file": "src/scheduler/src/snapshot.c, src/scheduler/src/snapshot_load.c, src/scheduler/src/snapshot_wire.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": "Two separate defects on the SnapshotEntry save/load path, both pre-existing (origin unknown):\n- **Read side, `src/scheduler/src/snapshot_load.c:129`:** the shared-pool loop skipped any resval with `rv->host != NULL`. The writer stores shared values with `host = NULL`, but after the capnp round trip (`write_snapshot_entry()` in recording.c → `.replay` → `read_SnapshotEntry`/`decode_SnapshotEntry` in sim.c) a NULL host decodes as `\"\"`. So every shared value in a snapshot read from a file was silently skipped, and `core->sharedInst` started empty. The `RESVALS_FULL` event path (`core_events.c:1124-1147`) has no host check, which is why the workaround loaded. A non-empty host only appears on `RESVALS_DELTA` (routing a value to one worker).\n- **Write side, `src/scheduler/src/snapshot.c:431`:** the shared-pool loop was bounded by `core->sharedInst.count`. `zarray_put_ex` (`src/lib/zarray.c`) counts filled slots, not highest index + 1, so in a sparse `sharedInst` the values at higher indices were never written. In the baseline fixture, `license` (idx 2) and `limit=cluster_slots` were dropped.\n- **Same defect, per worker, `src/scheduler/src/snapshot_wire.c:242`:** the loop over `w->resvals` was bounded by `w->resvals.count`. A worker never holds a value at a global resource's idx, so its resvals always have holes, and `limit=host_slots` was dropped for every worker.\n- Scope checked: no other `.count`-bounded loop over a sparse resval zarray remains in src/scheduler or src/lib. `repl_info.c:524` and `resource.c:262` already use `.caps`; the other `.count` uses are dense lists or log lines.", + "fix": "- `snapshot_load.c`: a resval with a NULL **or empty** host is a shared-pool entry; only a named host is skipped.\n- `snapshot.c`: the shared-pool loop is bounded by `sharedInst.caps` (the project convention for sparse resval arrays). Empty slots were already skipped via `zarray_get` returning NULL.\n- `snapshot_wire.c`: the per-worker loop is bounded by `w->resvals.caps`.\n- These changes make the shared and per-worker values round-trip through both the write side and the load seam (persistence.md, snapshot field-completeness).\n- Compatibility: replay files written by the old writer lack the dropped values, so the reader fix alone can't recover them (`/home/claude/tmp/bug-1923/fixA` still shows `value=(none)`). Files written from now on carry them.\n- Fixture: `src/scheduler/testsuite/fixtures/repl_trace_baseline/set_output.replay` was regenerated. Only its SnapshotEntry changed (+304 bytes: `license`, `limit=cluster_slots` and two per-worker `limit=host_slots` values). The header differs only in the ignored wall-clock field, the transcript, `sim_output.replay` and verify output are unchanged, and messages 2-15 are byte-identical.\n\nVerification:\n- Test: new `src/scheduler/testsuite/test_snapshot_sparse_resvals.c` (\"scheduler snapshot sparse resvals test\"), which links the real scheduler sources. RED before the fix: 6 Tests 5 Failures (`test_save_keeps_sparse_shared_resval`, `test_save_keeps_sparse_worker_resval`, `test_save_load_round_trip_keeps_sparse_resvals`, `test_load_takes_shared_resval_with_empty_host`, and `test_replay_round_trip_keeps_sparse_resvals`, which goes through the real `.replay` writer and the `--sim` start-up reader). The guard test `test_load_skips_resval_with_named_host` passed. GREEN after: 6 Tests 0 Failures.\n- Suites: scheduler meson suite Ok 100 / Fail 0, asan (`src/xce.build` in the fix worktree); `scheduler repl trace baseline test` OK with the regenerated `set_output.replay`.\n- Live: `xce_scheduler --sim /home/claude/tmp/bug-1923/fixC/contention.replay --interactive` on the fixed asan build: `info resource license` shows `value=2.00 used=0.00`, then `value=2.00 used=2.00` after `step`, and jobs 102 and 103 DISPATCH (before the fix: `value=(none)`, and both PEND). A variant-A replay regenerated with the fixed writer also loads `value=2.00`. No HA soak was needed: the change is limited to the scheduler's snapshot save/load and does not touch the controller or WAL.", "tags": [ "sim", "snapshot", @@ -17447,10 +17447,12 @@ "persistence" ], "related_bugs": [], - "fix_commits": [], + "fix_commits": [ + "16616d96" + ], "record": ".wolf/bugs/bug-1923.md", "gitea_issue": 348, - "gitea_synced_status": "open" + "gitea_synced_status": "fixed" } ] } diff --git a/.wolf/bugs/bug-1923.md b/.wolf/bugs/bug-1923.md index b53444aa..0be4addc 100644 --- a/.wolf/bugs/bug-1923.md +++ b/.wolf/bugs/bug-1923.md @@ -1,8 +1,8 @@ --- id: "bug-1923" -status: "open" +status: "fixed" status_updated: "2026-10-08" -status_note: "newly logged" +status_note: "" component: "scheduler" severity: "wrong-result" timestamp: "2026-10-08T07:17:34Z" @@ -11,9 +11,10 @@ occurrences: 1 files: ["src/scheduler/src/snapshot.c", "src/scheduler/src/snapshot_load.c", "src/scheduler/src/snapshot_wire.c"] tags: ["sim", "snapshot", "resvals", "replay", "persistence"] related: [] +fix_commits: ["16616d96"] gitea_issue: 348 -gitea_synced_status: "open" -gitea_synced_hash: "d364cfaa24aa" +gitea_synced_status: "fixed" +gitea_synced_hash: "735fa9567f4e" --- # bug-1923: xce_scheduler --sim drops shared resource values from the snapshot (license shows value=(none)) @@ -60,15 +61,26 @@ Durable copies are in `/home/claude/tmp/bug-1923/`: `fixA/contention.replay` has - Evidence: `/home/claude/tmp/bug-1923/` (replays, generator, decoder, probe script) ## Root cause -TODO: required for fixed/partial +Two separate defects on the SnapshotEntry save/load path, both pre-existing (origin unknown): +- **Read side, `src/scheduler/src/snapshot_load.c:129`:** the shared-pool loop skipped any resval with `rv->host != NULL`. The writer stores shared values with `host = NULL`, but after the capnp round trip (`write_snapshot_entry()` in recording.c → `.replay` → `read_SnapshotEntry`/`decode_SnapshotEntry` in sim.c) a NULL host decodes as `""`. So every shared value in a snapshot read from a file was silently skipped, and `core->sharedInst` started empty. The `RESVALS_FULL` event path (`core_events.c:1124-1147`) has no host check, which is why the workaround loaded. A non-empty host only appears on `RESVALS_DELTA` (routing a value to one worker). +- **Write side, `src/scheduler/src/snapshot.c:431`:** the shared-pool loop was bounded by `core->sharedInst.count`. `zarray_put_ex` (`src/lib/zarray.c`) counts filled slots, not highest index + 1, so in a sparse `sharedInst` the values at higher indices were never written. In the baseline fixture, `license` (idx 2) and `limit=cluster_slots` were dropped. +- **Same defect, per worker, `src/scheduler/src/snapshot_wire.c:242`:** the loop over `w->resvals` was bounded by `w->resvals.count`. A worker never holds a value at a global resource's idx, so its resvals always have holes, and `limit=host_slots` was dropped for every worker. +- Scope checked: no other `.count`-bounded loop over a sparse resval zarray remains in src/scheduler or src/lib. `repl_info.c:524` and `resource.c:262` already use `.caps`; the other `.count` uses are dense lists or log lines. ## Fix -TODO: required for fixed/partial +- `snapshot_load.c`: a resval with a NULL **or empty** host is a shared-pool entry; only a named host is skipped. +- `snapshot.c`: the shared-pool loop is bounded by `sharedInst.caps` (the project convention for sparse resval arrays). Empty slots were already skipped via `zarray_get` returning NULL. +- `snapshot_wire.c`: the per-worker loop is bounded by `w->resvals.caps`. +- These changes make the shared and per-worker values round-trip through both the write side and the load seam (persistence.md, snapshot field-completeness). +- Compatibility: replay files written by the old writer lack the dropped values, so the reader fix alone can't recover them (`/home/claude/tmp/bug-1923/fixA` still shows `value=(none)`). Files written from now on carry them. +- Fixture: `src/scheduler/testsuite/fixtures/repl_trace_baseline/set_output.replay` was regenerated. Only its SnapshotEntry changed (+304 bytes: `license`, `limit=cluster_slots` and two per-worker `limit=host_slots` values). The header differs only in the ignored wall-clock field, the transcript, `sim_output.replay` and verify output are unchanged, and messages 2-15 are byte-identical. ## 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: new `src/scheduler/testsuite/test_snapshot_sparse_resvals.c` ("scheduler snapshot sparse resvals test"), which links the real scheduler sources. RED before the fix: 6 Tests 5 Failures (`test_save_keeps_sparse_shared_resval`, `test_save_keeps_sparse_worker_resval`, `test_save_load_round_trip_keeps_sparse_resvals`, `test_load_takes_shared_resval_with_empty_host`, and `test_replay_round_trip_keeps_sparse_resvals`, which goes through the real `.replay` writer and the `--sim` start-up reader). The guard test `test_load_skips_resval_with_named_host` passed. GREEN after: 6 Tests 0 Failures. +- Suites: scheduler meson suite Ok 100 / Fail 0, asan (`src/xce.build` in the fix worktree); `scheduler repl trace baseline test` OK with the regenerated `set_output.replay`. +- Live: `xce_scheduler --sim /home/claude/tmp/bug-1923/fixC/contention.replay --interactive` on the fixed asan build: `info resource license` shows `value=2.00 used=0.00`, then `value=2.00 used=2.00` after `step`, and jobs 102 and 103 DISPATCH (before the fix: `value=(none)`, and both PEND). A variant-A replay regenerated with the fixed writer also loads `value=2.00`. No HA soak was needed: the change is limited to the scheduler's snapshot save/load and does not touch the controller or WAL. ## References -- Related: none +- Related: bug-1568 (same `snapshot_wire.c` worker-resval loop; that bug added the missing-resource diagnostic) +- Docs: .kiro/steering/persistence.md (Snapshot Save/Load Field-Completeness) +- Found by: .kiro/specs/scheduler-sim-decision-trace task 1.1 diff --git a/.wolf/cerebrum.md b/.wolf/cerebrum.md index 6dbf5cfd..fa84643f 100644 --- a/.wolf/cerebrum.md +++ b/.wolf/cerebrum.md @@ -158,7 +158,7 @@ - **(2026-09-29) Standalone ASAN `xce_scheduler --sim` exits 1 from exit-time LeakSanitizer reports (snapshot decode), not from a replay failure** -- run live `--sim-verify` replays with `ASAN_OPTIONS=detect_leaks=0` (as run-ha-soak.sh's replay gate does) and count `MISMATCH` lines. The HA soak (`run-ha-soak.sh`) must run inside `nix develop ./src` (deploy needs openssl) and needs `XCE_HA_BIN`/`XCE_HA_XT` pointing at a build dir that has controller+harness+worker+scheduler. - **(2026-09-29, bug-1883) Scheduler ctx vectors filled by prepare hooks are append-only (`xvec_idval_store` never dedups), so any pass that recomputes a want must reset that vector first.** A COMPOUND/ALTER job's primaries share one ctx; the job-level prepare pass reset only `.shared`, leaving the previous primary's per-host want in `.host`. Test time-sensitive replay fields with an epoch-scale timestamp plus a sub-second part: a fixture at `begin_round = 2000` ns cannot tell a correct `from` from 0 or from sub-second drift. -- **(2026-10-08, scheduler-sim-decision-trace 1.1, bug-1923) Shared (cluster-wide) resource values put in a sim recording's SnapshotEntry never reach `xce_scheduler --sim`.** `snapshot_load.c` skips resvals whose host decodes as `""` (not NULL), and `snapshot.c` iterates `sharedInst.count` (filled-slot count, not max index). Until fixed, test fixtures that need a shared value (e.g. a license pool) must send it as a RESVALS_FULL replay event. +- **(2026-10-08, scheduler-sim-decision-trace 1.1, bug-1923) Shared (cluster-wide) resource values put in a sim recording's SnapshotEntry never reach `xce_scheduler --sim`.** `snapshot_load.c` skips resvals whose host decodes as `""` (not NULL), and `snapshot.c` iterates `sharedInst.count` (filled-slot count, not max index). FIXED in 16616d96 (load accepts an empty host; save loops bound by `.caps`). Replays written before the fix still lack those values. Lesson: sparse resval zarrays must be iterated to `.caps`, never `.count`. - **(2026-10-08) `xce-build.sh`'s default ASAN build dir is `src/xce.build` relative to the repo root** (the script runs from `src/`); raw meson commands from the repo root need `nix develop ./src --command meson test -C src/xce.build ...`. ## Do-Not-Repeat