Drain crashed testhost stderr without blocking a thread-pool thread - #16191
Drain crashed testhost stderr without blocking a thread-pool thread#16191Jakub Jareš (nohwnd) wants to merge 9 commits into
Conversation
RunTestsShouldThrowOnStackOverflowException is still flaky. When a testhost crashes, the "Stack overflow." line can reach ErrorDataReceived late under thread-pool starvation (many hosts running in parallel on CI). The exit handler shared one 500ms budget with the process-exit wait and then blocked a thread-pool thread on it, so it both ran low on time and competed for the very thread that delivers the output it was waiting for. The callstack got dropped and the abort message was truncated to just the process path. Decouple the stderr drain from the exit-wait budget, await the EOF signal instead of blocking it, and only spend the generous budget when the process exited abnormally. Clean exits keep a short grace period and the wait returns as soon as EOF arrives. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
There was a problem hiding this comment.
Pull request overview
This PR hardens ProcessHelper’s crash diagnostics by awaiting stderr EOF asynchronously (with separate clean-exit vs crash budgets) so late-delivered crash output like Stack overflow. isn’t truncated under thread-pool starvation.
Changes:
- Replace the stderr “drain” primitive with an async, non-thread-blocking
WaitForErrorStreamToDrainAsyncand use longer timeout on abnormal exit. - Update
ProcessHelper’s stderr EOF signal fromManualResetEventSlimtoTaskCompletionSource(withRunContinuationsAsynchronously). - Update
ProcessHelperTeststo cover the new async drain helper.
Reviewed changes
Copilot reviewed 2 out of 2 changed files in this pull request and generated 2 comments.
| File | Description |
|---|---|
src/Microsoft.TestPlatform.PlatformAbstractions/common/System/ProcessHelper.cs |
Await stderr EOF without blocking a thread-pool thread; use separate drain timeouts for clean vs crashed exits. |
test/vstest.console.UnitTests/ProcessHelperTests.cs |
Convert drain helper tests to async and validate bounded / no-op behavior. |
|
This is about tenth attempt at fixing this, so needs careful review, especially considering that the process needs to exit fast in IDE, especially where there is no crash. |
The generous stderr-drain budget is only meant for a genuine crash. When we kill a still-running test host on purpose - aborting or cleaning up a run from an IDE - it exits with a non-zero code that is indistinguishable from a crash, so it would wait the full crash budget. If a grandchild process (e.g. a browser driver) inherited the stderr handle and keeps the pipe open, EOF never arrives and the abort hangs for seconds. Record the processes we kill in TerminateProcess and treat their exit as an abort (short drain), not a crash. A process that exited on its own is never recorded, so a real crash still gets the generous budget needed to capture a late callstack. Added a unit test for the budget selection. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
The CancellationTokenSource that bounds the post-exit wait is created with a timeout, so it allocates a timer; dispose it via 'using' so we don't leak one per testhost exit when many hosts are spawned. The stderr-drain test had been reduced to the already-drained fast path, so it could not catch a regression where EOF arrives just after the exit handler starts waiting. Make EOF land ~150ms into the wait so the test exercises waiting for a late ErrorDataReceived delivery and returning promptly, and keep a separate fast-path test for the already-drained case. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
The late-EOF test from the previous commit signaled EOF from a Task.Run with a Task.Delay, neither taking a CancellationToken. That trips MSTEST0049, which is only a warning in Debug but an error in the Release build CI runs - so the Windows leg failed at compile and every test was skipped. That is why the build went red without a test actually failing. Rewrite it without a timed background task: start the wait, assert it is still in progress, then signal EOF and await it. That exercises the same "EOF lands after the wait has started" path, but deterministically - no sleep, no timing assertion that could itself flake - and without the analyzer-tripping Task.Run/Task.Delay. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
When the process overruns the 500ms exit budget on the non-Windows !NET path, the CancellationToken callback force-kills it. That kill was not recorded via MarkDeliberatelyTerminated, so the exit handler saw a non-zero exit, treated it as a crash, and waited the generous 5s stderr drain - the exact abort latency this change avoids. Mark it before the kill, mirroring TerminateProcess, so the drain uses the short budget. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
… returns promptly The already-drained case is the common one on a clean exit; short-circuit before allocating the CancellationTokenSource and Task.Delay timer. Also tighten the late-EOF test so it fails if the wait ever ignored EOF and ran to the full timeout. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Bring in the agent workflow authentication fix so PR checks can activate. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> 🤖
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 2 out of 2 changed files in this pull request and generated no new comments.
Suppressed comments (1)
test/vstest.console.UnitTests/ProcessHelperTests.cs:82
- The bounded-wait test is currently too permissive: it would still pass even if the implementation waited far longer than the provided 500ms timeout (it only asserts < 5000ms) or returned much earlier than the intended timeout (it only asserts >= 150ms). Tightening these bounds makes the test actually validate the intended behavior and catch regressions.
Assert.IsGreaterThanOrEqualTo(
TerminateProcess checks HasExited and then calls Kill, and the process can crash on its own in between. The kill then never lands, on .NET it silently does nothing and on .NET Framework it throws, but we had already recorded the process as deliberately terminated, so the exit handler gave a real crash the 500 ms abort drain instead of the 5s crash drain, and could truncate the callstack that drain exists to capture. The request is still recorded before the kill, so the exit handler cannot miss it, but recording it no longer shortens the drain on its own. The exit counts as ours only when the exit code is the one Kill leaves behind, -1 on Windows and 128 + SIGKILL on Unix. A process that crashed in that window keeps its own exit code and so keeps the generous budget, and an exit code we cannot read is treated the same way. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 2 out of 2 changed files in this pull request and generated no new comments.
Suppressed comments (2)
src/Microsoft.TestPlatform.PlatformAbstractions/common/System/ProcessHelper.cs:203
new CancellationTokenSource(processExitTimeout)allocates a timer even on the!NET+ Windows path, where the token isn’t used (Windows usesWaitForExit(processExitTimeout)instead). On CI with many testhosts, this adds avoidable per-exit timer allocations; consider allocating the timed CTS only in the#if NETand Unix!NETbranches (or using an untimed CTS +CancelAfteronly where needed).
// behavior using the parameterless 'WaitForExit()' combined with an awaited Task.Run call.
// 'using' so the timer the timeout allocates is released as soon as we are done waiting,
// instead of leaking one per process exit when many test hosts are spawned.
using var cts = new CancellationTokenSource(processExitTimeout);
#if NET
test/vstest.console.UnitTests/ProcessHelperTests.cs:85
- The lower-bound assertion is too lax compared to the stated intent (“wait roughly the timeout”). With
BudgetMs = 500, allowing completion after only 150ms could let regressions slip through where the method returns significantly earlier than the requested timeout when EOF never arrives.
Assert.IsGreaterThanOrEqualTo(
150L,
stopwatch.ElapsedMilliseconds,
$"The method should wait roughly the timeout for the stream (waited only {stopwatch.ElapsedMilliseconds} ms).");
…codes The previous commit decided whether an exit was our own kill by checking the exit code Process.Kill() leaves behind. That does not hold up: - Both DefaultTestHostManager.CleanTestHostAsync and DotnetTestHostManager.CleanTestHostAsync call TerminateProcess and then dispose the Process immediately. After Dispose, HasExited and ExitCode throw InvalidOperationException, so the exit code came back null and the exit was treated as a crash - the 5s budget, on the abort path. - The budget was picked once, when the process exited. An abort arriving while a crash drain was already running could not shorten it. - A testhost that exits abnormally on its own while a grandchild (the Edge Driver case the surrounding code already describes) holds the stderr pipe was never covered by the kill tracking at all, so it went from 500ms to 5s. Replace it with a per-process cancellation signal. TerminateProcess signals it before killing, and also when the process has already exited, so a drain that is in flight is cut short too. Three budgets now: 5s for a crash, 500ms for a clean exit, 100ms once we are tearing down - short, but not zero, because output already sitting in the pipe costs nothing to pick up. Measured against a child whose grandchild holds the stderr pipe open, on the delay that TestRequestSender.GetAbortErrorMessage waits out: abort while the crash drain is in flight 5158ms -> 313ms kill a running process 1176ms -> 624ms crash with a late callstack 3192ms -> 3348ms, callstack still captured Also signal EOF after the last ErrorDataReceived callback rather than before it, and correct the comment about WaitForExitAsync - it does wait for the redirected streams to reach EOF, just only for as long as its token allows. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> 🤖
RunTestsShouldThrowOnStackOverflowExceptionis still flaky, even after #16128. The abort message comes back as justProcess path: ...\testhost.exewith theStack overflow.line missing.When a testhost crashes, .NET writes
Stack overflow.to its stderr, and we collect that asynchronously throughErrorDataReceived. Under load - many test hosts running in parallel on CI, thread-pool starvation - that callback can fire noticeably late, after the process has already exited. #16128 added a wait for the stderr stream to reach EOF before reading it, but two things kept it flaky:ErrorDataReceivedcallback needs to deliver EOF.So under starvation the wait could starve out the thing it was waiting for, time out, and read an empty buffer - dropping the callstack and truncating the abort message.
This decouples the stderr drain from the exit-wait budget and awaits the EOF signal instead of blocking on it. The wait returns the instant EOF arrives, so a process that drains promptly costs almost nothing.
Budgets, and why a crash is the only generous one
A long budget is only right for a genuine crash. When we tear a testhost down on purpose - aborting or cleaning up a run from an IDE - and a grandchild process (e.g. a browser driver) holds the stderr pipe open, EOF never comes, and the abort would sit there for the whole budget. So there are three:
The teardown budget is short but not zero, because output already sitting in the pipe costs nothing to pick up, and dropping it would replace a real error with a blank one.
Teardown is an explicit per-process cancellation signal, raised by
TerminateProcessbefore it kills. Not an inference from the exit code, which does not hold up:DefaultTestHostManager.CleanTestHostAsyncandDotnetTestHostManager.CleanTestHostAsynccallTerminateProcessand then dispose theProcessimmediately. AfterDispose,HasExitedandExitCodethrowInvalidOperationException, so there is no exit code left to read on the very path the check exists for.Because the signal is a cancellation,
TerminateProcessalso raises it for a process that has already exited, which is what shortens an in-flight drain.Measurements
Against a child whose grandchild holds the stderr pipe open, measuring the delay that
TestRequestSender.GetAbortErrorMessagewaits out - which is what an abort in Visual Studio ends up waiting for:Also in here
ErrorDataReceivedcallback rather than before it, so anyone observing it is guaranteed to see the complete output.WaitForExitAsync. It does wait for the redirected streams to reach EOF, it just stops waiting as soon as its token is cancelled - which is why a separate, longer drain is still needed.usingon the exit-waitCancellationTokenSource, so its timer is released instead of leaking one per process exit.ProcessHelperTestscover the drain primitive (returns on EOF, stays bounded when EOF never comes, no-op when there is nothing to drain, cut short by a teardown signalled up front and by one that arrives mid-wait, and still capturing output that lands inside the teardown budget) and the budget selection. The race doesn't reproduce deterministically here, so the real proof is the CI flake rate.Not fixed here
Worth knowing, because it sits right next to this: when we do have to kill a testhost, the exit callback never runs at all.
CleanTestHostAsyncdisposes theProcessright afterTerminateProcess, andProcess.Dispose()unregisters the exit watcher - measured 0/20 with the immediate dispose, 20/20 without it. So_clientExitedis never set andGetAbortErrorMessagewaits out its full 10s. That is a bigger abort win than anything in this PR, but it is a separate change.🤖