Project-system: Eternal restore loop when version is dynamically generated

[abpiskunov]

Open solution in this zip file: \\vwdbuild01\Temp\antonpis\repro\RestoreLoopRepro.zip. It would start restore, restore fails and would start again - never stopping restore loop.

I saw that on VS d15rel 26131.1.

[abpiskunov]

@srivatsn @davkean FYI, not sure if it is known , but probably would be release blocking ...

[natidea]

@abpiskunov I don't see this problem on d15rel.26202.1. Can you confirm it is fixed for you in that build? Closing for now.

[davkean]

We've got another repro of this, more details forthcoming.

[mikeharder]

It repros for me on 15.0.26202.1 D15REL. Repro project at https://github.com/mikeharder/HelloWorldNetCoreApp2.

One thing unusual about the repro project is TargetFramework=netcoreapp2.0 and RuntimeFrameworkVersion=2.0.0-*.

[mikeharder]

dotnet restore from the command line works fine:

> dotnet --info
.NET Command Line Tools (1.0.0-rc4-004755)

Product Information:
 Version:            1.0.0-rc4-004755
 Commit SHA-1 hash:  bffbee2b91

Runtime Environment:
 OS Name:     Windows
 OS Version:  6.3.9600
 OS Platform: Windows
 RID:         win81-x64
 Base Path:   C:\Program Files\dotnet\sdk\1.0.0-rc4-004755

> dotnet restore
  Restoring packages for D:\Git\HelloWorldNetCoreApp2\HelloWorldNetCoreApp2.csproj...
  Generating MSBuild file D:\Git\HelloWorldNetCoreApp2\obj\HelloWorldNetCoreApp2.csproj.nuget.g.props.
  Generating MSBuild file D:\Git\HelloWorldNetCoreApp2\obj\HelloWorldNetCoreApp2.csproj.nuget.g.targets.
  Writing lock file to disk. Path: D:\Git\HelloWorldNetCoreApp2\obj\project.assets.json
  Restore completed in 162.53 ms for D:\Git\HelloWorldNetCoreApp2\HelloWorldNetCoreApp2.csproj.

  NuGet Config files used:
      D:\Git\HelloWorldNetCoreApp2\NuGet.Config
      C:\Users\<user>\AppData\Roaming\NuGet\NuGet.Config
      C:\Program Files (x86)\NuGet\Config\Microsoft.VisualStudio.Offline.config

  Feeds used:
      https://dotnet.myget.org/F/dotnet-core/api/v3/index.json
      https://api.nuget.org/v3/index.json

[mikeharder]

Build error in VS:

Severity: Error
Code: MSB4062
Description: The "HandlePackageFileConflicts" task could not be loaded from the assembly C:\Users\mharder\.nuget\packages\netstandard.library\2.0.0-beta-24918-03\build\desktop/NETStandard.Tools.dll. Could not load file or assembly 'NETStandard.Tools, Version=999.999.999.999, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51' or one of its dependencies. Strong name validation failed. (Exception from HRESULT: 0x8013141A) Confirm that the <UsingTask> declaration is correct, that the assembly and all its dependencies are available, and that the task contains a public class that implements Microsoft.Build.Framework.ITask.
Project: HelloWorldNetCoreApp2
File: C:\Users\<username>\.nuget\packages\netstandard.library\2.0.0-beta-24918-03\build\NETStandard.Library.targets
Line: 80

Output Window:

Restoring NuGet packages...
Time Elapsed: 00:00:00.0075856
========== Finished ==========

Restoring NuGet packages...
Time Elapsed: 00:00:00.0586642
========== Finished ==========

Restoring NuGet packages...
Time Elapsed: 00:00:00.0071143
========== Finished ==========

[mikeharder]

The "HandlePackageFileConflicts" task could not be loaded from the assembly
C:\Users\<user>\.nuget\packages\netstandard.library\2.0.0-beta-24918-03\build\desktop/NETStandard.Tools.dll.
Could not load file or assembly 'NETStandard.Tools, Version=999.999.999.999, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51'
or one of its dependencies.
Strong name validation failed. (Exception from HRESULT: 0x8013141A)

Perhaps the root cause in my repro, is that the netstandard.library package being used is not signed?

[abpiskunov]

@natidea try to remove all obj/bin/.vs folders form teh solution form all projects, close VS and open solution again - that worked for me everytime to get that repro

[mikeharder]

@natidea @abpiskunov: The solution from Anton does not repro on my install of 15.0.26202.1 D15REL.

[eerhardt]

@ericstj @weshaggard for the signing of the net standard package

[natidea]

I was able to repro with @mikeharder 's project, but still can't repro with Anton's. Issue went away when I switched target framework to netcoreapp1.0

[natidea]

Stepping through @mikeharder 's project in a debugger, I see an infinite loop of subscription updates with the following sequence of changes to PackageReferences:

• Added: Microsoft.NETCore.App
• Removed: Microsoft.NETCore.App
• Added: Microsoft.NETCore.App
• Removed: Microsoft.NETCore.App
  ...

And so on. Each time this changes, we nominate NuGet to do a new restore.

[natidea]

I'm no longer seeing this on my machine. I noticed that the NETStandard.Library package was updated to 2.0.0-beta-25006-01 and the binaries are signed in this build, whereas they were not signed in the build I was using last week: 2.0.0-beta-24918-03.

@weshaggard can you confirm the signing issue was fixed?

[davkean]

Regardless of whether the signing issue was fixed, we should make it so that we never get into this state if there are bad packages.

[weshaggard]

Yes the signing issue was fixed but I agree with @davkean we should guard against this as any nuget package could potentially get us into this state.

[natidea]

/cc some NuGet folks for ideas on how a failures during restore could lead to project state changing in a way that produces this infinite loop. @emgarten @alpaix @rrelyea

I'll note that the task that failed (HandlePackageFileConflicts) is taking a direct dependency on our SDK targets:

<HandlePackageFileConflictsAfter>ResolvePackageDependenciesForBuild</HandlePackageFileConflictsAfter>

It seems likely that only packages with tasks that participate in this part of the build could put us in this broken state i.e. mostly our packages and partner teams. I'll drop the blocking release label.

[atanasa]

I am experiencing an endless loop of restores in VS 2017 RC4+26206.0 when switching to a custom solution configuration. I have 3 solution configurations - Debug, Restore, Interop. Once I switch to the Interop configuration it would start doing restore in an endless loop. There are no errors just a repeating restore operation every second.

I am having trouble isolating this. Is there some way to turn on diagnostics? I have changed the verbosity for Build and Run in Options to Diagnostic but this does not seem to affect the restore output.

[atanasa]

I have managed to get an isolated repro for my case. The repro solution:
ReproEternalRestore.zip

This is the project:

<Project Sdk="Microsoft.NET.Sdk">
  <PropertyGroup>
    <InteropVersion>$([System.DateTime]::Now.ToString(yyyyMMdd.HHmmss))</InteropVersion>
    <PackageVersion Condition=" '$(Configuration)' == 'Interop' ">$(InteropVersion)</PackageVersion>
  </PropertyGroup>
  <PropertyGroup Condition="'$(Configuration)|$(Platform)'=='Interop|AnyCPU'" />
  <PropertyGroup>
    <TargetFramework>netstandard1.4</TargetFramework>
  </PropertyGroup>

</Project>

I would probably be able to workaround it by taking this into a post build action. It is strange that a change in the package version would trigger a restore as this is the version of the output package not the input dependencies. Also it seems that this is evaluated very often.

[rrelyea]

PackageVersion gets written in the assets file, as that is where "dotnet pack" will get the appropriate version to reference as a package, for projectreferences.
Roslyn project system has package version as a property that NuGet restore cares about, and nominates its project for a restore whenever it changes.

/cc: @alpaix @rohit21agrawal

[anangaur]

Just checking if this is still an issue and being actively looked into? We have been documenting this as a known issue in all our release notes for NuGet releases.

[natidea]

@anangaur what does the known issue documentation look like? Some specific issues around eternal restore have been resolved using targeted fixes, but the general architectural problem remains, and users can still enter this state (e.g. with package version numbers that contain a timestamp). We don't yet have a general solution.

[anangaur]

We have been referring this as a known issue in NuGet release notes right from 4.0.0 RTM till the last release 4.5.0 RTM

Do you think we can remove this known issue as the chances of users encountering this issue would be much lesser than before considering many related issues have been fixed now? Can we close this issue and open another one that is more specific in nature?

[davkean]

I think we should detect this case - and avoid the loop. Unsure where or who should do the work.

[gshock]

hi all, i am seeing this endless loop when i use commands in the post-build command line.
i am just trying to copy files and run powershell scripts.
is this going to be in the fixes? it's pretty useful (time-saving) when that is not broken

[andresguibarra]

Currently having this issue in several projects. I don't know exactly how to reproduce it but the first step would be having a project in visual studio.

[buybackoff]

For several days I have had the problem randomly and rebuilding a solution helped. Now a solution went crazy and endlessly updates NuGet packages every half second. Cannot use VS completely. Debugging complains that code was edited. Any way to fix it? Using 16.0.0

[joshmouch]

I get this infinite loop in VS 2019 if I add the following to my csproj file:

<Version>$([System.DateTime]::Now.ToString("yyyy.MMdd.HHmm.ss"))</Version>

[andresguibarra]

@joshmouch you're right!

I deleted these lines and stopped restoring packages in an infinite loop:

<Build>$([System.DateTime]::op_Subtraction($([System.DateTime]::get_Now().get_Date()),$([System.DateTime]::new(2000,1,1))).get_TotalDays())</Build>
<Revision>$([MSBuild]::Divide($([System.DateTime]::get_Now().get_TimeOfDay().get_TotalSeconds()), 2).ToString('F0'))</Revision>
<Version>1.2.$(Build).$(Revision)</Version>

[buybackoff]

I have also recently added NuGet version number that depends on time. Hopefully zeroing the seconds parts will help.

[joshmouch]

Any comments from Microsoft on how to have a dynamic <Version> without causing this infinite loop?

[davkean]

@joshmouch We evaluate the project _all the time_, even sometimes without user action, when that happens we think there's changes because the value has changed - hence the loop. Zero'ing the seconds part is a workaround and we should make a change to avoid the loop, but I still worry about all the extra work we do because of this regardless of the restore.

[atanasa]

Considering that VS uses a custom restore engine different that the one in the command line, as a general solution I requested that there is an option to disable the nuget integration in Visual Studio - https://github.com/NuGet/Home/issues/7469
If that is an option, then you would manually trigger the restore via a button only when you want to and have total control on how your project is build and have that build be identical to the build from the command line (dotnet sdk or msbuild).

[SamuelEnglard]

A workaround I found is to not have the version change during design-time builds. Using the advice from design-time-builds.md I made it only add the date when not a design-time build.

[nkolev92]

Another report in https://developercommunity.visualstudio.com/content/problem/899082/running-low-priority-background-processes-never-co-1.html

[chanibal]

Had this issue with VS 2019 16.5.5: details on Stack Overflow, someone also had this on MS Developer Community.

[aesalazar]

This is still an issure in VS 2019 16.6. I had this in all of my csproj files which triggered the issue:

<FileVersion>1.0.$([System.DateTime]::UtcNow.Date.Subtract($([System.DateTime]::Parse("2000-01-01"))).TotalDays).$([System.Math]::Floor($([MSBuild]::Divide($([System.DateTime]::UtcNow.TimeOfDay.TotalSeconds), 1.32))))</FileVersion>
<Version>1.0.$([System.DateTime]::UtcNow.Date.Subtract($([System.DateTime]::Parse("2000-01-01"))).TotalDays).$([System.Math]::Floor($([MSBuild]::Divide($([System.DateTime]::UtcNow.TimeOfDay.TotalSeconds), 1.32))))</Version>

I was able to resolve it by backing off the Version to NOT include the seconds suffix:

<FileVersion>1.0.$([System.DateTime]::UtcNow.Date.Subtract($([System.DateTime]::Parse("2000-01-01"))).TotalDays).$([System.Math]::Floor($([MSBuild]::Divide($([System.DateTime]::UtcNow.TimeOfDay.TotalSeconds), 1.32))))</FileVersion>
<Version>1.0.$([System.DateTime]::UtcNow.Date.Subtract($([System.DateTime]::Parse("2000-01-01"))).TotalDays)</Version>

but still keep it on the FileVersion.

[dominoFire]

Another report: https://developercommunity.visualstudio.com/content/problem/1173352/if-csproj-has-dynamic-versionsuffix-nuget-restore.html

[ben-page]

This is still an issue in 16.8.1

[kartheekp-ms]

@RamjotSingh from Teams team has reported this issue through a VS feedback ticket. Any user action such as adding a class file, editing code in the IDE triggered a restore through project system nomination. The project had their patch version number set to
<SemanticVersionPatch>$([MSBuild]::Divide($([System.DateTime]::Now.Subtract($([System.DateTime]::Parse($(SemanticVersionDate)))).TotalMinutes), 5).ToString('F0'))</SemanticVersionPatch> this behavior in the IDE.

@nkolev92 suggested a fix to this setting and there were no continuous restores after that.

https://developercommunity2.visualstudio.com/t/Performance-issues-in-Visual-Studio-168/1280509