msbuild icon indicating copy to clipboard operation
msbuild copied to clipboard

[Bug]: dotnet (ms)build deadlocks when run from other app with RedirectStandardOutput=true and process.WaitForExit(Async) used

Open MaceWindu opened this issue 1 year ago • 14 comments

Updated 17/08/24 with more details

Issue Description

We are trying to build some code by calling dotnet build from our software and faced with dotnet process hangs under some conditions.

Steps to Reproduce

Caller code

using System.Diagnostics;

internal class Program
{
	static async Task Main(string[] args)
	{
		var psi = new ProcessStartInfo("dotnet")
		{
			RedirectStandardOutput = true,
		};

		psi.ArgumentList.Add("build");
		psi.ArgumentList.Add(@"path_to_Project.csproj");
		psi.ArgumentList.Add("-c");
		psi.ArgumentList.Add("Debug");

		var process = Process.Start(psi) ?? throw new InvalidOperationException($"Failed to run 'dotnet build' process");

		// hangs here, because dotnet.exe process doesn't terminate
		await process.WaitForExitAsync(default);

		if (process.ExitCode != 0)
		{
			var errors = await process.StandardOutput.ReadToEndAsync(default);
			Console.WriteLine(errors);
		}
	}
}

test project: 1111111111111111111111111111111111111111111111111111111111111111111111.zip

Expected Behavior

dotnet process exits

Actual Behavior

Process locked awaiting something

Analysis

Application deadlocks when output, produced by build goes above some limit. If it doesn't for you - just copy-paste properties in test class to increase amount of errors which will increase amount of printed text.

To workaround issue read output stream immediately instead of waiting for application to exit:

var errors = new List<string>();
while (true)
{
	var line = await process.StandardOutput.ReadLineAsync(cancellationToken);
	if (line == null)
	{
		break;
	}
	errors.Add(line);
}

Threads stacks in build process:

Main Thread image Pump 1 image Pump 2 image Node image

Versions & Configurations

dotnet --info

.NET SDK:
 Version:           8.0.400
 Commit:            36fe6dda56
 Workload version:  8.0.400-manifests.56cd0383
 MSBuild version:   17.11.3+0c8610977

Runtime Environment:
 OS Name:     Windows
 OS Version:  10.0.19045
 OS Platform: Windows
 RID:         win-x64
 Base Path:   C:\Program Files\dotnet\sdk\8.0.400\

.NET workloads installed:
Configured to use loose manifests when installing new manifests.
 [aspire]
   Installation Source: VS 17.11.35208.52
   Manifest Version:    8.1.0/8.0.100
   Manifest Path:       C:\Program Files\dotnet\sdk-manifests\8.0.100\microsoft.net.sdk.aspire\8.1.0\WorkloadManifest.json
   Install Type:        FileBased


Host:
  Version:      8.0.8
  Architecture: x64
  Commit:       08338fcaa5

.NET SDKs installed:
  3.1.426 [C:\Program Files\dotnet\sdk]
  6.0.315 [C:\Program Files\dotnet\sdk]
  8.0.400 [C:\Program Files\dotnet\sdk]

.NET runtimes installed:
  Microsoft.AspNetCore.App 3.1.32 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 5.0.17 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 6.0.31 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 6.0.33 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 7.0.20 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 8.0.8 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 3.1.32 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 5.0.17 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 6.0.31 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 6.0.33 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 7.0.20 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 8.0.8 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.WindowsDesktop.App 3.1.32 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 5.0.17 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 6.0.33 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 7.0.20 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 8.0.8 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]

Other architectures found:
  arm64 [C:\Program Files\dotnet]
    registered at [HKLM\SOFTWARE\dotnet\Setup\InstalledVersions\arm64\InstallLocation]
  x86   [C:\Program Files (x86)\dotnet]
    registered at [HKLM\SOFTWARE\dotnet\Setup\InstalledVersions\x86\InstallLocation]

Environment variables:
  Not set

global.json file:
  Not found

MaceWindu avatar Aug 16 '24 11:08 MaceWindu

Hmm, looks like we can use dotnet msbuild as workaround for now

MaceWindu avatar Aug 16 '24 12:08 MaceWindu

Can you also try using dotnet build with the '--tl:off' flag? That'll disable the MSBuild Terminal Logger, which is the default starting in .Net 9. 'dotnet msbuild' doesn't use it as the default, so that could be one reason why using it works.

baronfel avatar Aug 16 '24 13:08 baronfel

Nope, tried it already. Only tl:on works, but produce unreadable output due to control sequences

MaceWindu avatar Aug 16 '24 13:08 MaceWindu

~Actually looks like -consoleloggerparameters:Summary, which is used by dotnet build also breaks dotnet msbuild~

not working https://github.com/dotnet/msbuild/issues/10530#issuecomment-2293581921

MaceWindu avatar Aug 16 '24 13:08 MaceWindu

~Checked other values for consoleloggerparameters. Following also lead to hang:~

  • ~PerformanceSummary~
  • ~ShowCommandLine~

~Looks live it is not a blocker for us anymore with dotnet msbuild~

not working https://github.com/dotnet/msbuild/issues/10530#issuecomment-2293581921

MaceWindu avatar Aug 16 '24 13:08 MaceWindu

Thanks for the great research! That helps a lot.

Speaking personally I'd encourage folks to use dotnet build wherever possible instead of dotnet msbuild because build is a 'semantic' action that we can improve over time, whereas MSBuild is the generic, open-ended toolbox/escape hatch. Of course that doesn't work right now for you, but once this gets fixed I'd hope there wouldn't be other blockers to switching back for you.

baronfel avatar Aug 16 '24 13:08 baronfel

~Also as dotnet build pass parameters to msbuid, it is also possible to use -consoleloggerparameters:WarningsOnly;ErrorsOnly with it to make it work as another workaround.~

actually no, as Summary also respected, it still hangs. Just not in my test-case

MaceWindu avatar Aug 16 '24 13:08 MaceWindu

Tried to implement workaround in our code just to find out that it doesn't work. Issue reproduced with dotnet msbuild too with provided repro code - just need to copy-paste properties in test.cs to increase amount of errors. It looks like it depends on size of outputed logs somehow.

MaceWindu avatar Aug 16 '24 14:08 MaceWindu

Maybe same as #6753 ? (env vars workaround doesn't work for me)

MaceWindu avatar Aug 16 '24 14:08 MaceWindu

Out of ideas for workaround. Looks like I will need to use system-specific script to wrap dotnet call with redirect to file and then read file 🥲

MaceWindu avatar Aug 16 '24 14:08 MaceWindu

Looks like this works:

was:

await process.WaitForExitAsync(cancellationToken);

workaround:

var errors = new List<string>();
while (true)
{
	var line = await process.StandardOutput.ReadLineAsync(cancellationToken);
	if (line == null)
	{
		break;
	}
	errors.Add(line);
}

MaceWindu avatar Aug 16 '24 15:08 MaceWindu

Updated issue report with proper analysis details

MaceWindu avatar Aug 17 '24 09:08 MaceWindu

Also could confirm that same issue applicable to Linux (used mcr.microsoft.com/dotnet/sdk:8.0 docker image). Only difference is that after existing loop below

while (true)
{
	var line = await process.StandardOutput.ReadLineAsync(cancellationToken);
	if (line == null)
	{
		break;
	}
	errors.Add(line);
}

process.HasExisted is false, so I need to use WaitForExitAsync to ensure process terminated. So final working code is:

var logs = new List<string>();
while (true)
{
    var line = await process.StandardOutput.ReadLineAsync(cancellationToken);
    if (line == null)
    {
        break;
    }
    logs.Add(line);
}

await process.WaitForExitAsync(cancellationToken);

MaceWindu avatar Aug 22 '24 14:08 MaceWindu

This is not an msbuild bug; try it with any program that generates that much output and you will get the exact same deadlock.

jhudsoncedaron avatar Oct 11 '24 14:10 jhudsoncedaron

Sorry, this issue wasn't added to the iteration and slipped our attention. As it was mentioned, we are not able to fix this issue :(

I would recommend to use MSBuild API instead of starting new dotnet process - https://learn.microsoft.com/en-us/visualstudio/msbuild/msbuild-api?view=vs-2022 (and please read also Find and use a version of MSBuild article in that case)

MichalPavlik avatar Oct 24 '24 14:10 MichalPavlik