NuGet static graph restore can cause subsequent builds to fail to expand globs in .NET SDK 6.0.100-preview6

[ViktorHofer]

Issue Description

CSC : error CS2001: Source file 'D:\repos\runtime\src\coreclr\System.Private.CoreLib\*.analyzerdata.x64' could not be found. [D:\repos\runtime\src\coreclr\System.Private.CoreLib\System.Private.CoreLib.csproj]
CSC : error CS2001: Source file 'D:\repos\runtime\src\coreclr\System.Private.CoreLib\*.analyzerdata.net6.0' could not be found. [D:\repos\runtime\src\coreclr\System.Private.CoreLib\System.Private.CoreLib.csproj]
CSC : error CS2001: Source file 'D:\repos\runtime\src\coreclr\System.Private.CoreLib\*.analyzerdata.netcoreapp' could not be found. [D:\repos\runtime\src\coreclr\System.Private.CoreLib\System.Private.CoreLib.csproj]

The globbing of items in msbuild isn't expanded. These files are passed to the compiler as AdditionalFiles items. This was originally reported by @stephentoub.

Steps to Reproduce

This should be easily reproducible by doing the same globbing as in the link below in a hello world app. Note that this seems to be dependent on the exact version of msbuild being used.

Expected Behavior

The items specified in https://github.com/dotnet/arcade/blob/28a6403ee97077256fcdc60f599f0ad9e38e3cfa/src/Microsoft.DotNet.CodeAnalysis/build/Microsoft.DotNet.CodeAnalysis.targets#L21-L25 should be expanded correctly. The wildcard should be expanded and not hardcoded as a literal *.

Actual Behavior

The wildcard globbing isn't expanded and the wildcard * is written literally.

Analysis

Versions & Configurations

MSBuild version = "17.0.0-preview-21317-11+c579afe9c"

Attach a binlog

Internal link for MSFT employees:
https://microsofteur-my.sharepoint.com/:u:/g/personal/vihofer_microsoft_com/EftKjjkbyK5JvpaijHLKfjABIeIYvPIfQk_fIslqqn-rQA?e=suROf8

[rainersigwald]

I don't repro in a simple project with the same MSBuild/SDK (or MSBuild.exe from my dogfood VS which is the same version):
msbuild6602.zip

My first thought is that this may be an instance of #406, but there's no recursion in the pattern and the paths aren't all that long. It could conceivably be a different exception causing the same symptom but I don't know what that would be.

The source as currently checked in doesn't have any interesting files or patterns: https://github.com/dotnet/runtime/tree/213600c17635bf25f812a6a7e6ab53d4fa875883/src/libraries/System.IO.Compression/src

cc @ladipro since this is maybe related to your glob change #6151.

[rainersigwald]

I have a local repro with SDK 6.0.100-preview.6.21321.7 and the dotnet/runtime repo as in the OP.

[rainersigwald]

Been looking at this this morning. It looks like there may be a race condition in persistent state in worker nodes somehow?

I can get into a state where it fails consistently, but I've also seen states where it consistently passes, for instance building with -m:1 and DOTNET_DO_NOT_USE_MSBUILDNOINPROCNODE=true.

Naturally those are the ones that are easier to debug, so I haven't chased down the problem yet.

[rainersigwald]

In the bad state, I see an entry in s_lazyWildCardExpansionRegexes: [*?]+.*(?<!proj)$.

That's causing this to return true

msbuild/src/Build/Utilities/EngineFileUtilities.cs

Lines 227 to 230 in bbeb701

	private static bool MatchesLazyWildcard(string fileSpec)
	{
	return _regexMatchCache.Value.GetOrAdd(fileSpec, file => s_lazyWildCardExpansionRegexes.Any(regex => regex.IsMatch(fileSpec)));
	}

which bubbles up to

msbuild/src/Build/Utilities/EngineFileUtilities.cs

Lines 136 to 141 in bbeb701

	if (!FilespecHasWildcards(filespecEscaped) ||
	FilespecMatchesLazyWildcard(filespecEscaped, forceEvaluateWildCards))
	{
	// Just return the original string.
	fileList = new string[] { returnEscaped ? filespecEscaped : EscapingUtilities.UnescapeAll(filespecEscaped) };
	}

I don't see any place where that could be written to other than here:

msbuild/src/Build/Utilities/EngineFileUtilities.cs

Lines 202 to 222 in bbeb701

	private static List<Regex> PopulateRegexFromEnvironment()
	{
	string wildCards = Environment.GetEnvironmentVariable("MsBuildSkipEagerWildCardEvaluationRegexes");
	if (string.IsNullOrEmpty(wildCards))
	{
	return new List<Regex>(0);
	}
	else
	{
	List<Regex> regexes = new List<Regex>();
	foreach (string regex in wildCards.Split(MSBuildConstants.SemicolonChar))
	{
	Regex item = new Regex(regex, RegexOptions.Compiled | RegexOptions.Singleline | RegexOptions.IgnoreCase);
	// trigger a match first?
	item.IsMatch("foo");
	regexes.Add(item);
	}
	return regexes;
	}
	}

But that env var doesn't seem to be set anywhere.

[rainersigwald]

I finally found dotnet.exe where it is explicitly set. These are two worker nodes launched from the same process:

AHA! State is leaking from NuGet setting this for restore:

https://github.com/NuGet/NuGet.Client/blob/b83566ec2369c4e9fd07e6f95d734dfe370a1e66/src/NuGet.Core/NuGet.Build.Tasks.Console/MSBuildFeatureFlags.cs#L76

https://github.com/NuGet/NuGet.Client/blob/b83566ec2369c4e9fd07e6f95d734dfe370a1e66/src/NuGet.Core/NuGet.Build.Tasks.Console/MSBuildFeatureFlags.cs#L16

cc @jeffkl, @nkolev92

I think this may be new behavior related to dotnet/sdk#18263 (cc @rokonec): before, NuGet's limit of 1 worker node would have been in-proc; now it's forced out by MSBUILDNOINPROCNODE.

https://github.com/NuGet/NuGet.Client/blob/b83566ec2369c4e9fd07e6f95d734dfe370a1e66/src/NuGet.Core/NuGet.Build.Tasks.Console/MSBuildStaticGraphRestore.cs#L872-L874

Long term, I think we should teach NuGet to unset MSBUILDNOINPROCNODE or at least set EnableNodeReuse=false.

This suggests a workaround: set the environment variable DOTNET_CLI_DO_NOT_USE_MSBUILDNOINPROCNODE=true, kill all dotnet.exe processes, and it should work ok.

[rainersigwald]

Other possible workarounds:

• Build with --no-restore
• Turn off graph restore

[jeffkl]

@rainersigwald Static graph restore happens entirely out of proc, how is it leaking over to builds?

[rainersigwald]

@jeffkl well, we made it more out of proc and now it's too out of proc :)

Before:

(MSBuild running restore) ---------------------------------------------(download)
    \- (NuGet helper process) -- static graph stuff -- build stuff -- exits /

after

(MSBuild running restore) ---------------------------------------------------------(download)
    \- (NuGet helper process) -- static graph stuff ----------------------------(exits) /
                                                     \- (MSBuild.exe) build stuff /-----(idle)

Where that third process (MSBuild.exe or dotnet.exe msbuild is the out-of-proc worker node created by the MSBuild API when called in the helper because MSBUILDNOINPROCNODE=1 was set, so it needed a worker node. Then on a subsequent build that node is reused, but that breaks stuff because it's in the MsBuildSkipEagerWildCardEvaluationRegexes state.

[jeffkl]

@rainersigwald so you're saying the out of proc evaluations launch a re-usable msbuild.exe node now? Would that be a problem for any app that does evaluations and creates polluted instances?

[rainersigwald]

It's not the evaluations that are spawning the node but the target executions that collect the output.

[jeffkl]

So is the fix to set EnableNodeReuse to false on the BuildParameters?

https://source.dot.net/#Microsoft.Build/BackEnd/BuildManager/BuildParameters.cs,396

[rainersigwald]

Either that, or explicitly unset MSBUILDNOINPROCNODE from your environment in the EXE before loading MSBuild. Or both.

Just setting EnableNodeReuse will still cause a third child MSBuild process which isn't strictly necessary, and since the whole point is perf I'd unset the variable.

[jeffkl]

We don't set MSBUILDNOINPROCNODE in static graph restore, is that set because I'm setting maxNodeCount in the project collection to 1?

https://github.com/NuGet/NuGet.Client/blob/dev/src/NuGet.Core/NuGet.Build.Tasks.Console/MSBuildStaticGraphRestore.cs#L874

[rainersigwald]

No, it's being set by the CLI because it's been observed to improve performance: dotnet/sdk#17916.

We should consider changing that mechanism so it's less "infectious", like promoting it to a command-line argument or doing it at the API level somehow. @rokonec thoughts/feelings/preferences?

[rainersigwald]

(I still think NuGet should make itself robust to the situation since a user might have set it in some rare circumstances.)

[ladipro]

We should consider changing that mechanism so it's less "infectious", like promoting it to a command-line argument or doing it at the API level somehow

A low-cost fix may be to do this via a different environment variable that MSBuild unsets after reading. Or even just unset MSBUILDNOINPROCNODE on startup after reading if we feel adventurous.

[ladipro]

I would also argue that MsBuildSkipEagerWildCardEvaluationRegexes ranks higher on the hack-o-meter than MSBUILDNOINPROCNODE so if it's used in a prod scenario, we should think about making it a command-line argument or API as well.

[alexrp]

FWIW, I think I'm running into this issue in some variation fairly often in my zig-msbuild-sdk project. dotnet build in the repository root and then dotnet build in src/samples reproduces it fairly often, leading to a BadPathName error from the Zig compiler.

[rainersigwald]

@alexrp What .NET SDK version are you using? The condition that caused this error shouldn't have ever shipped in a formal preview, just the daily builds for a while.

(The underlying bugs are there but shouldn't have bitten anyone until various things combined.)

[alexrp]

$ dotnet --info
.NET SDK (reflecting any global.json):
 Version:   6.0.100-preview.6.21355.2
 Commit:    7f8e0d76c0

Runtime Environment:
 OS Name:     Windows
 OS Version:  10.0.22000
 OS Platform: Windows
 RID:         win10-x64
 Base Path:   C:\Program Files\dotnet\sdk\6.0.100-preview.6.21355.2\

Host (useful for support):
  Version: 6.0.0-preview.6.21352.12
  Commit:  770d630b28

.NET SDKs installed:
  2.1.815 [C:\Program Files\dotnet\sdk]
  3.0.100 [C:\Program Files\dotnet\sdk]
  3.1.201 [C:\Program Files\dotnet\sdk]
  3.1.202 [C:\Program Files\dotnet\sdk]
  3.1.411 [C:\Program Files\dotnet\sdk]
  5.0.100-rc.1.20452.10 [C:\Program Files\dotnet\sdk]
  5.0.100 [C:\Program Files\dotnet\sdk]
  5.0.102 [C:\Program Files\dotnet\sdk]
  5.0.202 [C:\Program Files\dotnet\sdk]
  5.0.301 [C:\Program Files\dotnet\sdk]
  5.0.302 [C:\Program Files\dotnet\sdk]
  6.0.100-preview.6.21355.2 [C:\Program Files\dotnet\sdk]

.NET runtimes installed:
  Microsoft.AspNetCore.All 2.1.13 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.27 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.All 2.1.28 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.All]
  Microsoft.AspNetCore.App 2.1.13 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.27 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 2.1.28 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.0.0 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.1.2 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.1.3 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.1.4 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.1.14 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.1.16 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 3.1.17 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 5.0.0-rc.1.20451.17 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 5.0.0 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 5.0.2 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 5.0.5 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 5.0.7 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 5.0.8 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 6.0.0-preview.6.21355.2 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 2.1.13 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.27 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 2.1.28 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.0.0 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.1.2 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.1.3 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.1.4 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.1.14 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.1.16 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 3.1.17 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 5.0.0-rc.1.20451.14 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 5.0.0 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 5.0.2 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 5.0.5 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 5.0.7 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 5.0.8 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 6.0.0-preview.6.21352.12 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.WindowsDesktop.App 3.0.0 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 3.1.2 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 3.1.3 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 3.1.4 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 3.1.14 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 3.1.16 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 3.1.17 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 5.0.0-rc.1.20452.2 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 5.0.0 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 5.0.2 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 5.0.5 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 5.0.7 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 5.0.8 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 6.0.0-preview.6.21353.1 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]

To install additional .NET runtimes or SDKs:
  https://aka.ms/dotnet-download

[alexrp]

Here's an example:

**/*.cxx(1,1): error GB70915D9: unable to build C object: unable to build C object: BadPathName [C:\Users\alex\source\repos\zig-msbuild-sdk\src\samples\cxxexe\cxxexe.cxxproj]

The SDK is doing:

        <Compile Include="**/*.cxx"
                 Excludes="$(DefaultItemExcludes); $(DefaultExcludesInProjectFolder)"
                 Condition="'$(CompilerMode)' == 'Cxx'" />