Skip to content

Flaky on main: inherited_output_handle_cannot_block_control_completion races a 5s timeout and blocks merges #845

Description

Summary

start::tests::inherited_output_handle_cannot_block_control_completion is a new test with a race in it. It passes reliably enough to clear its own PR gate and then fails intermittently on main, where it is currently blocking unrelated PRs from merging.

Where it came from

Introduced by b9d08f4 -- "Refactor PLM to use the canonical Learning Mode analyzer" (#760), merged 2026-08-12T21:16:56Z. #760's own windows / x64 and windows / arm64 checks were both green at merge.

The first failure on main came 4h35m later. In the 60 Build runs on main before that (2026-07-30 onward) this test never failed.

Failures on main

All four are event=push, head_branch=main, and all four head SHAs are ancestors of main:

Run main commit Arch Merged PR whose post-merge run this was
31659025220 2d8bad3 x64 #834
31669523256 604ffee x64 #829
31725574986 40e4bc5 both #803
31738885552 1c11f25 arm64 #814

Every one of those four PRs was green on windows / x64 and windows / arm64 at merge time. Nothing failing was checked in -- the test is simply nondeterministic, so it wins the race on the PR run and loses it on the very next run of the same code.

#814 is a documentation-only PR, which is about as clear as it gets that the failure is independent of the change under test.

All four panic identically:

test start::tests::inherited_output_handle_cannot_block_control_completion ... FAILED
thread '...' panicked at host\plm\src\start.rs:600:14:
descendant PID should be retained in partial stdout

Root cause

The test spawns powershell.exe, which uses Start-Process to launch a detached grandchild inheriting stdout, then writes PID=$($p.Id). run_wpr_command is given a 5-second timeout. The test then parses PID= out of the partial stdout captured before the drain was abandoned:

let pid = message
    .split("PID=")
    .nth(1)
    ...
    .expect("descendant PID should be retained in partial stdout");   // start.rs:600

Within those 5 seconds PowerShell has to start, run Start-Process, write the marker, and have it reach the captured buffer. On a loaded runner PowerShell startup alone eats most of the budget; when it does not make it, .nth(1) is None and the .expect panics. Both failing jobs ended at roughly the timeout (5.92s x64, 5.12s arm64).

The test's actual assertions -- "output drain failed", may_have_changed_wpr_state, and control_elapsed < 15s -- are not what breaks. Only the PID parse is, and that exists so the test can clean up after itself.

Secondary defect: on the failure path the Stop-Process cleanup never runs, so each failure leaks a 60-second sleeping powershell process onto the runner.

Suggested fix

Poll for the PID= marker with a much larger ceiling instead of a fixed 5-second budget, and move the Stop-Process cleanup so it runs even when the parse fails.

Impact

Blocks merges repo-wide. It is currently the only thing keeping #836 red, and #836 touches no PLM files.

cc Richie Gomez (@richiemsft) (author of #760)

Metadata

Metadata

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions