Files reconcile-storm gate panics when a completed JoinHandle is polled again

kayg commented

2026-10-06 18:35:44 +00:00

Owner

Observed while running the required full Files gate for #1153 after merging origin/dev ff53d7b8b. No Files source was changed by this job.

Command: CARGO_PROFILE_DEV_DEBUG=line-tables-only CARGO_INCREMENTAL=0 CARGO_BUILD_JOBS=4 TMPDIR=$PWD/target/tmp cargo test -p calternal-plugin-files -- --test-threads=4. Fixtures used local SSD.

Verbatim failure:

---- tests::internal_temp_paths_never_enter_index_during_atomic_write_reconcile_storm stdout ----
thread 'tests::internal_temp_paths_never_enter_index_during_atomic_write_reconcile_storm' panicked at tokio-1.53.1/src/runtime/task/core.rs:427:22:
JoinHandle polled after completion

test result: FAILED. 259 passed; 1 failed; 4 ignored; 0 measured; 0 filtered out; finished in 479.67s

This is a panic, not a SLOW-only finding. Keep the existing 1,000-write/four-scan checks and the five-minute bound; do not weaken assertions. Inspect the test's select/timeout and cleanup joins, which can poll a completed JoinHandle again. Production state correctness was not established by this failed test. #1153's full Files gate is not passing.

Observed while running the required full Files gate for #1153 after merging origin/dev ff53d7b8b. No Files source was changed by this job. Command: `CARGO_PROFILE_DEV_DEBUG=line-tables-only CARGO_INCREMENTAL=0 CARGO_BUILD_JOBS=4 TMPDIR=$PWD/target/tmp cargo test -p calternal-plugin-files -- --test-threads=4`. Fixtures used local SSD. Verbatim failure: ``` ---- tests::internal_temp_paths_never_enter_index_during_atomic_write_reconcile_storm stdout ---- thread 'tests::internal_temp_paths_never_enter_index_during_atomic_write_reconcile_storm' panicked at tokio-1.53.1/src/runtime/task/core.rs:427:22: JoinHandle polled after completion test result: FAILED. 259 passed; 1 failed; 4 ignored; 0 measured; 0 filtered out; finished in 479.67s ``` This is a panic, not a SLOW-only finding. Keep the existing 1,000-write/four-scan checks and the five-minute bound; do not weaken assertions. Inspect the test's select/timeout and cleanup joins, which can poll a completed JoinHandle again. Production state correctness was not established by this failed test. #1153's full Files gate is not passing.

kayg commented

2026-10-06 18:36:46 +00:00

Author

Owner

Source evidence: crates/plugins/files/src/lib.rs:8248–8261. On an unsuccessful completion, the cleanup loop includes &mut watcher, aborts it and awaits it if unfinished. The following unconditional watcher.abort(); let _ = watcher.await; polls that completed JoinHandle again. This explains the recorded Tokio panic and masks the original timeout/error. The job did not change this test or weaken its 1,000-write/four-scan/five-minute checks.

Source evidence: crates/plugins/files/src/lib.rs:8248–8261. On an unsuccessful completion, the cleanup loop includes `&mut watcher`, aborts it and awaits it if unfinished. The following unconditional `watcher.abort(); let _ = watcher.await;` polls that completed JoinHandle again. This explains the recorded Tokio panic and masks the original timeout/error. The job did not change this test or weaken its 1,000-write/four-scan/five-minute checks.

kayg referenced this issue

2026-10-06 18:36:47 +00:00

Hide any item (⋯ → Hide) with one reserved marker across the app #1153

kayg referenced this issue

2026-10-06 18:54:50 +00:00

Hide any item (⋯ → Hide) with one reserved marker across the app #1153

kayg commented

2026-10-06 19:56:39 +00:00

Author

Owner

Starting #1213 on branch job/fix-1213 at base ff53d7b8b4 (origin/dev).

Starting #1213 on branch job/fix-1213 at base ff53d7b8b4da5a21f862d57dcc3496f8c019f647 (origin/dev).

kayg commented

2026-10-06 19:59:03 +00:00

Author

Owner

Finding: in crates/plugins/files/src/lib.rs, the timeout/error cleanup loop can await the watcher handle, then the following shared path awaits it again. Tokio JoinHandle outputs can be consumed once. The production reconcile path has no corresponding handle-polling logic, so this is a test-harness issue. The focused baseline run is still compiling.

kayg commented

2026-10-06 21:00:06 +00:00

Author

Owner

Verification finding: focused loop runs 1–3 passed (110.49 s, 131.98 s and 225.44 s). Run 4 reached the preserved timeout and failed with Elapsed(()) after 327.86 s; the updated cleanup reported the five-minute timeout instead of repolling the watcher JoinHandle. This run was on the shared build host. I am keeping the existing timeout and continuing the requested repetitions.

Verification finding: focused loop runs 1–3 passed (110.49 s, 131.98 s and 225.44 s). Run 4 reached the preserved timeout and failed with `Elapsed(())` after 327.86 s; the updated cleanup reported the five-minute timeout instead of repolling the watcher JoinHandle. This run was on the shared build host. I am keeping the existing timeout and continuing the requested repetitions.

kayg commented

2026-10-06 22:15:52 +00:00

Author

Owner

Finished #1213.

Branch: job/fix-1213
Head: c7dfdc5e02bc0f911d72fb915a96f299e35dc7e9
Changed: crates/plugins/files/src/lib.rs
Fix: the timeout/error cleanup owns cancellation and joining of the watcher; the success path now joins it only when that cleanup did not run. This prevents polling a consumed Tokio JoinHandle twice. The 1,000 writes, four scans, assertions and five-minute bound are unchanged. No production code changed.

Gates:

cargo fmt --check: exit 0, no output.

cargo clippy -p calternal-plugin-files --all-targets -- -D warnings:

    Finished `dev` profile [unoptimized + debuginfo] target(s) in 4m 16s

cargo test -p calternal-plugin-files -- --test-threads=4:

test result: ok. 258 passed; 0 failed; 4 ignored; 0 measured; 0 filtered out; finished in 339.39s
test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s

Focused loop:
```
focused loop summary: 15 passed, 5 failed out of 20
```
The five failures reached the unchanged five-minute timeout and reported Elapsed(()); none reproduced the JoinHandle repoll panic. The loop did not establish 20/20 stability under this host load. The full crate suite, including the storm test, passed.
cargo clean: Removed 11129 files, 7.0GiB total.

Decision: keep the existing five-minute limit and make the failure cleanup path the sole owner of watcher cancellation/join. No DESIGN-level choice was needed. Known gap: five focused repetitions timed out under shared-host load.

Finished #1213. - Branch: `job/fix-1213` - Head: `c7dfdc5e02bc0f911d72fb915a96f299e35dc7e9` - Changed: `crates/plugins/files/src/lib.rs` - Fix: the timeout/error cleanup owns cancellation and joining of the watcher; the success path now joins it only when that cleanup did not run. This prevents polling a consumed Tokio JoinHandle twice. The 1,000 writes, four scans, assertions and five-minute bound are unchanged. No production code changed. Gates: - `cargo fmt --check`: exit 0, no output. - `cargo clippy -p calternal-plugin-files --all-targets -- -D warnings`: ``` Finished `dev` profile [unoptimized + debuginfo] target(s) in 4m 16s ``` - `cargo test -p calternal-plugin-files -- --test-threads=4`: ``` test result: ok. 258 passed; 0 failed; 4 ignored; 0 measured; 0 filtered out; finished in 339.39s test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s ``` - Focused loop: ``` focused loop summary: 15 passed, 5 failed out of 20 ``` The five failures reached the unchanged five-minute timeout and reported `Elapsed(())`; none reproduced the JoinHandle repoll panic. The loop did not establish 20/20 stability under this host load. The full crate suite, including the storm test, passed. - `cargo clean`: `Removed 11129 files, 7.0GiB total`. Decision: keep the existing five-minute limit and make the failure cleanup path the sole owner of watcher cancellation/join. No DESIGN-level choice was needed. Known gap: five focused repetitions timed out under shared-host load.

kayg commented

2026-10-06 22:16:42 +00:00

Author

Owner

Orchestrator: panic fixed (c7dfdc5e0, harness only), merging in round 32. Remaining: 5 of 20 focused runs hit the unchanged 5-minute bound on this loaded host (load ~30). That is a timing-only finding; bash-perf (#1224) should check whether the reconcile storm itself is slow under contention before anyone touches the bound.

Orchestrator: panic fixed (c7dfdc5e0, harness only), merging in round 32. Remaining: 5 of 20 focused runs hit the unchanged 5-minute bound on this loaded host (load ~30). That is a timing-only finding; bash-perf (#1224) should check whether the reconcile storm itself is slow under contention before anyone touches the bound.

kayg referenced this issue

2026-10-07 01:23:01 +00:00

Reliability round: probe the routes added 2026-10-05/06 on a real server #1202

kayg commented

2026-10-07 01:23:02 +00:00

Author

Owner

The required full Files gate on the #1202 continuation reached the unchanged reconcile-storm cleanup and panicked with JoinHandle polled after completion. The completed timeout cleanup already joins the watcher, then the unconditional cleanup polls it again. This is the existing #1213 runner defect; it is not the separate #1279 Journal fix.

The new Public privacy regression passed. Full gate output:

thread 'tests::internal_temp_paths_never_enter_index_during_atomic_write_reconcile_storm' (820486) panicked at /home/kayg/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.53.1/src/runtime/task/core.rs:427:22:
JoinHandle polled after completion

test result: FAILED. 260 passed; 1 failed; 4 ignored; 0 measured; 0 filtered out; finished in 370.28s

I am using one shared test-only abort/join helper for both cleanup paths, with a deterministic consumed-handle and repeated-cleanup regression. The 1,000 writes, four scans, Index/feed assertions and five-minute completion bound stay unchanged. The source behavior will not be changed to make this check pass. The underlying completion outcome will be reported after the focused rerun.

The required full Files gate on the #1202 continuation reached the unchanged reconcile-storm cleanup and panicked with `JoinHandle polled after completion`. The completed timeout cleanup already joins the watcher, then the unconditional cleanup polls it again. This is the existing #1213 runner defect; it is not the separate #1279 Journal fix. The new Public privacy regression passed. Full gate output: ``` thread 'tests::internal_temp_paths_never_enter_index_during_atomic_write_reconcile_storm' (820486) panicked at /home/kayg/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.53.1/src/runtime/task/core.rs:427:22: JoinHandle polled after completion test result: FAILED. 260 passed; 1 failed; 4 ignored; 0 measured; 0 filtered out; finished in 370.28s ``` I am using one shared test-only abort/join helper for both cleanup paths, with a deterministic consumed-handle and repeated-cleanup regression. The 1,000 writes, four scans, Index/feed assertions and five-minute completion bound stay unchanged. The source behavior will not be changed to make this check pass. The underlying completion outcome will be reported after the focused rerun.

kayg commented

2026-10-07 01:31:49 +00:00

Author

Owner

Head c8fe092c3de1b1f388ecb2c71ae307de0447eaaa. #1213 timeout cleanup now uses one shared test-only abort/join helper. It skips finished handles that the timed body may already have consumed. Both cleanup paths use it. Product behavior, 1,000 writes, four scans, Index/feed assertions and the five-minute bound are unchanged. Clippy with warnings denied passed.

test tests::storm_cleanup_does_not_poll_consumed_worker_handles_twice ... ok
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 265 filtered out; finished in 0.00s

test tests::internal_temp_paths_never_enter_index_during_atomic_write_reconcile_storm has been running for over 60 seconds
test tests::internal_temp_paths_never_enter_index_during_atomic_write_reconcile_storm ... ok
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 265 filtered out; finished in 132.34s

The initial full-suite failure is retained in #1202 and the evidence. No test expectation or deadline was changed. No issue is closed.

Head `c8fe092c3de1b1f388ecb2c71ae307de0447eaaa`. #1213 timeout cleanup now uses one shared test-only abort/join helper. It skips finished handles that the timed body may already have consumed. Both cleanup paths use it. Product behavior, 1,000 writes, four scans, Index/feed assertions and the five-minute bound are unchanged. Clippy with warnings denied passed. ``` test tests::storm_cleanup_does_not_poll_consumed_worker_handles_twice ... ok test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 265 filtered out; finished in 0.00s ``` ``` test tests::internal_temp_paths_never_enter_index_during_atomic_write_reconcile_storm has been running for over 60 seconds test tests::internal_temp_paths_never_enter_index_during_atomic_write_reconcile_storm ... ok test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 265 filtered out; finished in 132.34s ``` The initial full-suite failure is retained in #1202 and the evidence. No test expectation or deadline was changed. No issue is closed.

kayg referenced this issue

2026-10-07 01:35:01 +00:00

Reliability round: probe the routes added 2026-10-05/06 on a real server #1202

kayg referenced this issue

2026-10-07 01:35:21 +00:00

BLOCKER: Public hidden-name Markdown preview exposes real names in headers #1280

kayg referenced this issue from a commit

2026-10-07 05:01:28 +00:00

test(files): profile reconcile storm phases (#1213)

kayg referenced this issue

2026-10-07 05:42:20 +00:00

Bug bash: perf #1224

kayg referenced this issue from a commit

2026-10-07 05:47:25 +00:00

test(files): retain storm profile when timeout (#1213)

kayg commented

2026-10-07 06:04:26 +00:00

Author

Owner

The first perf-VM run reached the 300 s storm bound and exited after 310.80 s with JoinHandle polled after completion. The timeout cleanup awaited the watcher once in the worker loop and again unconditionally, which masked the intended timeout and prevented the partial profile from being printed. I changed the cleanup to cancel/join writer and scanner handles there, then stop/join the watcher exactly once. I am rebuilding and will make one bounded rerun; no existing assertion or timeout was changed.

The first perf-VM run reached the 300 s storm bound and exited after 310.80 s with `JoinHandle polled after completion`. The timeout cleanup awaited the watcher once in the worker loop and again unconditionally, which masked the intended timeout and prevented the partial profile from being printed. I changed the cleanup to cancel/join writer and scanner handles there, then stop/join the watcher exactly once. I am rebuilding and will make one bounded rerun; no existing assertion or timeout was changed.

kayg referenced this issue

2026-10-07 06:26:03 +00:00

PROCESS: browser smoke suite of real User flows over a throttled network (deploy gate) #1122

kayg commented

2026-10-07 06:49:23 +00:00

Author

Owner

Updated local profile on commit 5e87adf1a, after fixing the timeout cleanup to await the watcher once:

cargo test -p calternal-plugin-files: 260 passed; 0 failed; 4 ignored; 0 measured; finished in 214.01s.
Isolated profile: FILES_RECONCILE_STORM_PROFILE {"change_feed_rows":1001,"indexed_rows":1000,"journal_rows":1001,"scans_before_write_burst_ms":[20,11,5,4],"scans_during_write_burst_ms":[22,8,8,7],"total_test_ms":151654,"write_and_scan_ms":150962,"writes":1000}; the focused test passed in 151.67s.
Load around the local run: before 19.71 / 23.40 / 26.99, after 20.08 / 21.27 / 25.45. The perf VM could not be reacquired after the first run.

Inference: reconcile itself was not slow in this sample (all eight scans were 4–22 ms); atomic writes plus watcher adoption account for nearly all of the 151 s. The earlier perf-VM attempt used the HDD-emulated TMPDIR and exceeded 300 s, then exposed the double-await test panic; its measured load inside the perf lock was 0.61 / 0.26 / 0.40. The updated cleanup now prints timings on the timeout path too.

Updated local profile on commit 5e87adf1a, after fixing the timeout cleanup to await the watcher once: - `cargo test -p calternal-plugin-files`: `260 passed; 0 failed; 4 ignored; 0 measured; finished in 214.01s`. - Isolated profile: `FILES_RECONCILE_STORM_PROFILE {"change_feed_rows":1001,"indexed_rows":1000,"journal_rows":1001,"scans_before_write_burst_ms":[20,11,5,4],"scans_during_write_burst_ms":[22,8,8,7],"total_test_ms":151654,"write_and_scan_ms":150962,"writes":1000}`; the focused test passed in 151.67s. - Load around the local run: before 19.71 / 23.40 / 26.99, after 20.08 / 21.27 / 25.45. The perf VM could not be reacquired after the first run. Inference: reconcile itself was not slow in this sample (all eight scans were 4–22 ms); atomic writes plus watcher adoption account for nearly all of the 151 s. The earlier perf-VM attempt used the HDD-emulated TMPDIR and exceeded 300 s, then exposed the double-await test panic; its measured load inside the perf lock was 0.61 / 0.26 / 0.40. The updated cleanup now prints timings on the timeout path too.

kayg referenced this issue

2026-10-07 06:49:25 +00:00

Bug bash: perf #1224

kayg referenced this issue from a commit

2026-10-07 06:55:59 +00:00

test(files): await storm watcher only once (#1213)

kayg referenced this issue

2026-10-07 07:32:15 +00:00

Bug bash: perf #1224

kayg referenced this issue

2026-10-07 19:03:01 +00:00

Bug bash: security #1223