From ce729b5fada131f413352632285be70eb81efd74 Mon Sep 17 00:00:00 2001 From: Rongsong Shen Date: Fri, 2 Oct 2026 04:24:25 +0000 Subject: [PATCH] docs(buglog): bug-1902 fixed in daeb9041 Co-Authored-By: Claude Opus 5.5 (1M context) --- .wolf/buglog.json | 12 +++++++----- .wolf/bugs/bug-1902.md | 23 +++++++++++++---------- 2 files changed, 20 insertions(+), 15 deletions(-) diff --git a/.wolf/buglog.json b/.wolf/buglog.json index 7d432868..84445b50 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -16819,9 +16819,9 @@ }, { "id": "bug-1902", - "status": "investigating", + "status": "fixed", "status_updated": "2026-10-02", - "status_note": "recurred 2026-10-01 in a full xce-build all run (bug-1736 work): test_walcompare_unrecognized_flag_rejected_with_usage, 'xce_test did not exit within the harness's safety timeout after quit'; passed 3/3 targeted reruns", + "status_note": "", "component": "harness", "severity": "noise", "timestamp": "2026-10-01T11:22:43Z", @@ -16829,8 +16829,8 @@ "occurrences": 2, "error_message": "harness pty test test_source_missing_file_rejected_with_error timed out once after quit\n\n**Observed:** during task 4.3 of spec job-array-one-based-index, one run of the harness suite under ASAN failed in the pty CLI test:\n```\ntest_test_cli.c: test_source_missing_file_rejected_with_error: FAIL: xce_test did not exit within the harness's safety timeout after 'quit'\n```\n**Expected:** after `quit`, `xce_test` exits within the test's safety timeout and the test passes, as it does in every other run.\n**Impact:** noise: an intermittent false failure of the harness suite; no product impact observed.\n**Found by:** test (harness suite run during task 4.3, 2026-10-01)", "file": "src/harness/testsuite/test_test_cli.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": "Not an `xce_test` hang. `clitest_wait_for_exit()` and `clitest_wait_for_text()` (`src/harness/testsuite/test_test_cli.c`) did not measure time: they added `CLITEST_POLL_SLICE_MS` (100 ms) per loop iteration. After `quit`, `xce_test` closes its pty before it becomes reapable, so `poll()` returns at once on every call (hang-up, nothing to read) and the loop spun: the 5000 ms budget ran out within milliseconds while the ASAN child was still tearing down, which takes longer under load. Measured with a temporary wall-clock probe over 2287 exits under load: real time from `quit` to reap at most 6 ms, while the counter reached up to 58800 ms (9 exits would have tripped the 5 s limit).", + "fix": "Both waits use a `CLOCK_MONOTONIC` deadline (`clitest_now_ms()`), and `clitest_pump_once()` naps 10 ms when `poll()` wakes with nothing to read, so a hung-up pty no longer spins. Test-harness only; `xce_test` is unchanged.\n\nVerification:\n- Test: the load reproduction above is the RED (12/48 runs failing); GREEN after the fix: 0/48 and 0/48 in two further rounds of the same 16-way parallel load\n- Suites: harness meson suite 7/7 OK (asan, src/build.jai)\n- Live: n/a (test-harness timing; no product code changed)", "tags": [ "harness", "test", @@ -16838,7 +16838,9 @@ "pty" ], "related_bugs": [], - "fix_commits": [], + "fix_commits": [ + "daeb9041" + ], "record": ".wolf/bugs/bug-1902.md", "repro_attempts": "0/5 reruns, 2026-10-01 (4 targeted meson reruns + reviewer full run)" }, diff --git a/.wolf/bugs/bug-1902.md b/.wolf/bugs/bug-1902.md index fe866bcf..db1ebcee 100644 --- a/.wolf/bugs/bug-1902.md +++ b/.wolf/bugs/bug-1902.md @@ -1,8 +1,8 @@ --- id: "bug-1902" -status: "investigating" +status: "fixed" status_updated: "2026-10-02" -status_note: "recurred 2026-10-01 in a full xce-build all run (bug-1736 work): test_walcompare_unrecognized_flag_rejected_with_usage, 'xce_test did not exit within the harness's safety timeout after quit'; passed 3/3 targeted reruns" +status_note: "" component: "harness" severity: "noise" timestamp: "2026-10-01T11:22:43Z" @@ -11,6 +11,7 @@ occurrences: 2 files: ["src/harness/testsuite/test_test_cli.c"] tags: ["harness", "test", "flaky", "pty"] related: [] +fix_commits: ["daeb9041"] repro_attempts: "0/5 reruns, 2026-10-01 (4 targeted meson reruns + reviewer full run)" --- @@ -34,20 +35,22 @@ test_test_cli.c: test_source_missing_file_rejected_with_error: FAIL: xce_test di - Deployment: none (harness_unit_test, pty-driven xce_test, no controller) ## Reproduction -1. `bash src/tools/xce-build.sh harness asan build.jai --jobs 8 --incremental` (runs the harness suite, including `test_test_cli.c` over a pty) -- Frequency: 1/6 runs, 2026-10-01 (passed in 4 targeted reruns and in the reviewer's run) -- Evidence: not kept (the failing build log was overwritten by the passing reruns) +1. Build the harness (`bash src/tools/xce-build.sh harness asan build.jai --jobs 8 --incremental`). +2. Run the pty test binary 16 at a time to load the machine (32 cores here): `for i in $(seq 16); do ASAN_OPTIONS=detect_leaks=0 src/build.jai/harness/harness_unit_test > run$i.log 2>&1 & done; wait`, three rounds. +3. Some runs fail a different `test_test_cli.c` test each time with `xce_test did not exit within the harness's safety timeout after 'quit'`. +- Frequency: 12/48 runs under 16-way parallel load, 2026-10-01 (1/6 and 1/127-test full suite runs earlier, unloaded reruns pass) +- Evidence: not kept (reproduces on demand with the steps above) ## Root cause -TODO: required for fixed/partial +Not an `xce_test` hang. `clitest_wait_for_exit()` and `clitest_wait_for_text()` (`src/harness/testsuite/test_test_cli.c`) did not measure time: they added `CLITEST_POLL_SLICE_MS` (100 ms) per loop iteration. After `quit`, `xce_test` closes its pty before it becomes reapable, so `poll()` returns at once on every call (hang-up, nothing to read) and the loop spun: the 5000 ms budget ran out within milliseconds while the ASAN child was still tearing down, which takes longer under load. Measured with a temporary wall-clock probe over 2287 exits under load: real time from `quit` to reap at most 6 ms, while the counter reached up to 58800 ms (9 exits would have tripped the 5 s limit). ## Fix -TODO: required for fixed/partial +Both waits use a `CLOCK_MONOTONIC` deadline (`clitest_now_ms()`), and `clitest_pump_once()` naps 10 ms when `poll()` wakes with nothing to read, so a hung-up pty no longer spins. Test-harness only; `xce_test` is unchanged. ## 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: the load reproduction above is the RED (12/48 runs failing); GREEN after the fix: 0/48 and 0/48 in two further rounds of the same 16-way parallel load +- Suites: harness meson suite 7/7 OK (asan, src/build.jai) +- Live: n/a (test-harness timing; no product code changed) ## References - Related: none