Inconsistent copy of transitive assembly references with FastUpToDate build

[govert]

Visual Studio Version

17.9.2

Summary

With the build acceleration option, there are now two build behaviours in Visual Studio - normal MSBuild build and the FastUpToDate build. We have found a case where the FastUpToDate build would copy additional output files where a normal build would not. This happens when a referenced project has a further assembly reference. This extra assembly would not normally be copied to the output of the top level project, but under FastUpToDate there is an extra copy done.

Steps to Reproduce

1. Create a new C# Console App called ConsoleApp1 in a solution named TestFastUpToDate (with the solution and project not in the same directory), targeting .NET 8.0.
2. To the solution, add a new Class Library project called ClassLibrary1, targeting .NET 8.0.
3. To the solution, add another new Class Library called ClassLibrary2, targeting .NET 8.0.
4. Rebuild ClassLibrary2 (to ensure the output of ClassLibrary2 is created).
5. In ClassLibrary1.csproj, add an assembly reference to the output of ClassLibrary2. This adds a <Reference> item with its HintPath.

  <ItemGroup>
    <Reference Include="ClassLibrary2">   <HintPath>..\ClassLibrary2\bin\Debug\net8.0\ClassLibrary2.dll</HintPath>
    </Reference>
  </ItemGroup>

6. In ConsoleApp1, add a project reference to ClassLibrary1.

  <ItemGroup>
    <ProjectReference Include="..\ClassLibrary1\ClassLibrary1.csproj" />
  </ItemGroup>

8. Note that we now have these three project files.

ClassLibrary1.csproj

<Project Sdk="Microsoft.NET.Sdk">

  <PropertyGroup>
    <TargetFramework>net8.0</TargetFramework>
    <ImplicitUsings>enable</ImplicitUsings>
    <Nullable>enable</Nullable>
  </PropertyGroup>

  <ItemGroup>
    <Reference Include="ClassLibrary2">
      <HintPath>..\ClassLibrary2\bin\Debug\net8.0\ClassLibrary2.dll</HintPath>
    </Reference>
  </ItemGroup>

</Project>

ClassLibrary2.csproj

<Project Sdk="Microsoft.NET.Sdk">

  <PropertyGroup>
    <TargetFramework>net8.0</TargetFramework>
    <ImplicitUsings>enable</ImplicitUsings>
    <Nullable>enable</Nullable>
  </PropertyGroup>

</Project>

ConsoleApp1.csproj

<Project Sdk="Microsoft.NET.Sdk">

  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFramework>net8.0</TargetFramework>
    <ImplicitUsings>enable</ImplicitUsings>
    <Nullable>enable</Nullable>
  </PropertyGroup>

  <ItemGroup>
    <ProjectReference Include="..\ClassLibrary1\ClassLibrary1.csproj" />
  </ItemGroup>

</Project>

9. We will now monitor the output directory of ConsoleApp1 (C:\Temp\TestFastUpToDate\ConsoleApp1\bin\Debug\net8.0 for my project) to see what files are placed there from the build.

Expected Behavior

Building or rebuilding the solution with the full build will behave the same way as a 'FastUpToDate' build.

Actual Behavior

A 'FastUpToDate' build copies an additional file to the output directory, which a rebuild or normal build does not copy.

This is the output from a normal build (Build -> Build Solution) when the output directory of ConsoleApp1 is empty:

Build started at 14:50...
1>FastUpToDate: Build acceleration is enabled for this project via a feature flag. See "Tools | Options | Environment | Preview Features" to control this setting. See https://aka.ms/vs-build-acceleration. (ClassLibrary2)
1>FastUpToDate: Comparing timestamps of inputs and outputs: (ClassLibrary2)
1>FastUpToDate:     No inputs are newer than earliest output 'C:\Temp\TestFastUpToDate\ClassLibrary2\obj\Debug\net8.0\ClassLibrary2.pdb' (2024-03-12 14:50:08.069). Newest input is 'C:\Temp\TestFastUpToDate\ClassLibrary2\obj\ClassLibrary2.csproj.nuget.g.targets' (2024-03-12 14:48:10.754). (ClassLibrary2)
1>FastUpToDate: Project is up-to-date. (ClassLibrary2)
2>FastUpToDate: Build acceleration is enabled for this project via a feature flag. See "Tools | Options | Environment | Preview Features" to control this setting. See https://aka.ms/vs-build-acceleration. (ClassLibrary1)
2>FastUpToDate: Comparing timestamps of inputs and outputs: (ClassLibrary1)
2>FastUpToDate:     No inputs are newer than earliest output 'C:\Temp\TestFastUpToDate\ClassLibrary1\obj\Debug\net8.0\ClassLibrary1.pdb' (2024-03-12 14:50:20.040). Newest input is 'C:\Temp\TestFastUpToDate\ClassLibrary2\bin\Debug\net8.0\ClassLibrary2.dll' (2024-03-12 14:50:08.070). (ClassLibrary1)
2>FastUpToDate: Project is up-to-date. (ClassLibrary1)
3>FastUpToDate: Build acceleration is enabled for this project via a feature flag. See "Tools | Options | Environment | Preview Features" to control this setting. See https://aka.ms/vs-build-acceleration. (ConsoleApp1)
3>FastUpToDate: Comparing timestamps of inputs and outputs: (ConsoleApp1)
3>FastUpToDate: Output 'C:\Temp\TestFastUpToDate\ConsoleApp1\bin\Debug\net8.0\ConsoleApp1.dll' does not exist, not up-to-date. (ConsoleApp1)
3>------ Build started: Project: ConsoleApp1, Configuration: Debug Any CPU ------
3>Build started 2024/03/12 14:50:52.
3>Target _GetProjectReferenceTargetFrameworkProperties:
3>Target ResolveProjectReferences:
3>Target GenerateTargetFrameworkMonikerAttribute:
3>  Skipping target "GenerateTargetFrameworkMonikerAttribute" because all output files are up-to-date with respect to the input files.
3>Target CoreGenerateAssemblyInfo:
3>  Skipping target "CoreGenerateAssemblyInfo" because all output files are up-to-date with respect to the input files.
3>Target _GenerateSourceLinkFile:
3>  Source Link is empty, file 'obj\Debug\net8.0\ConsoleApp1.sourcelink.json' does not exist.
3>Target CoreCompile:
3>  Skipping target "CoreCompile" because all output files are up-to-date with respect to the input files.
3>Target _CreateAppHost:
3>  Skipping target "_CreateAppHost" because all output files are up-to-date with respect to the input files.
3>Target _CopyFilesMarkedCopyLocal:
3>  Copying file from "C:\Temp\TestFastUpToDate\ClassLibrary1\bin\Debug\net8.0\ClassLibrary1.pdb" to "C:\Temp\TestFastUpToDate\ConsoleApp1\bin\Debug\net8.0\ClassLibrary1.pdb".
3>  Copying file from "C:\Temp\TestFastUpToDate\ClassLibrary1\bin\Debug\net8.0\ClassLibrary1.dll" to "C:\Temp\TestFastUpToDate\ConsoleApp1\bin\Debug\net8.0\ClassLibrary1.dll".
3>  Touching "C:\Temp\TestFastUpToDate\ConsoleApp1\obj\Debug\net8.0\ConsoleA.CB28C8CC.Up2Date".
3>Target GetCopyToOutputDirectoryItems:
3>  Target _GetCopyToOutputDirectoryItemsFromTransitiveProjectReferences:
3>Target _CopyOutOfDateSourceItemsToOutputDirectory:
3>  Copying file from "C:\Temp\TestFastUpToDate\ConsoleApp1\obj\Debug\net8.0\apphost.exe" to "C:\Temp\TestFastUpToDate\ConsoleApp1\bin\Debug\net8.0\ConsoleApp1.exe".
3>Target CopyFilesToOutputDirectory:
3>  Copying file from "C:\Temp\TestFastUpToDate\ConsoleApp1\obj\Debug\net8.0\ConsoleApp1.dll" to "C:\Temp\TestFastUpToDate\ConsoleApp1\bin\Debug\net8.0\ConsoleApp1.dll".
3>  ConsoleApp1 -> C:\Temp\TestFastUpToDate\ConsoleApp1\bin\Debug\net8.0\ConsoleApp1.dll
3>  Copying file from "C:\Temp\TestFastUpToDate\ConsoleApp1\obj\Debug\net8.0\ConsoleApp1.pdb" to "C:\Temp\TestFastUpToDate\ConsoleApp1\bin\Debug\net8.0\ConsoleApp1.pdb".
3>
3>Build succeeded.
3>    0 Warning(s)
3>    0 Error(s)
3>
3>Time Elapsed 00:00:00.25
========== Build: 1 succeeded, 0 failed, 2 up-to-date, 0 skipped ==========
========== Build completed at 14:50 and took 00.367 seconds ==========

Then when pressing Build -> Build Solution again, we get this FastUpToDate build:

Build started at 14:51...
1>FastUpToDate: Build acceleration is enabled for this project via a feature flag. See "Tools | Options | Environment | Preview Features" to control this setting. See https://aka.ms/vs-build-acceleration. (ClassLibrary2)
1>FastUpToDate: Comparing timestamps of inputs and outputs: (ClassLibrary2)
1>FastUpToDate:     No inputs are newer than earliest output 'C:\Temp\TestFastUpToDate\ClassLibrary2\obj\Debug\net8.0\ClassLibrary2.pdb' (2024-03-12 14:50:08.069). Newest input is 'C:\Temp\TestFastUpToDate\ClassLibrary2\obj\ClassLibrary2.csproj.nuget.g.targets' (2024-03-12 14:48:10.754). (ClassLibrary2)
1>FastUpToDate: Project is up-to-date. (ClassLibrary2)
2>FastUpToDate: Build acceleration is enabled for this project via a feature flag. See "Tools | Options | Environment | Preview Features" to control this setting. See https://aka.ms/vs-build-acceleration. (ClassLibrary1)
2>FastUpToDate: Comparing timestamps of inputs and outputs: (ClassLibrary1)
2>FastUpToDate:     No inputs are newer than earliest output 'C:\Temp\TestFastUpToDate\ClassLibrary1\obj\Debug\net8.0\ClassLibrary1.pdb' (2024-03-12 14:50:20.040). Newest input is 'C:\Temp\TestFastUpToDate\ClassLibrary2\bin\Debug\net8.0\ClassLibrary2.dll' (2024-03-12 14:50:08.070). (ClassLibrary1)
2>FastUpToDate: Project is up-to-date. (ClassLibrary1)
3>FastUpToDate: Build acceleration is enabled for this project via a feature flag. See "Tools | Options | Environment | Preview Features" to control this setting. See https://aka.ms/vs-build-acceleration. (ConsoleApp1)
3>FastUpToDate: Comparing timestamps of inputs and outputs: (ConsoleApp1)
3>FastUpToDate:     No inputs are newer than earliest output 'C:\Temp\TestFastUpToDate\ConsoleApp1\obj\Debug\net8.0\ConsoleApp1.pdb' (2024-03-12 14:50:08.592). Newest input is 'C:\Temp\TestFastUpToDate\ClassLibrary1\obj\Debug\net8.0\ref\ClassLibrary1.dll' (2024-03-12 14:50:08.101). (ConsoleApp1)
3>FastUpToDate: Copying 1 files to accelerate build (https://aka.ms/vs-build-acceleration): (ConsoleApp1)
3>FastUpToDate:     From 'C:\Temp\TestFastUpToDate\ClassLibrary2\bin\Debug\net8.0\ClassLibrary2.dll' to 'C:\Temp\TestFastUpToDate\ConsoleApp1\bin\Debug\net8.0\ClassLibrary2.dll'. (ConsoleApp1)
3>FastUpToDate: Build acceleration copied 1 files. (ConsoleApp1)
3>FastUpToDate: Project is up-to-date. (ConsoleApp1)
========== Build: 0 succeeded, 0 failed, 3 up-to-date, 0 skipped ==========
========== Build completed at 14:51 and took 00.042 seconds ==========
Visual Studio accelerated 1 project(s), copying 1 file(s). See https://aka.ms/vs-build-acceleration.

Note in the FastUpToDate build, we have an extra file copy of ClassLibrary2.dll to the output of ConsoleApp1.
This is the inconsistent behaviour between FastUpToDate and normal build.

User Impact

The default setting for build acceleration changed in VS 17.9 (according to the last internal VS check-ins referenced in this issue). For our projects this update turned out to be a surprising and hard-to-track-down breaking change. (Even though the previous comment suggests it changed for "sdk style (.NET core) projects", our sdk style (.NET Framework)" project was affected.) The default changed with no indication in the Visual Studio release notes.

The behavior of the "FastUpToDate" build is different to the normal MSBuild in that additional transitive dependencies are copied to the output, where MSBuild would not copy these files. With build acceleration on, the extra files will be copied to output when either doing "Build" or starting to debug, which both trigger the "FastUpToDate" build and hence the extra copy. When doing a "Rebuild" or building after changes, the real MSBuild build is run, which does not copy the extra files. This is even more confusing, since extra files will remain in the output until manually deleted ("Clean" runs MSBuild, which will not remove the extra files).

Whether the extra files should be there or not is another matter, but having these two incompatible build behaviors is very confusing. In our case these files were not used, but broke things at runtime.

There is an easy workaround for the problem - just disable the build acceleration for the project. In our case we were also able to remove the unneeded assembly references, but that might not always be the case.

[adamint]

@drewnoakes for investigation

[drewnoakes]

@govert thank you for the detailed repro. That's very helpful. We will take a look asap.

In ClassLibrary1.csproj, add an assembly reference to the output of ClassLibrary2. This adds a Reference item with its HintPath.

Why use a Reference instead of a ProjectReference? Referencing the output of another project in this way is not supported. For one thing, it hides the build order dependency from the build system. It's possible that the bug here is just a race condition.

[govert]

In our actual case, we were just referencing an external library (for which we did not have a project, solution or NuGet package) on its own. But when writing up the repro, I tried picking some random assembly from a NuGet package, but that was harder to explain in the write-up than just to add another project and use its output.
The point is not that the extra reference is from a project that is part of the solution, or how it is built. It's just an assembly that is outside the solution and projects and pulled in as a <Reference> item with a HintPath (not sure that's important) into a ProjectReferenced library project. Then the FUTD build transitively copies the extra assembly, inconsistent with a normal build.

(An extra quirk in our case was that the assembly .dll file had been renamed, so the internal assembly name did not match the .dll file name. But that seemed incidental too, and not needed to reproduce the extra copy.)

[govert]

I tried it now and referencing a library from a NuGet package in the C:\Users\<User>\.NuGet\Packages cache, or another faraway location, does not cause the copy under FUTD build. Then copying that same library to a directory under the solution directory does causes the FUTD problem again. So, the location relative to the solution file (or ConsoleApp project ?) seems important, but nothing about the assembly itself.