Opam install speed regression in 2.2

[Khady]

Opam 2.1.2 and 2.2 appear to have pretty different speed on the lock and install commands.

$ opam --version
2.1.2
$ time opam lock ahrefs-all-deps
Generated lock files for:
  - ahrefs-all-deps.git: /home/me/.../ahrefs-all-deps.opam.locked

real	0m2.482s
user	0m2.354s
sys	0m0.128s
$ time opam install --deps-only ./ahrefs-all-deps.opam.locked

real	0m1.060s
user	0m0.917s
sys	0m0.143s

vs

$ opam --version
2.2.0~alpha3
$ time opam lock ahrefs-all-deps
Generated lock files for:
  - ahrefs-all-deps.git: /home/me/.../ahrefs-all-deps.opam.locked

real	0m0.587s
user	0m0.462s
sys	0m0.125s
$ time opam install --deps-only ./ahrefs-all-deps.opam.locked
Nothing to do.

real	0m10.967s
user	0m10.390s
sys	0m0.576s

In 2.2 lock is much faster but install is much slower.

From the debug output my understanding is that the solver is used in install with 2.2 but not with 2.1. Note that this is only the case with lock files, install with 2.1 on the raw ahrefs-all-deps takes ~10s and triggers the solver.

For lock the difference also seems to be calling the solver or not. But here the solver is not called in 2.2, so things got faster.

[rjbou]

opam lock doesn't call the solver, but compute several transitive dependencies, and this computation was speed up in 2.2.0~alpha with #5337 & #5503.

For opam install, we need to dig in.
Note for developers: add bench tests for opam install & opam lock.

[Khady]

opam lock doesn't call the solver

Oh ok, sorry I was confused by those debug logs

00:02.379  SOLVER                 Warn: fallback constraint for ocamlformat (< 0.25)
00:02.380  SOLVER                 Warn: fallback constraint for ocamlformat (>= 0.24)
00:02.382  SOLVER                 Warn: fallback constraint for ocamlformat (< 0.25)
00:02.383  SOLVER                 Warn: fallback constraint for ocamlformat (>= 0.24)
00:02.385  SOLVER                 Warn: fallback constraint for ocamlformat (= 0.24.0)
00:02.385  SOLVER                 Warn: fallback constraint for ocamlformat (= 0.24.0)
00:02.394  SOLVER                 Load cudf universe (depopts:true, build:true, post:true)
00:02.402  SOLVER                 filter_dependencies result=412 elements

[rjbou]

The SOLVER "header" is to notify that it is functions called from OpamSolver.
The solver call itself is in those logs, e.g:

00:10.689  SOLVER                 Calling solver builtin-mccs+glpk with criteria -removed,-count[avoid-version,changed],-count[version-lag,request],-count[version-lag,changed],-count[missing-depexts,changed],-changed
00:10.780  SOLVER                 External solver took 0.091s
00:10.780  CUDF                   Solver call done in 0.258s

[kit-ty-kate]

I'm unable to reproduce the regression with opam install --deps-only. On my local machine if i create an opam file that contains every packages i have already installed with a strict dependency, all versions (tested with 2.1.2, 2.1.5 and master) take around 4 seconds and do trigger the solver (this could be improved though!)

@Khady How did you test this locally? Were both code sections in the issue description executed on the same machine one after the other? If so, the slow down is expected the first time opam is ran as it reloads its cache (although it should have been done during opam init --reinit -ni, but this could also be improved to show a warning to execute this command)

[Khady]

If I remember correctly, the logs are showing exactly the commands I ran. I had one terminal with opam 2.2 and one with opam 2.1. Each has a different opam root. They have a switch each, which contains exactly the same packages at the same version except for some opam plugins. I was able to obtain the same numbers multiple times in a row for each version.

will try to check again

[kit-ty-kate]

I tracked the issue down to this commit 9aa2290. I'm looking into it to see what could be done

[kit-ty-kate]

I think i understand why i wasn't able to reproduce on my own above: the ahrefs-all-deps package you're installing is already installed locally on your current switch, however locally I was trying to reproduce with --deps-only of a package that is not installed (but whose dependencies are).

9aa2290 changed the behaviour of this corner case. I opened #5908 to fix this.