Paket 4.x install command takes hours to complete (while 3.x takes minutes)

[pmbanka]

Description

Paket 4.x install command takes a very long time to process my paket.dependencies. I let it run for ~hour and then just killed it. Paket 3.x handled it without problems.

I'm on windows.

Repro steps

1. Clone https://github.com/pmbanka/paket-perf-repro
2. Run paket_old.exe install
3. git add .; git reset --hard
4. Try running paket.exe install

Expected behavior

Both versions should end running in short time.

Actual behavior

paket.exe install takes > 1h

Known workarounds

Use Paket 3.x.

[forki]

/cc @cloudRoutine I assume it's related to the resolver change. Any chance you could take a look?

[0x53A]

I was a bit bored, so I let the profiler run for a while parallel to my normal work.

The 30% inclusive in String.Concat is slightly concerning.

I think there are a few big quick-wins, will try to send a pr in a few minutes.

[forki]

haha. we should remove verbosefn completely!

[0x53A]

After eliminating that:

r.Graph is currently a List, I will try to convert that to a set.

Should speed it up by a magnitude, lets see ...

[matthid]

yep very nice! The bug report really indicated some algorithmic problem (like the graph list you found, instead of the string concat). thanks for looking into this. I'm really waiting for these improvements :) (you saved me from some work I wanted to do eventually, thanks!)

[forki]

r.Graph is currently a List, I will try to convert that to a set.

I'm not sure if order is important. And I think the issue is equality checks on Requirements. they are very slow

[0x53A]

@forki, yup, 43% of total time is Requirements.Compare. Luckily that compare function should have a bit of potential for improvements.

Changing list to set didn't improve it noticeably.

[cloudRoutine]

that verbosefn was essential in diagnosing issues when I rewrote the resolver to be tail recursive. That being said I still think we should have another level of detail above verbose like diagnosticfn

[0x53A]

@cloudRoutine see 0x53A@2251ab3, that fixed it without affecting logging.

[forki]

Yes that's the correct fix. Verbosefn should go completely Am 26.04.2017 20:41 schrieb "Lukas Rieger" <[email protected]>:

…

@cloudRoutine <https://github.com/cloudRoutine> see ***@***.*** <0x53A@2251ab3>, that fixed it without affecting logging. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#2289 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AADgNFovpUqzHeaw5D4mV84wSAyXeHEvks5rz4_lgaJpZM4NI1d6> .

[0x53A]

So I'm not familiar with the Resolve algorithm, but I feel like it goes bonkers somewhere.

One example: it considers these two versions of SourceLink.Fake at the end, but the highest one doesn't have any requirements and so should be an automatic match!

Same with SQLProvider:

[cloudRoutine]

@0x53A you're right it is going mad at some point and it's done that for a long time, I never was able to identify the reason behind it and the last time I worked on the resolve function I was focused on eliminating the stack overflows and never got around to fixing this part

[cloudRoutine]

since appveyor just failed due to a goddamn timeout on basic resolver spec I included this change on ef3f1c4

[0x53A]

I tried a few things, the ones that seemed to improve performance are pushed to https://github.com/0x53A/Paket/tree/perf, but in general I think the algorithm should be fixed first.

If none of you beat me to it, I will try to reduce the repro tomorrow, and maybe figure out what's wrong with the resolver.

[0x53A]

So I was able to reduce it:

redirects: on
framework: net46

source https://api.nuget.org/v3/index.json

nuget FsCheck.Nunit
nuget NUnit ~> 2

nuget Suave

Paket version 4.8.4
Resolving packages for group Main:
 - NUnit 2.6.4
 - FsCheck.Nunit 2.8.0
 - Suave 2.1.0
 - Suave 2.0.5
 - Suave 2.0.4
 - Suave 2.0.3
 - Suave 2.0.2
 - Suave 2.0.1
 - Suave 2.0.0
 - Suave 1.1.3
 - Suave 1.1.2
 - Suave 1.1.1
 - Suave 1.1.0
 - Suave 1.0.0
 - Suave 0.33.0
 - Suave 0.32.1
 - Suave 0.32.0
 - Suave 0.31.2
 - Suave 0.31.1
 - Suave 0.31.0
 - Suave 0.30.0
 - Suave 0.29.1
 - Suave 0.29.0
 - Suave 0.28.1
 - Suave 0.28.0
     Suave 0.28.0 was unlisted
 - Suave 0.27.0
 - Suave 0.26.2
 - Suave 0.26.1
 - Suave 0.26.0
 - Suave 0.25.0
 - Suave 0.24.0
 - Suave 0.23.0
 - Suave 0.22.0
 - Suave 0.21.1
 - Suave 0.21.0
 - Suave 0.20.2
 - Suave 0.20.1
 - Suave 0.20.0
 - Suave 0.19.1
 - Suave 0.19.0
 - Suave 0.18.0
 - Suave 0.17.0
 - Suave 0.16.0
 - Suave 0.15.0
 - Suave 0.14.0
 - Suave 0.13.0
 - Suave 0.12.0
 - Suave 0.11.0
 - Suave 0.10.0
 - Suave 0.9.0
 - Suave 0.8.0
 - Suave 0.7.0
 - Suave 0.6.0
 - Suave 0.5.0
 - Suave 0.4.0
 - Suave 0.3.0
 - Suave 0.2.0
 - Suave 0.1.78
 - Suave 0.0.5
 - Suave 0.0.4
 - Suave 0.0.3
 - Suave 0.0.2
 - Suave 0.0.1
     Suave 0.0.1 was unlisted
 - FsCheck.Nunit 2.7.2
 - FsCheck.Nunit 2.7.1
 - FsCheck.Nunit 2.7.0
 - FsCheck.Nunit 2.6.3
 - NUnit.Runners 2.6.4
 - FSharp.Core 4.1.12
 - FsCheck 2.8.0
 - System.ValueTuple 4.3.0
Locked version resolution written to C:\Users\lr\Source\Repos\paket-perf-repro\paket.lock
Garbage collecting Akka
Garbage collecting Akka.TestKit
Garbage collecting Akka.TestKit.NUnit
Garbage collecting Newtonsoft.Json
Garbage collecting System.Collections.Immutable
5 seconds - ready.

REDIRECTS: ON
FRAMEWORK: NET46
NUGET
  remote: https://api.nuget.org/v3/index.json
    FsCheck (2.8)
      FSharp.Core (>= 3.1.2.5)
    FsCheck.Nunit (2.6.3)
      FsCheck (>= 2.6.3)
      NUnit (>= 2.6.4 < 2.7)
      NUnit.Runners (>= 2.6.4 < 2.7)
    FSharp.Core (4.1.12)
      System.ValueTuple (>= 4.3)
    NUnit (2.6.4)
    NUnit.Runners (2.6.4)
    Suave (2.1)
      FSharp.Core (>= 4.0.0.1)
    System.ValueTuple (4.3)

If you try to reproduce it yourself, you need to always delete the lockfile so that it will start with a clean slate.

As you can see, even if it is now able to resolve it, it still demonstrates that strange behaviour of testing all different versions of suave.

[0x53A]

I got a bit further debugging this:

It (successfully) resolves the following Requirements:
NUnit 2.6.4
FsCheck.Nunit 2.8.0
Suave 2.1.0

then it tries to resolve NUnit > 3, but finds a conflict.

So it goes back one step, to Suave, and loops over all versions of Suave.

[0x53A]

So I think (I hope) I solved it:

The full initial paket.dependencies:

Locked version resolution written to paket.lock
37 seconds - ready.

the relevant change is fuseConflicts:

master...0x53A:perf#diff-781e85b03afcc7c6cedfbd46e3d3b607R659

Instead of just going back one step, I try to find a step that matches the current conflict.
That may not yet be totally correct, but seems to be enough to solve the current issue.

[matthid]

@0x53A This now also resolves with #2307 So I'm really looking forward to combining your perf improvements with the fix :)

Locked version resolution written to C:\PROJ\paket.test\paket.lock
1 minute, 9 seconds - ready.

[matthid]

Omg I merged your branch and get exactly the same :(. Seems like my fix/additional change neglects your improvements?!

Locked version resolution written to C:\PROJ\paket.test\paket.lock
1 minute, 9 seconds - ready.

[pmbanka]

I just wanted to say thank you to everyone working on the issue. Watching you resolving this from a poor repro in just a few days made my jaw drop on the floor. You are awesome and I hope next time I'll be able to help and participate more!