From 16b422e303e3fb91cd1c3a63fdf837c8bd3221d7 Mon Sep 17 00:00:00 2001 From: Rongsong Shen Date: Mon, 28 Sep 2026 07:26:50 +0000 Subject: [PATCH] chore(buglog): log bug-1880 (sim-verify mismatch on array job dispatches) and bug-1881 (mismatch message hides the diff) Co-Authored-By: Claude Opus 5.5 (1M context) --- .wolf/buglog.json | 53 ++++++++++++++++++++++++++++++++++++++++++ .wolf/bugs/bug-1880.md | 53 ++++++++++++++++++++++++++++++++++++++++++ .wolf/bugs/bug-1881.md | 52 +++++++++++++++++++++++++++++++++++++++++ 3 files changed, 158 insertions(+) create mode 100644 .wolf/bugs/bug-1880.md create mode 100644 .wolf/bugs/bug-1881.md diff --git a/.wolf/buglog.json b/.wolf/buglog.json index 9fd9ef50..47254627 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -16138,6 +16138,59 @@ ], "fix_commits": [], "record": ".wolf/bugs/bug-1879.md" + }, + { + "id": "bug-1880", + "status": "investigating", + "status_updated": "2026-09-28", + "status_note": "not reproduced yet: needs the snapshot before 06:50:11; message hides the diff (bug-1881)", + "component": "scheduler", + "severity": "wrong-result", + "timestamp": "2026-09-28T07:26:08Z", + "last_seen": "2026-09-28T07:26:08Z", + "occurrences": 1, + "error_message": "sim-verify flags every DISPATCH of array job 0-12-1790578108-0 as MISMATCH in a pc13v replay\n\n**Observed:**\n```\n[2026-09-28 06:50:11,909] [93231] [ ERROR] [ sim_log_mismatch] sim_log_mismatch decision verification MISMATCH at begin_round=1790578211909717418 decision_index=0 expected_ts=1790578211910119659 -- expected: DISPATCH jobid=0-12-1790578108-0[7] nhosts=1 -- actual: DISPATCH jobid=0-12-1790578108-0[7] nhosts=1\n... (one per dispatch, elements [7]..[49], through 07:00:21)\n```\n**Expected:** the simulator reproduces the recorded dispatches exactly, as for the other jobs in the capture.\n**Impact:** sim-verify reports every dispatch of this array job as divergent, so the replay cannot be used to check scheduler parity; either the simulator allocates differently from the live scheduler (a real parity bug) or the verifier compares a field that legitimately differs.\n**Found by:** user replaying a pc13v capture with sim-verify, 2026-09-28", + "file": "src/scheduler/src/sim_verify.c", + "root_cause": "Unconfirmed: the printed fields (kind, jobid, nhosts) are equal, so the difference is in what sim_decision_eq() (src/scheduler/src/sim_verify.c) compares beyond them -- per host, the allocation's resname, value, duration and reserve (sim_verify_alloc_eq/host_alloc_eq/job_alloc_eq). bug-1881 makes the message show which.", + "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": [ + "scheduler", + "sim", + "sim-verify", + "replay", + "array-job" + ], + "related_bugs": [ + "bug-1842", + "bug-1844", + "bug-1845" + ], + "fix_commits": [], + "record": ".wolf/bugs/bug-1880.md" + }, + { + "id": "bug-1881", + "status": "open", + "status_updated": "2026-09-28", + "status_note": "logged 2026-09-28; fix not started", + "component": "scheduler", + "severity": "wrong-result", + "timestamp": "2026-09-28T07:26:09Z", + "last_seen": "2026-09-28T07:26:09Z", + "occurrences": 1, + "error_message": "sim_log_mismatch prints identical expected/actual, hiding the field that differs\n\n**Observed:**\n```\n... MISMATCH ... -- expected: DISPATCH jobid=0-12-1790578108-0[49] nhosts=1 -- actual: DISPATCH jobid=0-12-1790578108-0[49] nhosts=1\n```\n**Expected:** the message names the field(s) that differ, with both values.\n**Impact:** a mismatch cannot be diagnosed from the log (bug-1880: 43 such lines, none showing the difference).\n**Found by:** user reading the bug-1880 replay log, 2026-09-28", + "file": "src/scheduler/src/sim_verify.c", + "root_cause": "sim_log_mismatch() (src/scheduler/src/sim_verify.c) summarizes each decision as kind + jobid + nhosts, while sim_decision_eq() also compares every host's allocations (resname, value, duration, reserve), so a difference there prints two identical summaries.", + "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": [ + "scheduler", + "sim", + "sim-verify", + "logging" + ], + "related_bugs": [], + "fix_commits": [], + "record": ".wolf/bugs/bug-1881.md" } ] } diff --git a/.wolf/bugs/bug-1880.md b/.wolf/bugs/bug-1880.md new file mode 100644 index 00000000..c9cd59ea --- /dev/null +++ b/.wolf/bugs/bug-1880.md @@ -0,0 +1,53 @@ +--- +id: "bug-1880" +status: "investigating" +status_updated: "2026-09-28" +status_note: "not reproduced yet: needs the snapshot before 06:50:11; message hides the diff (bug-1881)" +component: "scheduler" +severity: "wrong-result" +timestamp: "2026-09-28T07:26:08Z" +last_seen: "2026-09-28T07:26:08Z" +occurrences: 1 +files: ["src/scheduler/src/sim_verify.c"] +tags: ["scheduler", "sim", "sim-verify", "replay", "array-job"] +related: ["bug-1842", "bug-1844", "bug-1845"] +--- + +# bug-1880: sim-verify flags every DISPATCH of array job 0-12-1790578108-0 as MISMATCH in a pc13v replay + +## Description +**Observed:** +``` +[2026-09-28 06:50:11,909] [93231] [ ERROR] [ sim_log_mismatch] sim_log_mismatch decision verification MISMATCH at begin_round=1790578211909717418 decision_index=0 expected_ts=1790578211910119659 -- expected: DISPATCH jobid=0-12-1790578108-0[7] nhosts=1 -- actual: DISPATCH jobid=0-12-1790578108-0[7] nhosts=1 +... (one per dispatch, elements [7]..[49], through 07:00:21) +``` +**Expected:** the simulator reproduces the recorded dispatches exactly, as for the other jobs in the capture. +**Impact:** sim-verify reports every dispatch of this array job as divergent, so the replay cannot be used to check scheduler parity; either the simulator allocates differently from the live scheduler (a real parity bug) or the verifier compares a field that legitimately differs. +**Found by:** user replaying a pc13v capture with sim-verify, 2026-09-28 + +## Environment +- OS: NixOS 26.05 (Yarara); 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: debug (build.dbg) +- Code: scheduler-framework @ 4c134127 (`xce_scheduler --version`: v0.0.0.1-4c134127-85e8fc00, built 2026-09-28T06:40:21Z) +- Deployment: pc13v: xce_scheduler in simulation mode (pid 93231) replaying a capture of the live pc13v cluster's scheduler (scheduler-replay-20260928-064842.replay, captured from 06:48:42); exact command line and --sim-start-ts not recorded + +## Reproduction +1. `xce_scheduler -s data/scheduler-replay-20260928-064842.replay --sim-verify` starting from a snapshot BEFORE the array job's first dispatch at 06:50:11 (the default start, the replay's most recent snapshot, is after them) +- Frequency: 43/43 dispatches of array job 0-12-1790578108-0 (elements [7]..[49]) in the pc13v run; 0/3 here with the default start (those rounds are never replayed); an arbitrary --sim-start-ts (1790578000000000000) is rejected -- the right snapshot is not known yet +- Evidence: data/scheduler-replay-20260928-064842.replay and data/xce_scheduler.log (ERROR lines only), copied from pc13v 2026-09-28 + +## Root cause +Unconfirmed: the printed fields (kind, jobid, nhosts) are equal, so the difference is in what sim_decision_eq() (src/scheduler/src/sim_verify.c) compares beyond them -- per host, the allocation's resname, value, duration and reserve (sim_verify_alloc_eq/host_alloc_eq/job_alloc_eq). bug-1881 makes the message show which. + +## 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: bug-1881 (the message hides the differing field), bug-1842, bug-1844, bug-1845 (earlier --sim-verify false positives) diff --git a/.wolf/bugs/bug-1881.md b/.wolf/bugs/bug-1881.md new file mode 100644 index 00000000..ee15fab8 --- /dev/null +++ b/.wolf/bugs/bug-1881.md @@ -0,0 +1,52 @@ +--- +id: "bug-1881" +status: "open" +status_updated: "2026-09-28" +status_note: "logged 2026-09-28; fix not started" +component: "scheduler" +severity: "wrong-result" +timestamp: "2026-09-28T07:26:09Z" +last_seen: "2026-09-28T07:26:09Z" +occurrences: 1 +files: ["src/scheduler/src/sim_verify.c"] +tags: ["scheduler", "sim", "sim-verify", "logging"] +related: [] +--- + +# bug-1881: sim_log_mismatch prints identical expected/actual, hiding the field that differs + +## Description +**Observed:** +``` +... MISMATCH ... -- expected: DISPATCH jobid=0-12-1790578108-0[49] nhosts=1 -- actual: DISPATCH jobid=0-12-1790578108-0[49] nhosts=1 +``` +**Expected:** the message names the field(s) that differ, with both values. +**Impact:** a mismatch cannot be diagnosed from the log (bug-1880: 43 such lines, none showing the difference). +**Found by:** user reading the bug-1880 replay log, 2026-09-28 + +## Environment +- OS: NixOS 26.05 (Yarara); 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: debug (build.dbg) +- Code: scheduler-framework @ 4c134127 (`xce_scheduler --version`: v0.0.0.1-4c134127-85e8fc00, built 2026-09-28T06:40:21Z) +- Deployment: pc13v: xce_scheduler in simulation mode (pid 93231) replaying a capture of the live pc13v cluster's scheduler (scheduler-replay-20260928-064842.replay, captured from 06:48:42); exact command line and --sim-start-ts not recorded + +## Reproduction +1. Any --sim-verify mismatch whose decisions differ only below the jobid/nhosts level (bug-1880's replay) +- Frequency: deterministic (43/43 lines in the pc13v run) +- Evidence: data/xce_scheduler.log + +## Root cause +sim_log_mismatch() (src/scheduler/src/sim_verify.c) summarizes each decision as kind + jobid + nhosts, while sim_decision_eq() also compares every host's allocations (resname, value, duration, reserve), so a difference there prints two identical summaries. + +## 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: bug-1880