diff --git a/.wolf/buglog.json b/.wolf/buglog.json index 1ec21384..63d791f3 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -17424,6 +17424,31 @@ "record": ".wolf/bugs/bug-1922.md", "gitea_issue": 346, "gitea_synced_status": "fixed" + }, + { + "id": "bug-1923", + "status": "open", + "status_updated": "2026-10-08", + "status_note": "newly logged", + "component": "scheduler", + "severity": "wrong-result", + "timestamp": "2026-10-08T07:17:34Z", + "last_seen": "2026-10-08T07:17:34Z", + "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", + "tags": [ + "sim", + "snapshot", + "resvals", + "replay", + "persistence" + ], + "related_bugs": [], + "fix_commits": [], + "record": ".wolf/bugs/bug-1923.md" } ] } diff --git a/.wolf/bugs/bug-1923.md b/.wolf/bugs/bug-1923.md new file mode 100644 index 00000000..d7c7219c --- /dev/null +++ b/.wolf/bugs/bug-1923.md @@ -0,0 +1,71 @@ +--- +id: "bug-1923" +status: "open" +status_updated: "2026-10-08" +status_note: "newly logged" +component: "scheduler" +severity: "wrong-result" +timestamp: "2026-10-08T07:17:34Z" +last_seen: "2026-10-08T07:17:34Z" +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: [] +--- + +# bug-1923: xce_scheduler --sim drops shared resource values from the snapshot (license shows value=(none)) + +## Description +**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: +``` +[sim] resource license: desc= valtype=numeric ordtype=incr flags=GLOBAL,SHARED,CONSUMABLE interval=0 +[sim] value=(none) +[sim] DISPATCH jobid=0-0-0-101 +[sim] PEND jobid=0-0-0-102 +[sim] PEND jobid=0-0-0-103 +[sim] PEND jobid=0-0-0-104 +``` +When the same value arrives as a `RESVALS_FULL` replay event, it loads (`value=2.00 used=2.00`), and jobs 102 and 103 dispatch. + +**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. + +**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. + +**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. + +Two separate defects were found (see Reproduction, variants A and C): +- **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. +- **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. + +## Environment +- OS: no /etc/os-release; Docker container; NixOS kernel; kernel Linux 6.18.33 x86_64 +- libc: glibc 2.42-47 (interpreter /nix/store/wb6rhpznjfczwlwx23zmdrrw74bayxw4-glibc-2.42-47/lib/ld-linux-x86-64.so.2) +- Toolchain: gcc (GCC) 15.2.0, meson 1.9.1 +- Build: asan (xce.build) +- Code: scheduler-framework @ ed201686-dirty +- Deployment: none (offline `xce_scheduler --sim --interactive`; the replay is synthetic, written by a test generator with 2 virtual workers) +- Note: `-dirty` = only the uncommitted task 1.1 test files and unrelated .wolf/ bookkeeping; no production scheduler source was changed + +## Reproduction +Durable copies are in `/home/claude/tmp/bug-1923/`: `fixA/contention.replay` has the value in the snapshot (license idx 2); `fixC/contention.replay` is the same but the license is idx 0; `fixB/contention.replay` uses the `RESVALS_FULL` workaround. +1. Build the scheduler: `bash src/tools/xce-build.sh scheduler` (ASAN, `src/xce.build`). +2. `cd "$(mktemp -d)" && cp /home/claude/tmp/bug-1923/fixA/contention.replay .` +3. `printf 'info resource license\nstep\ninfo resource license\nquit\n' | ASAN_OPTIONS=detect_leaks=0 TERM=dumb /home/rshen/projects/xce/scheduler-framework/src/xce.build/scheduler/xce_scheduler --sim contention.replay --interactive --logfile sched.log` +4. Both `info resource license` calls print `value=(none)`, and jobs 102 and 103 PEND. Repeat with `fixC` (same result: the read-side skip alone is enough) and `fixB` (the first call prints `value=(none)` because the event is applied in round 1; after `step` it prints `value=2.00 used=2.00` and jobs 102 and 103 dispatch). +- How the replays are generated: `/home/claude/tmp/bug-1923/gen.c` is a copy of the test's `write_contention_replay()`, with `-DSNAPSHOT_LICENSE` (A) or `-DLICENSE_FIRST` (C). The value is put in with `zarray_put(&sched.core.sharedInst, lic->idx, val)` before `sched_record_start()`. `build_and_run.sh [N]` rebuilds and reruns all three; it needs the scratch object copies, which were not kept. `decode.c` dumps a replay's `SnapshotEntry` resvals: A shows `count=0`, C shows `resval name=license host="" = 2.000000`. +- Frequency: deterministic (A 20/20 and C 20/20 show `value=(none)`; B 0/20; 2026-10-08) +- Evidence: `/home/claude/tmp/bug-1923/` (replays, generator, decoder, probe script) + +## Root cause +TODO: required for fixed/partial + +## Fix +TODO: required for fixed/partial + +## 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 + +## References +- Related: none