Opam list very slow on opam 2.5

Ecosystem
1

I recently upgraded from ubuntu 24.04 to 26.04 and thus from (I presume) opam 2.1 to 2.5.

It appears that Emacs takes a very long time to start due to user-setup’s opam-detect-installed-tools, which does opam list --installed --short --safe --color=never to get the list of tools for which it can do some configuration.

Indeed, running this command directly in a shell gets a “processing” message for several seconds, with an indication related to the repos. But there is no real need to interact with the repos to get the list of installed packages.

Can somebody reproduce this ?

2

I was going to write that I can’t reproduce, but testing this I discovered I hadn’t finished upgrading opam to 2.5.1 and then after upgrading I could reproduce:

$ time opam list --installed --short --safe --color=never >/dev/null

real	0m0.196s
user	0m0.156s
sys	0m0.040s
$ opam --version
2.5.0
$ time opam list --installed --short --safe --color=never >/dev/null # after upgrading opam

real	0m2.308s
user	0m1.683s
sys	0m0.401s
$ opam --version
2.5.1
3

Does the situation improve if you do it once without the --safe ? I feel it got better for me after that but still slower than it used to be

``real 0m0,619s user 0m0,483s sys 0m0,134s ``

4

Try using strace to pinpoint what is slow (e.g. a particular system call, too many system calls, etc.).

This will print a summary of all system calls, how many times they got called, and how much time they took:

time strace -c -- opam list --installed --short --color=never >/dev/null

You can then dig deeper to see if you can spot the individual system call that is slow:

strace -ffrT opam list --installed --short --color=never 3>&1 1>&2 2>&3 3>/dev/null|sort -g

If that doesn’t help then you can try creating and looking at a flamegraph:

perf record --call-graph=dwarf -F 499 -- opam list --installed --short --color=never >/dev/null
git clone https://github.com/brendangregg/FlameGraph.git
perf script | FlameGraph/stackcollapse-perf.pl | FlameGraph/stackcollapse-recursive.pl | FlameGraph/flamegraph.pl >|flame.svg

Then open flame.svg in the browser.

5

FYI, you can now directly do:

$ perf record --call-graph=dwarf -F 499 -- opam list --installed --short --color=never >/dev/null
$ perf script report flamegraph
6

@reynir @ysalmon i’m unable to reproduce this locally but you might have an easier time debugging using --debug or even --debug-level=3 (and removing --safe(?) otherwise it doesn’t show any debug output, that seems like a bug…).

debug-levels above 0 show timed traces of internal opam actions (that you can then grep for in the opam code). If something jumps from by more than a few hundred milliseconds at a time you’ll know something costly happened between these two actions. For example for me the costliest action is:

00:00.061  CACHE(installed)   Loaded <switch>/.opam-switch/packages/cache in 0.000s
00:00.212  STATE              Switch state loaded in 0.152s

which takes 152 milliseconds

7

In my case it spends a lot of time in compare_case calling the GC. This appears to be already fixed on master by Make OpamStd.String.compare_case allocation free · ocaml/opam@c4984a2 · GitHub

hyperfine --warmup 1 '\_build/default/src/client/opamMain.exe list --
installed --short --color=never >/dev/null' 'opam list --installed --short --color=never >/dev/null'

Benchmark 1: _build/default/src/client/opamMain.exe list --installed --short --color=never >/dev/null
Time (mean ± σ): 97.4 ms ± 2.8 ms [User: 62.6 ms, System: 34.7 ms]
Range (min … max): 94.6 ms … 102.6 ms 29 runs

Benchmark 2: opam list --installed --short --color=never >/dev/null
Time (mean ± σ): 149.2 ms ± 1.4 ms [User: 135.0 ms, System: 14.1 ms]
Range (min … max): 147.3 ms … 152.4 ms 20 runs

Summary
_build/default/src/client/opamMain.exe list --installed --short --color=never >/dev/null ran
1.53 ± 0.05 times faster than opam list --installed --short --color=never >/dev/null

8

Hi! Sorry, I’ve been away from vacation. I no longer can reproduce. I have touched the computer very little in the meantime so I’m not sure what’s changed.

$ time opam list --installed --short --safe --color=never >/dev/null

real	0m0.236s
user	0m0.184s
sys	0m0.053s
$ opam --version
2.5.1
9

Check the timestamp on ~/.opam/repo/state*.cache.
If I delete the state cache then all opam list commands take 1.7s. Running opam update writes out a new state cache, and all is fast again (<0.2s).

After upgrading from 2.5.0 to 2.5.1 did you run opam update? If not maybe there was a stale/invalid state cache left behind.
(or in fact running opam list, without the --safe flag would write out a new cache too. --safe doesn’t write to it, as asked)

10

Interesting! Yes, I had a state cache from yesterday 10:26 CEST. If I deleted the cache I get the 2 second delay which then disappears after running the command without --safe exactly as you describe.

11

Thanks, I’ve opened an issue here with some suggestions, in particular the opam shell integrations should probably detect and update stale caches (i.e. the equivalent of running opam list without --safe), which would avoid this problem on version upgrades.
(There’d be a one-off cost to update the stale cache, but then all future calls will be faster)