Hello! Ludovic Courtès writes:
> Hello! > > I just pushed another improvement: > d27cc3bfaafe6b5b0831e88afb1c46311d382a0b significantly reduces the > number of ‘stat’ calls when discovering .scm files. I’d be curious to > see what impact it has on NFS. > > Commit cbee955901b3e252ebdeb8066a2196055149198a also reduces the number > of ‘stat’ calls. > > After that I have: > > --8<---------------cut here---------------start------------->8--- > $ ./pre-inst-env strace -c guix environment --ad-hoc coreutils -- true > % time seconds usecs/call calls errors syscall > ------ ----------- ----------- --------- --------- ---------------- > 27.03 0.006916 1 13585 read > 24.64 0.006306 1 9701 8029 stat > 21.25 0.005438 1 10698 write > 11.05 0.002828 2828 1 wait4 > 3.60 0.000922 1 1598 122 open > 2.88 0.000738 4 203 28 futex > 1.79 0.000458 1 670 mmap > 1.75 0.000448 1 642 mprotect > 1.64 0.000419 0 1476 close > 1.36 0.000347 0 1411 3 lseek > 0.74 0.000190 2 107 sendfile > 0.70 0.000180 4 51 getdents > 0.62 0.000159 0 886 fstat > 0.54 0.000137 1 196 lstat > 0.22 0.000057 1 99 brk > 0.09 0.000024 4 6 clone > 0.02 0.000005 1 5 munmap > 0.02 0.000005 0 19 rt_sigprocmask > 0.02 0.000004 0 27 clock_gettime > 0.01 0.000003 3 1 getrandom > 0.01 0.000002 2 1 connect > 0.01 0.000002 1 3 prlimit64 > 0.00 0.000001 1 2 2 access > 0.00 0.000001 1 1 socket > 0.00 0.000000 0 5 rt_sigaction > 0.00 0.000000 0 7 1 ioctl > 0.00 0.000000 0 1 madvise > 0.00 0.000000 0 1 execve > 0.00 0.000000 0 1 uname > 0.00 0.000000 0 3 fcntl > 0.00 0.000000 0 1 getcwd > 0.00 0.000000 0 1 statfs > 0.00 0.000000 0 1 arch_prctl > 0.00 0.000000 0 2 sched_getaffinity > 0.00 0.000000 0 1 set_tid_address > 0.00 0.000000 0 1 set_robust_list > 0.00 0.000000 0 3 pipe2 > ------ ----------- ----------- --------- --------- ---------------- > 100.00 0.025590 41417 8185 total > $ git describe > v0.13.0-804-gf4453df9a > --8<---------------cut here---------------end--------------->8--- > > The number of ‘stat’ calls is a function of the number of entries in > ‘GUILE_LOAD_PATH’ and ‘GUILE_LOAD_COMPILED_PATH’. I can’t think of any > easy way to reduce it further. > > The many ‘read’ and ‘write’ are due to the unbuffered port used for > RPCs, and definitely not great when talking to a remote store. I’ve > tried to add some buffering but that turned out to be trickier than I > had hoped for. > > To be continued! > > Ludo’. I applied the patch, and here are the results: [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure -- true The following derivations will be built: /gnu/store/0hz8g844432b5h9zbqr9cpsjy0brg15h-profile.drv /gnu/store/wkksb7bbx3jr0p6p5cj4kkphbwday0yd-info-dir.drv /gnu/store/cd2mwx9qprdy23p7j3pik2zs14nifn36-manual-database.drv Creating manual page database for 1 packages... done in 1.816 s real 1m14.686s user 0m5.761s sys 0m0.498s [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure -- true real 0m34.100s user 0m5.599s sys 0m0.414s [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure -- true real 0m33.821s user 0m5.140s sys 0m0.432s [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes --no-grafts -- true The following derivations will be built: /gnu/store/rvh0imjdimwm90nzr0fmr5gmp97lyiix-profile.drv /gnu/store/5hm3v4afjf9gix92ixqzv9bwc11a608s-fonts-dir.drv real 0m37.200s user 0m3.408s sys 0m0.284s [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes --no-grafts -- true real 0m19.415s user 0m3.466s sys 0m0.306s [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes --no-grafts -- true real 0m18.850s user 0m3.536s sys 0m0.346s [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-grafts -- true real 0m16.003s user 0m3.246s sys 0m0.301s [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-grafts -- true real 0m18.205s user 0m3.470s sys 0m0.314s [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes -- true real 0m33.731s user 0m5.111s sys 0m0.428s [roel@hpcguix guix]$ time guixr environment --ad-hoc coreutils --pure --no-substitutes -- true real 0m30.993s user 0m5.049s sys 0m0.458s Why is grafting so slow, even if it doesn't have to graft anything? So, because grafting is disk-intensive rather than CPU-intensive, it might be a good idea to be able to globally disable grafting. (it would reduce the after-we-build-it-time considerably for our cluster.) Kind regards, Roel Janssen
