A crash in evaluator causes MSBuild to fail the build with 0 errors 0 warnings

[KirillOsenkov]

We should harden MSBuild against crashes in various places to ensure that we get a decent behavior and report the original stack.

A sample exception I'm seeing here causes these symptoms:

Path.CheckInvalidPathChars Line 1394
Path.Combine Line 1204
FileUtilities.GetFullPath Line 667
LazyItemEvaluator`4.LazyItemList.ProcessNonWildCardItemUpdates Line 431
LazyItemEvaluator`4.LazyItemList.ComputeItems Line 402
LazyItemEvaluator`4.LazyItemList.GetItemData Line 290
LazyItemEvaluator`4.<>c.<GetAllItemsDeferred>b__26_0 Line 489
Enumerable.<SelectManyIterator>d__17`2.MoveNext
Buffer`1..ctor
OrderedEnumerable`1.<GetEnumerator>d__1.MoveNext
Evaluator`4.Evaluate Line 665
Evaluator`4.Evaluate Line 320
ProjectInstance.Initialize Line 2752
ProjectInstance..ctor Line 484
BuildRequestConfiguration.<>c__DisplayClass61_0.<LoadProjectIntoConfiguration>b__0 Line 474
BuildRequestConfiguration.InitializeProject Line 500
BuildRequestConfiguration.LoadProjectIntoConfiguration Line 433
RequestBuilder.<BuildProject>d__67.MoveNext Line 1118
AsyncTaskMethodBuilder`1.Start Line 472
RequestBuilder.BuildProject
RequestBuilder.<BuildAndReport>d__58.MoveNext Line 812
AsyncTaskMethodBuilder.Start Line 317
RequestBuilder.BuildAndReport
RequestBuilder.<RequestThreadProc>d__57.MoveNext Line 777
AsyncTaskMethodBuilder.Start Line 317
RequestBuilder.RequestThreadProc
RequestBuilder.<StartBuilderThread>b__52_2 Line 702
Task`1.InnerInvoke Line 680
Task.Execute Line 2499
Task.ExecutionContextCallback Line 2861
ExecutionContext.RunInternal Line 981
ExecutionContext.Run Line 928
Task.ExecuteWithThreadLocal Line 2827
Task.ExecuteEntry Line 2757
TaskScheduler.TryExecuteTask Line 458
RequestBuilder.DedicatedThreadsTaskScheduler.<InjectThread>b__6_0 Line 1411
ThreadHelper.ThreadStart_Context Line 69
ExecutionContext.RunInternal Line 981
ExecutionContext.Run Line 928
ExecutionContext.Run Line 917
ThreadHelper.ThreadStart Line 106

In the Path.Combine, the first argument is:
C:\A\src\Shims
and the second one is:
\Users\kirill\AppData\Local\Microsoft\A\Temp\WebTooling\Schemas\JSON\Catalog\https

Throwing this ArgumentException from this location causes the problem:

msbuild/src/Build/Evaluation/LazyItemEvaluator.cs

Line 431 in d07c47a

if (itemsWithNoWildcards.TryGetValue(FileUtilities.GetFullPath(items[i].Item.EvaluatedInclude, items[i].Item.ProjectDirectory), out UpdateOperation op))

[KirillOsenkov]

The exception occurred as part of this scenario:
#6459

[KirillOsenkov]

itemsWithNoWildcards has two items, items has 1.5 million items (which are all the files on my drive)

[KirillOsenkov]

Hmm, I happened to have a file with this name in that location:

Directory:
\Users\kirill\AppData\Local\Microsoft\A\Temp\WebTooling\Schemas\JSON\Catalog\https
file:
https%003A%002F%002Fgo.microsoft.com%002Ffwlink%002F%003Flinkid%003D835884

This causes the ArgumentException in Path.Combine.

[KirillOsenkov]

No, the debugger was lying to me, the path that we're checking for null contains a zero char??

[KirillOsenkov]

OK, I have a minimal repro:

Paste this into 1.csproj:

<Project>

  <ItemGroup>
    <File Include="*" />
    <File Update="a" />
  </ItemGroup>

</Project>

In the same directory, create a file with the name %00. And build.

[KirillOsenkov]

Hmm, but this small repro does print the full exception call stack:

Build FAILED.
    0 Warning(s)
    0 Error(s)

Time Elapsed 00:00:00.02
MSBUILD : error MSB1025: An internal failure occurred while running MSBuild.
System.ArgumentException: Illegal characters in path.
   at System.IO.Path.CheckInvalidPathChars(String path, Boolean checkAdditional)
   at System.IO.Path.Combine(String path1, String path2)
   at Microsoft.Build.Shared.FileUtilities.GetFullPath(String fileSpec, String currentDirectory)
   at Microsoft.Build.Evaluation.LazyItemEvaluator`4.LazyItemList.ProcessNonWildCardItemUpdates(Dictionary`2 itemsWithNoWildcards, Builder items)
   at Microsoft.Build.Evaluation.LazyItemEvaluator`4.LazyItemList.ComputeItems(LazyItemList lazyItemList, ImmutableHashSet`1 globsToIgnore)
   at Microsoft.Build.Evaluation.LazyItemEvaluator`4.LazyItemList.GetItemData(ImmutableHashSet`1 globsToIgnore)
   at Microsoft.Build.Evaluation.LazyItemEvaluator`4.<>c.<GetAllItemsDeferred>b__26_0(LazyItemList itemList)
   at System.Linq.Enumerable.<SelectManyIterator>d__17`2.MoveNext()
   at System.Linq.Buffer`1..ctor(IEnumerable`1 source)
   at System.Linq.OrderedEnumerable`1.<GetEnumerator>d__1.MoveNext()
   at Microsoft.Build.Evaluation.Evaluator`4.Evaluate()

[KirillOsenkov]

Maybe there won't be an exception if this happens in a worker node??

[KirillOsenkov]

Basically having files with %00 on my drive, and then globbing all files from my drive resulted in this. Not how I wanted to spend my Sunday, but I'm happy I found a couple obscure issues!

[KirillOsenkov]

HAH!!!! I got it!

RequestBuilder catch block has a hole here for non-fatal exceptions:

msbuild/src/Build/BackEnd/Components/RequestBuilder/RequestBuilder.cs

Line 841 in d07c47a

if (ExceptionHandling.IsCriticalException(ex))

Modify the previous repro to use this project instead:

<Project>

  <ItemGroup Condition="$(IsInner) == true">
    <File Include="*" />
    <File Update="a" />
  </ItemGroup>

  <Target Name="Build">
    <MSBuild Projects="$(MSBuildThisFileFullPath)" Targets="Inner" Properties="IsInner=true"/>
  </Target>

  <Target Name="Inner">
  </Target>

</Project>

[KirillOsenkov]

Output:

C:\Temp>msbuild 1.proj
Microsoft (R) Build Engine version 16.9.0+5e4b48a27 for .NET Framework
Copyright (C) Microsoft Corporation. All rights reserved.

Build started 5/16/2021 9:28:00 PM.

Build FAILED.
    0 Warning(s)
    0 Error(s)

Time Elapsed 00:00:00.07

[KirillOsenkov]

Well, that was Sunday well spent, even if I say so myself.

[Forgind]

So we could add a very specific exception for if it finds an invalid path character, but I highly doubt that's the only way "build failed 0 warnings 0 errors" could come about in Evaluator. Finding all the possible sources of error would be a huge task. A relatively easy fix that would at least get the user a stack to try to identify what went wrong is if we wrapped all of Evaluate in a try/catch and logged a fairly generic error with a stack immediately rather than letting it bubble up to BuildAndReport, which clearly has no idea what to do. Does that sound good enough?

[KirillOsenkov]

I recommend you turn on first-chance exceptions in the debugger and step through building this project:
#6460 (comment)

You will see that the first catch block is here:

msbuild/src/Build/BackEnd/Components/RequestBuilder/RequestBuilder.cs

Line 1107 in 09bdfae

catch

The second catch block is here:

msbuild/src/Build/BackEnd/Components/RequestBuilder/RequestBuilder.cs

Line 823 in 09bdfae

catch (Exception ex)

The problem is that this second catch block is effectively throwing away all non-critical exceptions.

I don't care about this specific exception (invalid char). This is just a convenient representative of a class of exceptions in the build that will go unnoticed when they happen. As you correctly point out, there could be a plethora of these. We need to harden against all potential exceptions that bubble up to here - if an exception bubbles up to here, it's a bug in the engine.

I think that this catch block needs to do three things:

1. ensure the full stack of the exception is logged (by logging an error I presume)
2. fail the entire build (I think the finally block does that already)
3. the error should probably include a prompt to open an issue at https://github.com/dotnet/msbuild/issues/new

try/catch around the Evaluator is probably not the right thing because if there's an exception like this one, we probably don't want to continue the build.

In addition to all that hardening, we need to fix this particular case at the source - this needs to happen here:

msbuild/src/Build/Evaluation/LazyItemEvaluator.cs

Line 453 in 09bdfae

if (itemsWithNoWildcards.TryGetValue(FileUtilities.GetFullPath(items[i].Item.EvaluatedInclude, items[i].Item.ProjectDirectory), out UpdateOperation op))

We should sanitize inputs before we call Path.Combine in FileUtilities.GetFullPath, since fileSpec is a string with a zero-char:

But it is vastly more important to harden the engine and safeguard against any non-critical exceptions, not just this one.

[KirillOsenkov]

I also meant to add that this line is too complicated and we need to extract several subexpressions:

msbuild/src/Build/Evaluation/LazyItemEvaluator.cs

Line 453 in 09bdfae

if (itemsWithNoWildcards.TryGetValue(FileUtilities.GetFullPath(items[i].Item.EvaluatedInclude, items[i].Item.ProjectDirectory), out UpdateOperation op))

[Forgind]

I was thinking of the try/catch throwing the exception after making it nicer, since then we could actually say it's an error in Evaluate rather than that there's some bug with MSBuild, and we aren't entirely sure. On the other hand, the second catch will still swallow it, as you said, so maybe that's best. We could also split the difference and throw an internal exception in RequestBuilder with a message from the thrown exception (i.e., "Error in Evaluate") if present.

[KirillOsenkov]

I’d rather have the raw original exception with full stack, don’t see much value in wrapping it. I would add a text before or after it saying: there was an exception in MSBuild, please file an issue. I believe we already do it elsewhere, need to find it.

[pps83]

Not sure how this is related, but this annoying file https%003A%002F%002Fgo.microsoft.com%002Ffwlink%002F%003Flinkid%003D835884 now started to show up in every VS project folder. This is the report on VS: https://developercommunity.visualstudio.com/t/JSON-Schema-being-written-to-solution-fo/10158717