Nullable icon indicating copy to clipboard operation
Nullable copied to clipboard

Incremental build is slowed by timestamps of generated source file

Open AArnott opened this issue 3 years ago • 14 comments

Particularly when setting:

    <ProduceReferenceAssembly>true</ProduceReferenceAssembly>

We expect that when A references B and B changes in a way that does not impact its public API, then A does not need to be recompiled. But when A has a package reference to Nullable, it recompiles anyway for no good reason, making incremental builds slower.

Input file "C:\git\lib.template\obj\Library.Tests\Debug\netcoreapp3.1\NuGet\8ED094343F5007F7EC35D088A29F28BB2E4E7756\Nullable\1.3.0\Nullable/MemberNotNullAttribute.cs" is newer than output file "C:\git\lib.template\obj\Library.Tests\Debug\netcoreapp3.1\Library.Tests.xml".

image

Can you fix this by ensuring the timestamp is not updated on this file unnecessarily?

You can test this for yourself, and verify the effectiveness of your fix, using my template repo as follows:

git clone https://github.com/AArnott/Library.Template.git
cd Library.Template
.\init[.ps1]
dotnet build

Then make a change to Calculator.cs that does not impact the public API. Perhaps this:

-        public static int Add(int a, int b) => a + b;
+        public static int Add(int a, int b) => a + b + 1;

Then run:

dotnet build -bl

Open up the msbuild.binlog (in the https://msbuildlog.com viewer) and search for $task csc to see how many times the compiler actually ran. We want to see it just once. When Nullable is not referenced, this happens. But when it is referenced, we see 4.

AArnott avatar Feb 19 '21 17:02 AArnott

Hey, thanks for the report and the detailed reproduction guide! I’m a bit busy right now, but I‘ll gladly look into it when I find the time.

I’m on the phone right now, so I cannot load your example project and play around with the issue, but two remarks just based on the issue text:

  1. I’m a bit confused about the error message, namely that it states that MemberNotNullAttribute.cs is newer than an entirely different file (That doesn’t really make sense to me). Could that maybe happen because the produced XML documentation file is updated with Nullables XML documentation at a later step? Otherwise I cannot really explain why these two files conflict and trigger a new build.

  2. Regarding the timestamp: I must admit that I don’t know how to do this (from a nuspec file where the attributes are „included“ in a project). Can you tell me how I can make such a change?

manuelroemer avatar Feb 23 '21 06:02 manuelroemer

  1. MSBuild's incremental build is based on a set of input files and a set of output files. If any of the inputs is newer than any of the outputs, the build step is considered invalidated and run again. So two file names in the message do not have to do with each other in any way except one is an input and one is an output. Our job to fix incremental build is to make sure the input's timestamp isn't updated when the content of the file has not been so that this timestamp check doesn't trigger a rebuild.
  2. Curious. I had assumed the timestamp was updating because you were somehow generating the file during the build. If nuget is just copying the file, the timestamp shouldn't be changing. Maybe this is a nuget bug. If it is, we can file a bug against them and then workaround it by copying the files with an msbuild .targets file. A binary log should hopefully tell us which msbuild task is responsible for placing that file and/or updating its timestamp.

AArnott avatar Feb 23 '21 06:02 AArnott

Alright, thanks for the clarification on (1)! That helps with understanding the issue.

Regarding (2): I cannot tell whether that is a bug with NuGet. What I can say is that I’m not doing anything but including the attribute files as content files from within the nuspec. While I would expect NuGet to cache the files, they may be overwritten with the same content during every build. Perhaps that happens to prevent manual modification? Not sure.

What I’ll take away from this is that I should migrate away from including the files via the nuspec and instead do it via a targets file. I guess that this is a very reasonable approach without any drawbacks (which I should potentially have used long ago anyway). Again, I unfortunately don’t have a lot of time right now, but when I find some minutes I’ll make the changes.

Thanks again for opening the issue and for providing the details and help!

manuelroemer avatar Feb 24 '21 16:02 manuelroemer

Hi. Regarding switching to new SDK format I have created a topic at the discussions tab. I think the approach to use the "content"-/"contentFiles"-feature of NuGet and therefore <file ... /> in .nuspec-file is the right one. When using the "via a targets file"-approach you have to include the .cs-files into a custom folder (package), copy these .cs-files manually to the obj-folder of consuming project and add them manually via <Compile ...>...<Visible>false</Visible></Compile> dependent on framework. Not pretty to be honest.

teneko avatar Mar 25 '21 15:03 teneko

Hi, I also played around and tried switching from NuGet's features to a .targets file. I did, however, have some issues getting it to work for every single project type. A .targets file did, of course, work for projects using the new SDK style, but legacy projects using the old csproj format and potentially even a packages.config file had issues afterwards. Not quite sure if I that is fixable (I am by no means an MSBuild guru), but it didn't look like that. I also don't want to break compatibility with these legacy project types and NuGet's files/contentFiles approach does work. Maybe someone has a hint as to how a .targets file could successfully be used with older project types?

As to the updated timestamps: I have another suspicion which could cause the updates. I am including the CS files as AttributeFile.cs.pp (note the .pp extension). I use this extension because Visual Studio doesn't create a "virtual folder" in the Solution Explorer containing all of the package's attribute files when the package is referenced (this was, back then at least, the case if the files simply had the .cs extension). I assume that NuGet, to perform its magic on the .pp files, regenerates these during every build which could then lead to the updated timestamps. Not sure on this, I will have to experiment.

@teroneko Thanks a lot for your input and your project! As written above, I agree with you that, at the moment, using NuGets features seem better. Regarding your fork: I'll for sure have a look at it at some point. The Nuke build project is something that I dislike myself. I just can't really tell when as I don't have a lot of spare time on hand recently. 😄

manuelroemer avatar Mar 26 '21 08:03 manuelroemer

legacy projects using the old csproj format and potentially even a packages.config file had issues afterwards. Not quite sure if I that is fixable (I am by no means an MSBuild guru), but it didn't look like that.

I'm sure I could help make it work.

As written above, I agree with you that, at the moment, using NuGets features seem better.

Agreed. It's much simpler that way.

I assume that NuGet, to perform its magic on the .pp files, regenerates these during every build which could then lead to the updated timestamps.

That's a very good hypothesis. We can file a bug against nuget as they should run the transform in an isolated directory and only copy the result if its content changed.

I use this extension because Visual Studio doesn't create a "virtual folder" in the Solution Explorer containing all of the package's attribute files when the package is referenced

So you use the pp extension to alter how the file appears in Solution Explorer? And you specifically do not want the file to appear under a virtual folder? If I had to choose, I would argue in favor of a cs extension and faster build over a preferred rendering in Solution Explorer.

AArnott avatar Mar 26 '21 12:03 AArnott

Hello @AArnott. I tried to reproduce your problem, but I am honest, I cannot reproduce it.

My steps done so far after cloned Library.Template once before:

  1. rm -rf ./*
  2. git reset --hard 1c04816f75df76aefb8cfdb9f61865de2104ff92
  3. Change sdk from 5.0.103 to 5.0.201 (that SDK I had installed) because dotnet complains about it cannot find dotnet.dll (after running cmd /C "init.cmd" ofc): "Found .NET SDK, but did not find dotnet.dll at [C:\Program Files\dotnet\sdk\5.0.103\dotnet.dll]"
  4. dotnet build
  5. change from - public static int Add(int a, int b) => a + b; + public static int Add(int a, int b) => a + b + 1;
  6. dotnet build -bl

Inspect msbuild.binlog by searching for $task csc => Library Template-image

I tested it several times and also with my package; same result.

teneko avatar Apr 10 '21 04:04 teneko

Well, I just tried it fresh @teroneko and it still repros for me. I don't know why it wouldn't for you.

AArnott avatar Apr 10 '21 12:04 AArnott

Well, the only change I can see is the obvious change from SDK version 5.0.103 to 5.0.201. Please check this,

teneko avatar Apr 10 '21 17:04 teneko

I agree, and I tried the SDK version change locally as well, but the problem still repros.

AArnott avatar Apr 10 '21 18:04 AArnott

I use Cygwin and did the following

  1. delete C:\Users<user>.nuget\packages\nullable folder
  2. delete Library.Template folder
  3. git clone https://github.com/teroneko/Library.Template
  4. export DOTNET_ROOT='C:\Users\<user>\.dotnet'
  5. /cygdrive/c/Users/<user>/.dotnet/dotnet build
  6. make the non-public-api-change
  7. /cygdrive/c/Users/<user>/.dotnet/dotnet build -bl
  8. Open MSBuild Log Viewer and inspect msbuild.binlog (I also compared online just be sure it results into the same)

Library Template-image

It still remains the same and we don't get any further. :frowning_face:

teneko avatar Apr 10 '21 21:04 teneko

At your prompting, I've tried with WSL Ubuntu 20 as well, and I still see the same problem of 4 CSC tasks running. Even if the behavior isn't consistent across machines, it should be. I plan to file a bug against nuget tomorrow.

AArnott avatar Apr 11 '21 21:04 AArnott

Hey, sorry for not replying for that long!

Following your comments, I also tried it out again and I'm getting yet another result: image

This was the result after:

dotnet build
[change Calculator.cs]
dotnet build -bl

If I then run the exact same flow again without deleting bin and obj the entire process seems to work: image

Here are the full logs: Logs.zip

manuelroemer avatar Apr 14 '21 18:04 manuelroemer

What I can also say is that the .pp files don't seem to have an influence (at least not on the current issue of having 2 compilations - I cannot tell whether it was the case for the issue with 4 compilations). I tested this by creating a package variant which uses .cs files instead of .pp, adding that package to a local NuGet feed and doing the flow again. It led to the exact same result as in my comment above.

Take that with a grain of salt though, things might fluctuate in different environments.

manuelroemer avatar Apr 14 '21 18:04 manuelroemer