*.failed files causing massive headache with some clients being unable to install/update

agross commented 7 years ago

Description

There are two feeds (nuget.org) and an internal feed that both have different versions of System.Windows.Interactivity.

The nuget.org package is deprecated (not sure if that matters).
nuget.org has versions 1.0.0 and 1.0.1
The internal feed has version 3.0.40218.0
paket.dependencies specifies ~> 3.0, so the nuget.org packages should be disregarded completely

Repro steps

paket.dependencies:

framework: auto-detect
source https://nuget.org/api/v2
source https://internal.feed.local/httpAuth/app/nuget/v1/FeedService.svc

nuget System.Windows.Interactivity ~> 3.0

paket install tries to query nuget.org for ~> 3.0, but fails with this message:

Paket version 4.8.5
Resolving packages for group Main:
Paket failed with:
        There was a version conflict during package resolution.
  Could not resolve package System.Windows.Interactivity >= 3.0 < 4.0:
   - Available versions:
     - (1.0.1, [https://www.nuget.org/api/v2])
     - (1.0.0, [https://www.nuget.org/api/v2])

  Please try to relax some conditions or resolve the conflict manually (see http://fsprojects.github.io/Paket/nuget-dependencies.html#Use-exactly-this-version-constraint).

We tried reordering the source statements, but that didn't help.

We were able to generate a paket.lock file in an earlier version of paket, something between Fri Feb 3 16:42:44 2017 +0100 (last commit on the lockfile) and today broke that feature.

agross commented 7 years ago

Interestingly, this works on mono (macOS) without issues.

matthid commented 7 years ago

I think the implementation takes the first answer IIRC. This probably explains what you are seeing.

agross commented 7 years ago

In this case the first answer is a non-answer, so it should be disregarded.

matthid commented 7 years ago

Yes I agree, however this probably makes the resolver a lot slower so we need to be careful and see if there might be another way to handle this.

agross commented 7 years ago

As I said, we were able to create a valid resolution with an earlier version of Paket that had similar speed. I consider this to be a regression.

matthid commented 7 years ago

Ah sorry, I missed that part sadly we don't know on which versions only that it was before <=4.0.0-beta009 and <=3.35.1 and I assume you didn't use a alpha/beta back then.

agross commented 7 years ago

I will try bisecting this tomorrow.

agross commented 7 years ago

Correct, no betas.

agross commented 7 years ago

Idea: bundler adds its version to the lock file (only when it changes). Paket should probably too. @forki

agross commented 7 years ago

That's interesting, we now have two machines where it's able to paket update (1x macOS/mono, 1x Windows 10) without problems and one (Windows 10) where it shows the same behavior like yesterday.

Is the order in which package sources are queried deterministic?

matthid commented 7 years ago

No AFAIK the first/faster response wins.

agross commented 7 years ago

Any idea how I can bisect this then? The machine I own doesn't show the error right now.

matthid commented 7 years ago

I think the only way to make this reliable is to proxy internal.feed.local and delay the response

matthid commented 7 years ago

https://github.com/fsprojects/Paket/blob/master/src/Paket.Core/Dependencies/NuGetV2.fs#L841-L880

So I guess my assumption is false. We actually ask all sources, but there might be a various number of endpoints for a source which return different results...

Uli-Armbruster commented 7 years ago

Hier mal der Stacktrace:

D:\dev\heco\comwork\tools>paket update --verbose

Paket version 4.8.5
found: D:\dev\heco\comwork\tools\paket.dependencies
Parsing D:\dev\heco\comwork\tools\paket.dependencies
Resolving packages for group Main:
   0 packages in resolution.
   5 requirements left
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 4.19 < 5.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 3.3 < 4.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 3.0 < 4.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 2.0 < 3.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 0.9 < 1.0

  Trying to resolve FluentAssertions >= 4.19 < 5.0 (from D:\dev\heco\comwork\tools\paket.dependencies)
  - fetching versions for FluentAssertions
 - FluentAssertions 4.19.2
   Found Explored Package  FluentAssertions 4.19.2
   1 packages in resolution.
     - FluentAssertions, 4.19.2
   4 requirements left
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 3.3 < 4.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 3.0 < 4.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 2.0 < 3.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 0.9 < 1.0

  Trying to resolve FakeItEasy >= 3.3 < 4.0 (from D:\dev\heco\comwork\tools\paket.dependencies)
  - fetching versions for FakeItEasy
 - FakeItEasy 3.3.2
   Found Explored Package  FakeItEasy 3.3.2
   2 packages in resolution.
     - FakeItEasy, 3.3.2
     - FluentAssertions, 4.19.2
   3 requirements left
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 3.0 < 4.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 2.0 < 3.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 0.9 < 1.0

  Trying to resolve System.Windows.Interactivity >= 3.0 < 4.0 (from D:\dev\heco\comwork\tools\paket.dependencies)
  - fetching versions for System.Windows.Interactivity
  Could not resolve package System.Windows.Interactivity >= 3.0 < 4.0:
   - Available versions:
     - (1.0.1, [https://www.nuget.org/api/v2])
     - (1.0.0, [https://www.nuget.org/api/v2])

    ==> Trying different resolution.
 - FakeItEasy 3.3.1
   Found Explored Package  FakeItEasy 3.3.1
   2 packages in resolution.
     - FakeItEasy, 3.3.1
     - FluentAssertions, 4.19.2
   3 requirements left
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 3.0 < 4.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 2.0 < 3.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 0.9 < 1.0

 - FakeItEasy 3.3.0
   Found Explored Package  FakeItEasy 3.3.0
   2 packages in resolution.
     - FakeItEasy, 3.3.0
     - FluentAssertions, 4.19.2
   3 requirements left
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 3.0 < 4.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 2.0 < 3.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 0.9 < 1.0

 - FluentAssertions 4.19.1
   Found Explored Package  FluentAssertions 4.19.1
     FluentAssertions 4.19.1 was unlisted
 - FluentAssertions 4.19.0
   Found Explored Package  FluentAssertions 4.19.0
   1 packages in resolution.
     - FluentAssertions, 4.19.0
   4 requirements left
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 3.3 < 4.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 3.0 < 4.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 2.0 < 3.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 0.9 < 1.0

Searching for compatible unlisted package

   Retrieved Explored Package  FluentAssertions 4.19.2
   1 packages in resolution.
     - FluentAssertions, 4.19.2
   4 requirements left
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 3.3 < 4.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 3.0 < 4.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 2.0 < 3.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 0.9 < 1.0

   Retrieved Explored Package  FluentAssertions 4.19.1
   1 packages in resolution.
     - FluentAssertions, 4.19.1
   4 requirements left
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 3.3 < 4.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 3.0 < 4.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 2.0 < 3.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 0.9 < 1.0

   Retrieved Explored Package  FluentAssertions 4.19.0
   1 packages in resolution.
     - FluentAssertions, 4.19.0
   4 requirements left
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 3.3 < 4.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 3.0 < 4.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 2.0 < 3.0
     - D:\dev\heco\comwork\tools\paket.dependencies, >= 0.9 < 1.0

Paket failed with:
        There was a version conflict during package resolution.
  Resolved packages:
   - FluentAssertions 4.19.0
  Could not resolve package System.Windows.Interactivity >= 3.0 < 4.0:
   - Available versions:
     - (1.0.1, [https://www.nuget.org/api/v2])
     - (1.0.0, [https://www.nuget.org/api/v2])

  Please try to relax some conditions or resolve the conflict manually (see http://fsprojects.github.io/Paket/nuget-dependencies.html#Use-exactly-this-version-constraint).
StackTrace:
     bei Paket.PackageResolver.ResolutionModule.getModelOrFail@212.Invoke(String message)
   bei Paket.UpdateProcess.groups@147-5.Invoke(GroupName groupName, DependenciesGroup dependenciesGroup)
   bei Microsoft.FSharp.Collections.MapTreeModule.mapiOpt[a,b,c](FSharpFunc`3 f, MapTree`2 m)
   bei Microsoft.FSharp.Collections.FSharpMap`2.Map[b](FSharpFunc`2 f)
   bei Paket.UpdateProcess.selectiveUpdate(Boolean force, FSharpFunc`2 getSha1, FSharpFunc`2 getSortedVersionsF, FSharpFunc`2 getPackageDetailsF, LockFile lockFile, DependenciesFile dependenciesFile, UpdateMode updateMode, SemVerUpdateMode semVerUpdateMode)
   bei Paket.UpdateProcess.SelectiveUpdate(DependenciesFile dependenciesFile, FSharpOption`1 alternativeProjectRoot, UpdateMode updateMode, SemVerUpdateMode semVerUpdateMode, Boolean force)
   bei Paket.UpdateProcess.SmartInstall(DependenciesFile dependenciesFile, UpdateMode updateMode, UpdaterOptions options)
   bei <StartupCode$Paket-Core>.$PublicAPI.Update@217.Invoke(Unit unitVar0)
   bei Paket.Utils.RunInLockedAccessMode[a](String rootFolder, FSharpFunc`2 action)
   bei Paket.Program.main@438-15.Invoke(ParseResults`1 results)
   bei Paket.Program.processWithValidation[T](Boolean silent, FSharpFunc`2 validateF, FSharpFunc`2 commandF, ParseResults`1 result)
   bei Paket.Program.main$cont@420(ParseResults`1 results, Boolean silent, Boolean fromBootstrapper, Unit unitVar)
bei Paket.Program.main()

agross commented 7 years ago

We see two HTTP requests being made to the internal feed, both returning the same XML:

<feed xml:base="https://example.com/httpAuth/app/nuget/v1/FeedService.svc/" xmlns="http://www.w3.org/2005/Atom" xmlns:m="http://schemas.microsoft.com/ado/2007/08/dataservices/metadata" xmlns:d="http://schemas.microsoft.com/ado/2007/08/dataservices">
<id>https://example.cpm/httpAuth/app/nuget/v1/FeedService.svc/Packages</id>
<title type="text">Packages</title>
<updated>2017-05-18T13:58:39.527+02:00</updated>
<author>
<name/>
</author>
<link href="Packages" rel="self" title="Packages"/>
<entry>
<id>https://example.com/httpAuth/app/nuget/v1/FeedService.svc/Packages(Id='System.Windows.Interactivity',Version='3.0.40218.0')</id>
<title type="text">System.Windows.Interactivity</title>
<updated>2016-12-01T15:23:44.841+01:00</updated>
<author>
<name>Microsoft Corporation</name>
</author>
<category term="NuGetGallery.OData.V2FeedPackage" scheme="http://schemas.microsoft.com/ado/2007/08/dataservices/scheme"/>
<link href="Packages(Id='System.Windows.Interactivity',Version='3.0.40218.0')" rel="edit" title="V2FeedPackage"/>
<link href="Packages(Id='System.Windows.Interactivity',Version='3.0.40218.0')/$value" rel="edit-media" type="application/zip"/>
<content type="application/zip" src="https://example.com/httpAuth/app/nuget/v1/FeedService.svc/download/Kunden_Heco_ComWORK_Sdk/66522:id/packages/System.Windows.Interactivity.3.0.40218.0.nupkg"/>
<m:properties>
<d:Id>System.Windows.Interactivity</d:Id>
<d:Version>3.0.40218.0</d:Version>
<d:NormalizedVersion>3.0.40218</d:NormalizedVersion>
<d:Authors>Microsoft Corporation</d:Authors>
<d:Copyright>Copyright (c) Microsoft Corporation. All rights reserved.</d:Copyright>
<d:Created>2016-12-01T14:23:44.841</d:Created>
<d:Dependencies m:null="true"/>
<d:Description>System.Windows.Interactivity</d:Description>
<d:DownloadCount>0</d:DownloadCount>
<d:GalleryDetailsUrl m:null="true"/>
<d:IconUrl m:null="true"/>
<d:IsLatestVersion>true</d:IsLatestVersion>
<d:IsAbsoluteLatestVersion>true</d:IsAbsoluteLatestVersion>
<d:IsPrerelease>false</d:IsPrerelease>
<d:Language m:null="true"/>
<d:LastUpdated>2016-12-01T14:23:44.841</d:LastUpdated>
<d:Published>2016-12-01T14:23:44.841</d:Published>
<d:PackageHash>TbM3UATEutUGlJ5o63EsEXXTJYepKAfykJv8RbQ/xaDmGgGGFacE/h/x0C6UYmjiSOpLILxkDaaUvfGaWE2k8w==</d:PackageHash>
<d:PackageHashAlgorithm>SHA512</d:PackageHashAlgorithm>
<d:PackageSize>28043</d:PackageSize>
<d:ProjectUrl m:null="true"/>
<d:ReportAbuseUrl m:null="true"/>
<d:ReleaseNotes m:null="true"/>
<d:RequireLicenseAcceptance>false</d:RequireLicenseAcceptance>
<d:Summary m:null="true"/>
<d:Tags m:null="true"/>
<d:Title m:null="true"/>
<d:VersionDownloadCount>0</d:VersionDownloadCount>
<d:MinClientVersion m:null="true"/>
<d:LastEdited m:null="true"/>
<d:LicenseUrl m:null="true"/>
<d:LicenseNames m:null="true"/>
<d:LicenseReportUrl m:null="true"/>
</m:properties>
</entry>
</feed>

matthid commented 7 years ago

On your machine where this is not working, does the file

let h = source.Url |> normalizeUrl |> hash |> abs
let packageUrl = sprintf "Versions.%O.s%d.failed" packageName h
let fileName = Path.Combine(Constants.NuGetCacheFolder,packageUrl)

exists?

Can you verify that if works after deleting it?

matthid commented 7 years ago

Its defined as Path.Combine (appData, "Nuget", "Cache")

agross commented 7 years ago

@matthid Sorry, is this supposed to be executed in a FSI session?

does the file

Does ist what? ;-)

agross commented 7 years ago

The paket update --verbose output on a machine that works:

  Trying to resolve System.Windows.Interactivity >= 3.0 < 4.0 (from D:\Users\agross\Projekte\GROSSWEBER\Kunden\heco\heco\comwork\tools\paket.dependencies)
  - fetching versions for System.Windows.Interactivity
getAllVersionsFromNugetODataWithFilter from url 'https://example.com/httpAuth/app/nuget/v1/FeedService.svc/Packages?$filter=tolower(Id) eq 'system.windows.interactivity''
getAllVersionsFromNugetODataFindById from url 'https://example.com/httpAuth/app/nuget/v1/FeedService.svc/FindPackagesById()?id='System.Windows.Interactivity''
 - System.Windows.Interactivity 3.0.40218.0
   Found Explored Package  System.Windows.Interactivity 3.0.40218.0
   3 packages in resolution.
     - FakeItEasy, 3.3.2
     - FluentAssertions, 4.19.2
     - System.Windows.Interactivity, 3.0.40218.0
   2 requirements left
     - D:\Users\agross\Projekte\GROSSWEBER\Kunden\heco\heco\comwork\tools\paket.dependencies, >= 2.0 < 3.0
     - D:\Users\agross\Projekte\GROSSWEBER\Kunden\heco\heco\comwork\tools\paket.dependencies, >= 0.9 < 1.0

matthid commented 7 years ago

Basically try to delete all *.failed files from the Nuget/Cache folder (in AppData) an and try again and check if that fixes the problem on the not-working machine.

matthid commented 7 years ago

~~If that works the problem where this was introduced is most likely https://github.com/fsprojects/Paket/commit/f29d5352f2219bf5edf5a7d73fe79ea5c4b44eb9~~

Scratch that. TBH I don't see any related commit. This problem basically had to be there ever since :/

matthid commented 7 years ago

It would help to be able to debug this ...

agross commented 7 years ago

We debugged this a bit today:

group.ResolvedPackages.GetModelOrFail() fails
PackageResolver.availableVersions returns an empty list (which is strange because nuget.org variants are displayed -- keep in mind that I'm a F# noob)
PackageResolver.compatibleVersions filters the empty list down to be empty as well (Cpt. Obvious), so this branch is taken.
I could not find the code responsible talking to the NuGet feeds from this line, but both of ours package sources are used for the currentRequirement.Sources arg
We cleared the local NuGet cache

matthid commented 7 years ago

Maybe I can help with debugging this (Skype "matthi dot d at live dot de")? If not possible I'd suggest setting a breakpoint somewhere around the lines I posted above and see which path is taken for your package...

agross commented 7 years ago

Sent you a contact request. Are you available now?

agross commented 7 years ago

So the solution found by @matthid was to delete all *.failed files from %LOCALAPPDATA%\NuGet\Cache.

I wonder why those files exist in the first place and are cached indefinitely. // cc @forki

agross commented 7 years ago

Interestingly, the cache path above isn't even listed as a NuGet cache:

$ nuget locals all -list
http-cache: C:\Users\agross\AppData\Local\NuGet\v3-cache
global-packages: C:\Users\agross\.nuget\packages\
temp: C:\Users\agross\AppData\Local\Temp\NuGetScratch

matthid commented 7 years ago

are cached indefinitely.

Is probably the key point here... Interestingly this only causes headache in this particular situation where we have mutliple sources with the same package but different versions...

fsprojects / Paket

*.failed files causing massive headache with some clients being unable to install/update #2342

Description

Repro steps