`dotnet test` (MTP) hangs instead of failing when the test app never handshakes — macOS CI timeout

[dsplaisted]

Area: Area-dotnet test (MTP)
Type: Bug / Test Debt (flaky CI hang)
Severity: High — hangs a dotnet test run for 60+ min, times out the whole macOS CI leg (150-min cap)

Summary

On macOS CI, the SDK integration test
Microsoft.DotNet.Cli.Test.Tests.GivenDotnetTestRunsConsoleAppWithoutHandshake.RunConsoleAppDoesNothing_ShouldReturnCorrectExitCode
hangs for the full 60-minute blame-hang inactivity window. The test invokes the product
dotnet test (Microsoft.Testing.Platform / MTP) against a console app that does nothing and never
performs the MTP handshake. The product is supposed to detect the missing handshake and exit with a
failure code — instead dotnet test hangs indefinitely, so the test never returns.

This appears to be causing macOS helix jobs to time out. This is intermittent, or possibly specific to macOS x64.

Expected behavior

dotnet test against a console app that does not handshake with MTP should fail fast with a meaningful
error and return ExitCode.GenericFailure (this is exactly what the test asserts):

result.ExitCode.Should().Be(ExitCodes.GenericFailure,
    "dotnet test should fail with a meaningful error when run against console app without MTP handshake");

Actual behavior

dotnet test never returns. The child dotnet process(es) stay alive waiting for a handshake / exit
that never comes, so the xunit test method blocks in Process.WaitForExit, the test session goes idle,
and after 60 minutes the blame collector force-dumps and kills the process tree.

Evidence

PR / build: dotnet/sdk #54410 (codeflow [main] Source code updates from dotnet/dotnet), merged head
build 1447367, leg TestBuild: macOS (x64).
Helix job: c2dccf78-b122-463c-908a-c4055562985b (queue osx.15.amd64.open).
Helix summary: 205 passed, 0 real failures, 16 work items killed at job cancellation (exit -4),
2 still running. The 16 -4 items are collateral from the job timeout, not genuine failures.

Affected dotnet.Tests work items (all hung, all produced hang dumps):

Work item	Hung test	Elapsed before dump
dotnet.Tests.dll.19	GivenDotnetTestBuildsAndRunsTests.RunOnProjectWithClassLibrary_ShouldReturnExitCodeSuccess	1h 02m+
dotnet.Tests.dll.20	GivenDotnetTestBuildsAndRunsTestsForMultipleTFMs.RunProjectWithMultipleTFMs_ParallelizationTest_RunInParallelShouldFail	1h 21m
dotnet.Tests.dll.21	GivenDotnetTestRunsConsoleAppWithoutHandshake.RunConsoleAppDoesNothing_ShouldReturnCorrectExitCode	1h 22m

Timeline (work item .21, from dotnetTestLog.host.*.log and dotnetTestLog.datacollector.*.log):

06:39:16.343  RecordStart: GivenDotnetTestRunsConsoleAppWithoutHandshake.RunConsoleAppDoesNothing_ShouldReturnCorrectExitCode
06:39:16.352  [OUTPUT] Executing 'dotnet test -c Release':            ← test spawns child `dotnet test`
06:39:16.xxx  (immediately prior test `MTPHelpSnapshotTests.VerifyMTPHelpOutput` ran `dotnet test --help` and PASSED in 9s — harness healthy)
06:39:49.954  [Long Running Test] ... Elapsed: 00:00:33               ← already flagged long-running
   ‹total silence — no test activity for a full hour›
07:39:16.590  "The specified inactivity time of 60 minutes has elapsed. Collecting hang dumps from testhost and its child processes"
07:39:16.xxx  Process tree dumped:  dotnet.Tests (testhost) + 2 live child `dotnet` processes
07:42:03      collector kills testhost + both child `dotnet` processes

Blame config in effect: <CollectDumpOnTestSessionHang TestTimeout="60m" HangDumpType="Full" />.

The fact that two child dotnet processes were still alive and had to be killed confirms the child
dotnet test orchestrator (and the spawned no-op app) never exited — dotnet test sat waiting for a
handshake/exit indefinitely.

Test source: test/dotnet.Tests/CommandTests/Test/GivenDotnetTestRunsConsoleAppWithoutHandshake.cs:19
Test asset: ConsoleAppDoesNothing

Hang dumps are available but would need to be analyzed on a MacOS machine.

Repro artifacts

• Helix job: c2dccf78-b122-463c-908a-c4055562985b
• Work items: dotnet.Tests.dll.19, dotnet.Tests.dll.20, dotnet.Tests.dll.21
• Files per work item: *_hangdump.dmp (Mach-O), dotnetTestLog.host.*.log,
  dotnetTestLog.datacollector.*.log, dotnetTestLog.log, *-msbuild-dotnet-test.binlog

/cc @dotnet/dotnet-testing-admin @Youssef1313

[Youssef1313]

Are the dumps for this available?

[Evangelink]

Note

Comment posted by GitHub Copilot acting under @Evangelink''s account. The analysis below is mine; @Evangelink has not personally validated each step.

Summary

After tracing the MTP code paths, downloading the host/datacollector/console logs for Helix job c2dccf78-b122-463c-908a-c4055562985b, and walking the process tree at hang time, my best-supported hypothesis is that this is not an MTP code regression. It looks like an early-startup hang inside dotnet test (most likely MSBuild evaluation or NuGet restore) caused by transient state on the macOS x64 Helix agent. Evidence below.

Evidence

1. The hung dotnet test child produced zero output for the entire 60-minute window

In dotnetTestLog.host....log I grep''d for the work-item .21 test name. There are exactly 12 matching lines:

• the harness Executing ''dotnet test -c Release'': line at 06:39:16.352
• ten [createdump] lines starting at 07:39:16.671 (i.e. immediately after the blame collector tripped at 60 minutes)

No banner, no Running tests from ..., no Test run summary, no handshake-failure recap, no MSBuild output. With -verbosity:quiet (which BuildOrRestoreProjectOrSolution sets), MSBuild only prints errors, so a silent hang during restore/build would look exactly like this.

That rules out hangs in any code path downstream of MicrosoftTestingPlatformTestCommand.Run''s output.TestExecutionStarted(...) (which is what would have produced the first observable banner). The hang must be earlier — i.e. in MSBuildHandler.Initialize → MSBuildUtility.GetProjectsFromProject → BuildOrRestoreProjectOrSolution → in-process MSBuildApp.Main, or even before that.

2. The process tree at hang time has no children of the orchestrator

From dotnetTestLog.datacollector....log line 118-121:

NetClientHangDumper.Dump: Dumping this process tree (from bottom):
 >  63612 - dotnet            (testhost root)
 + - 63620 - dotnet.Tests     (xunit test runner, apphosted)
 + -- 63632 - dotnet          (the `dotnet test -c Release` orchestrator)

63632 has no children. That means:

• the ConsoleAppDoesNothing test asset was never spawned as a child, and
• in-process MSBuild had not yet spawned a worker node for parallel build either.

(MSBuild runs in-process inside the orchestrator by default, via Build.CommandLine.MSBuildApp.Main(arguments) in MSBuildForwardingAppWithoutLogging.ExecuteInProc. So a silent hang inside in-process MSBuild evaluation/restore would look exactly like this: no child processes, no output.)

3. Three unrelated tests hung in the same job

The same Helix job had three completely different tests hang in three separate work items:

• RunOnProjectWithClassLibrary_ShouldReturnExitCodeSuccess (.19)
• RunProjectWithMultipleTFMs_ParallelizationTest_RunInParallelShouldFail (.20)
• RunConsoleAppDoesNothing_ShouldReturnCorrectExitCode (.21)

Different scenarios, different test assets, different command lines, same job, same macOS x64 queue (osx.15.amd64.open). That pattern is much more consistent with an environmental issue on the agent (NuGet feed lockup, file-system / quarantine lock, transient macOS dyld issue, etc.) than with a code regression that would be specific to one scenario.

4. About the "two child dotnet processes were still alive" note

The original report mentions two child dotnet processes. From the dump log I think those are 63612 (testhost root) + 63632 (the dotnet test orchestrator) — both named dotnet. The xunit test runner 63620 (apphosted as dotnet.Tests) sits between them. There is only one true dotnet test child here (63632), and it has no children, which is the key observation.

Why no fast-fail / retry kicked in

• xUnit theory has no Timeout set on these tests.
• TestCommand.Execute has ExecuteWithRetry with SuccessOrNotTransientRestoreError, but that only retries on non-zero exit. A hang never exits, so retry never kicks in.
• The blame collector''s 60-minute inactivity timer is the only safety net — and 60 minutes per work item per CI hang is expensive.

What I''ve pushed for hypothesis validation

Draft PR #54585 adds -bl to the three observed-hung dotnet test invocations. TestCommand.Execute already uploads any *.binlog it finds in the working directory to HELIX_WORKITEM_UPLOAD_ROOT, so when the blame collector kills the hung process, MSBuild''s BinaryLogger (which flushes periodically) will leave a partial-but-actionable binlog identifying which target / task was stuck. That should let us confirm or refute "early MSBuild evaluation / restore" as the hang location next time it reproduces.

Open questions / what I''d look at next

1. Are NuGet packages required for these assets pre-warmed on the macOS x64 Helix images, or does each work item potentially do a cold restore from api.nuget.org? A network stall on first-time restore would match the symptom exactly.
2. Does anyone in dnceng have a record of macOS x64 Helix agents hanging similarly in other repos around that time window? If yes, this is almost certainly infrastructure.
3. The .dmp files captured by the blame collector are Mach-O. They''re hard to analyse cross-platform — anyone with a macOS box could open one in dotnet-dump analyze to confirm which target frame dotnet test was stuck on.

[Youssef1313]

I wonder if this could be the same as dotnet/runtime#128955 (we have been hitting strange hangs in aspnetcore due to it)

[Evangelink]

(Posted by GitHub Copilot acting under @Evangelink's account.)

Quick follow-up: I upgraded PR #54585 from passive (just adding -bl) to active. TestCommand now has an opt-in WithTimeout(TimeSpan) watchdog that Process.Kill(entireProcessTree: true)s the spawned child when exceeded. The 3 tests that hung in Helix job c2dccf78 now have a 5-minute timeout, so the next recurrence will fail fast (~5 min) with an actionable xUnit failure + whatever binlog MSBuild managed to write – instead of 60 min of silence followed by the blame createdump. Details in the PR.