ocaml
`opam update` very slow on MacOS
Hi,
I'm on MacOS, and updating takes far longer than on an Ubuntu machine I have access too (~15min vs ~20s):
$ time opam update -R default --switch=default
<><> Updating package repositories ><><><><><><><><><><><><><><><><><><><><> 🐫
[default] no changes from https://opam.ocaml.org
opam update -R default --switch=default 28.91s user 303.24s system 33% cpu 16:28.17 total
It seems to me very long. I'd appreciate if anybody could point me towards updating faster.
The network should not be too much of a problem, network speedtest reports ~100Mbps in average download speed.
(This has been a problem for quite a long time, but I did not take the time to raise an issue)
Here is the result of opam config report --switch=default (modified to use $HOME).
# opam config report
# opam-version 2.1.5
# self-upgrade no
# system arch=x86_64 os=macos os-distribution=homebrew os-version=13.4
# solver builtin-mccs+glpk
# install-criteria -removed,-count[avoid-version,changed],-count[version-lag,request],-count[version-lag,changed],-count[missing-depexts,changed],-changed
# upgrade-criteria -removed,-count[avoid-version,changed],-count[version-lag,solution],-count[missing-depexts,changed],-new
# jobs 7
# repositories 1 (http), 1 (version-controlled) (default repo at 93bb2e67)
# pinned 4 (git)
# current-switch default
# ocaml:native true
# ocaml:native-tools true
# ocaml:native-dynlink true
# ocaml:stubsdir $HOME/.opam/default/lib/ocaml/stublibs:$HOME/.opam/default/lib/ocaml
# ocaml:preinstalled false
# ocaml:compiler 5.0.0
Thank you Hadrien
This happens to me too at work but not at home, and I am suspecting that it has to do with the awful "management" software that my employer has installed on my computer ---- something that "security"-minded professionals like to do in order to impede any software-development-related tasks their colleagues may be undertaking 😆
Do you know if this software intercepts filesystem calls, @jonsterling? Still trying to root cause what the cause might be. In the future if you can reproduce it, opam update --debug will give useful timing information.
Good question @avsm ! I will do my best to find out when i get back to my work machine on Monday. I seem to recall that a lot of time and cpu is spent by both untarring (?) things, and diffing things, but i will get you some real information soon :)
Hello! Thanks for the answers, I'll see if my job has a filtering policy on that part.
Here is a log of opam update --debug (again with $HOME replacing its actual path) :
❯ opam update --debug -R default --switch=default
00:00.103 CLI Parsing CLI version 2.1
00:00.103 GSTATE LOAD-GLOBAL-STATE @ $HOME/.opam
00:00.104 CLIENT UPDATE default
00:00.104 RSTATE LOAD-REPOSITORY-STATE @ $HOME/.opam
00:00.218 CACHE(repository) Loaded $HOME/.opam/repo/state-28AC8B61.cache in 0.114s
00:00.218 RSTATE Cache found
00:00.218 STATE LOAD-SWITCH-STATE @ default
00:00.220 CACHE(installed) Loaded $HOME/.opam/default/.opam-switch/packages/cache in 0.000s
00:00.474 STATE Switch state loaded in 0.256s
<><> Updating package repositories ><><><><><><><><><><><><><><><><><><><><> 🐫
00:00.486 PARALLEL Iterate over 1 task(s) with 3 process(es)
00:00.486 PARALLEL Starting job 0 (worker 1/3): 0
00:00.487 SYSTEM mkdir /private/var/folders/3_/p70gr3m102v436vw19qfjj9r0000gn/T/opam-24571-080aa9
06:43.649 REPOSITORY update default from https://opam.ocaml.org
06:43.649 CURL pull-repo-update
06:43.649 SYSTEM mkdir /private/var/folders/3_/p70gr3m102v436vw19qfjj9r0000gn/T/opam-24571-080aa9/default.new
06:43.650 SYSTEM mkdir /var/folders/3_/p70gr3m102v436vw19qfjj9r0000gn/T/opam-24571-4d3227
06:43.660 PARALLEL Next task in job 0: /usr/local/bin/wget --content-disposition -t 3 -O /private/var/folders/3_/p70gr3m102v436vw19qfjj9r0000gn/T/opam-24571-4d3227/index.tar.gz.part -U opam/2.1.5 -- https://opam.ocaml.org/index.tar.gz
Processing 1/1: [default: http]
06:44.324 PARALLEL Collected task for job 0 (ret:0)
06:44.356 PARALLEL Next task in job 0: /usr/bin/tar xfz /private/var/folders/3_/p70gr3m102v436vw19qfjj9r0000gn/T/opam-24571-4d3227/index.tar.gz -C /private/var/folders/3_/p70gr3m102v436vw19qfjj9r0000gn/T/opam-24571-080aa9/default.new
07:33.623 PARALLEL Collected task for job 0 (ret:0)
07:33.623 SYSTEM rmdir /var/folders/3_/p70gr3m102v436vw19qfjj9r0000gn/T/opam-24571-4d3227
07:33.647 REPO_BACKEND diff: /private/var/folders/3_/p70gr3m102v436vw19qfjj9r0000gn/T/opam-24571-080aa9/{default,default.new}
07:33.649 PARALLEL Next task in job 0: /usr/bin/diff -ruaN default default.new
11:01.630 PARALLEL Collected task for job 0 (ret:1)
11:01.631 SYSTEM rmdir /private/var/folders/3_/p70gr3m102v436vw19qfjj9r0000gn/T/opam-24571-080aa9/default.new
[default] synchronised from https://opam.ocaml.org
11:37.634 REPOSITORY default: applying patch update at /Users/hadren02/.opam/log/patch-24571-2b30c6
11:37.636 PARALLEL Next task in job 0: /usr/local/bin/patch -p1 -i /Users/hadren02/.opam/log/patch-24571-2b30c6
11:42.045 PARALLEL Collected task for job 0 (ret:0)
11:42.045 SYSTEM rm $HOME/.opam/log/patch-24571-2b30c6
11:42.049 SYSTEM rm $HOME/.opam/repo/default.tar.gz.tmp
11:42.052 PARALLEL Next task in job 0: /usr/bin/tar cfz $HOME/.opam/repo/default.tar.gz.tmp -C /private/var/folders/3_/p70gr3m102v436vw19qfjj9r0000gn/T/opam-24571-080aa9 default
Processing 1/1:
15:36.209 PARALLEL Collected task for job 0 (ret:0)
15:36.209 SYSTEM rm $HOME/.opam/repo/default.tar.gz
16:04.754 PARALLEL Job 0 finished
16:04.761 FILE(repos-config) Wrote $HOME/.opam/repo/repos-config in 0.006s
16:04.763 SYSTEM rm $HOME/.opam/repo/state-28AC8B61.cache
16:04.766 CACHE(repository) Writing the repository cache to ~/.opam/repo/state-28AC8B61.cache ...
16:05.279 CACHE(repository) ~/.opam/repo/state-28AC8B61.cache written in 0.515s
Now run 'opam upgrade' to apply any package updates.
16:05.305 SYSTEM rmdir /private/var/folders/3_/p70gr3m102v436vw19qfjj9r0000gn/T/opam-24571-080aa9/default
16:40.196 SYSTEM rmdir /private/var/folders/3_/p70gr3m102v436vw19qfjj9r0000gn/T/opam-24571-080aa9
Hope this helps.
Sorry for the delay; I enclose the output of opam update --debug below.
opam update --debug
00:00.075 CLI Parsing CLI version 2.1
00:00.075 GSTATE LOAD-GLOBAL-STATE @ XXXXX/.opam
00:00.076 CLIENT UPDATE
00:00.076 RSTATE LOAD-REPOSITORY-STATE @ XXXXX/.opam
00:00.140 CACHE(repository) Loaded XXXXX/.opam/repo/state-3AF31D16.cache in 0.058s
00:00.140 RSTATE Cache found
00:00.140 STATE LOAD-SWITCH-STATE @ default
00:00.164 CACHE(installed) Loaded XXXXX/.opam/default/.opam-switch/packages/cache in 0.000s
00:00.380 STATE Switch state loaded in 0.240s
<><> Updating package repositories ><><><><><><><><><><><><><><><><><><><><><><>
00:00.394 PARALLEL Iterate over 1 task(s) with 3 process(es)
00:00.394 PARALLEL Starting job 0 (worker 1/3): 0
00:00.394 SYSTEM mkdir /private/var/folders/sh/d99d9gkj7ts3mw3sgjfm_qb9w0pklv/T/opam-17534-b5e54a
03:23.082 REPOSITORY update default from https://opam.ocaml.org
03:23.082 CURL pull-repo-update
03:23.083 SYSTEM mkdir /private/var/folders/sh/d99d9gkj7ts3mw3sgjfm_qb9w0pklv/T/opam-17534-b5e54a/default.new
03:23.083 SYSTEM mkdir /var/folders/sh/d99d9gkj7ts3mw3sgjfm_qb9w0pklv/T/opam-17534-eb8aa1
03:23.088 PARALLEL Next task in job 0: /opt/homebrew/bin/wget --content-disposition -t 3 -O /private/var/folders/sh/d99d9gkj7ts3mw3sgjfm_qb9w0pklv/T/opam-17534-eb8aa1/index.tar.gz.part -U opam/2.1.4 -- https://opam.ocaml.org/index.tar.gz
Processing 1/1: [default: http]
03:23.810 PARALLEL Collected task for job 0 (ret:0)
03:23.830 PARALLEL Next task in job 0: /usr/bin/tar xfz /private/var/folders/sh/d99d9gkj7ts3mw3sgjfm_qb9w0pklv/T/opam-17534-eb8aa1/index.tar.gz -C /private/var/folders/sh/d99d9gkj7ts3mw3sgjfm_qb9w0pklv/T/opam-17534-b5e54a/default.new
03:36.635 PARALLEL Collected task for job 0 (ret:0)
03:36.635 SYSTEM rmdir /var/folders/sh/d99d9gkj7ts3mw3sgjfm_qb9w0pklv/T/opam-17534-eb8aa1
03:36.646 REPO_BACKEND diff: /private/var/folders/sh/d99d9gkj7ts3mw3sgjfm_qb9w0pklv/T/opam-17534-b5e54a/{default,default.new}
03:36.647 PARALLEL Next task in job 0: /usr/bin/diff -ruaN default default.new
05:11.643 PARALLEL Collected task for job 0 (ret:0)
05:11.645 SYSTEM rm XXXXX/.opam/log/patch-17534-ee03e5
05:11.646 SYSTEM rmdir /private/var/folders/sh/d99d9gkj7ts3mw3sgjfm_qb9w0pklv/T/opam-17534-b5e54a/default.new
05:21.357 REPOSITORY update empty, no validation performed
[default] no changes from https://opam.ocaml.org
05:21.360 REPOSITORY default: applying empty update
05:21.364 PARALLEL Next task in job 0: /usr/bin/tar cfz XXXXX/.opam/repo/default.tar.gz.tmp -C /private/var/folders/sh/d99d9gkj7ts3mw3sgjfm_qb9w0pklv/T/opam-17534-b5e54a default
Processing 1/1:
06:22.305 PARALLEL Collected task for job 0 (ret:0)
06:22.305 SYSTEM rm XXXXX/.opam/repo/default.tar.gz
06:35.676 PARALLEL Job 0 finished
06:35.677 FILE(repos-config) Wrote XXXXX/.opam/repo/repos-config in 0.001s
06:35.677 SYSTEM rm XXXXX/.opam/repo/state-3AF31D16.cache
06:35.678 CACHE(repository) Writing the repository cache to ~/.opam/repo/state-3AF31D16.cache ...
06:35.914 CACHE(repository) ~/.opam/repo/state-3AF31D16.cache written in 0.236s
06:35.966 SYSTEM rmdir /private/var/folders/sh/d99d9gkj7ts3mw3sgjfm_qb9w0pklv/T/opam-17534-b5e54a/default
06:45.571 SYSTEM rmdir /private/var/folders/sh/d99d9gkj7ts3mw3sgjfm_qb9w0pklv/T/opam-17534-b5e54a
Here is an image of the activity monitor on my machine, showing that bsdtar is getting wrecked.