[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: Performance regression on NFS with new manifest version
|
From: |
Roel Janssen |
|
Subject: |
Re: Performance regression on NFS with new manifest version |
|
Date: |
Fri, 22 Sep 2017 14:09:02 +0200 |
|
User-agent: |
mu4e 0.9.18; emacs 25.2.1 |
Ludovic Courtès writes:
> Hello Roel,
>
> I’m finally going back to this issue…
>
> Roel Janssen <address@hidden> skribis:
>
>> Ludovic Courtès writes:
>>
>>> Hi,
>>>
>>> Roel Janssen <address@hidden> skribis:
>>>
>>>> Ricardo Wurmus writes:
>>>>
>>>>> Hi Roel,
>>>>>
>>>>>> Looking into the manifests ($GENERATION_15/manifest and
>>>>>> $GENERATION_16/manifest), I noticed that generation 15 uses manifest
>>>>>> version 2, and generation 16 uses manifest version 3.
>>>>>>
>>>>>> What has changed, so that it takes a lot longer to run the same command
>>>>>> as before? (this is probably disk-related, because that is a known
>>>>>> cause for trouble on network-mounted stores..)
>>>>>
>>>>> Commit 55b4715fd4c03e46501f123c5c9bc6072edf12a4 bumped the manifest
>>>>> version to 3. The goal was to represent propagated inputs as manifest
>>>>> entries so that we can anticipate conflicts from propagated inputs and
>>>>> refuse to build a profile when there would be conflicts.
>>>>
>>>> Thanks for pointing to that commit. It's much better this way. :-)
>>>>
>>>> So, what makes 'guix package --search-paths' so slow? It doesn't have
>>>> to check for conflicts because that's already done on profile creation
>>>> time. All it has to do is combine the search-path data and output
>>>> that..
>>>
>>> Could it be that you have lots of propagated inputs in your profile
>>> (Python, etc.)? Are you sure (per ‘strace’) that it has to do with file
>>> system accesses?
>>
>> Yes, I have lots of propagated inputs in that profile (R packages..).
>>
>> I haven't checked with strace, but everything else on this machine is
>> fast and plenty (24 cores, 128GB ram). The only troublesome thing is
>> the NFS-mounted store.
>
> I tried to reproduce the problem like this:
>
> --8<---------------cut here---------------start------------->8---
> $ ./pre-inst-env guix package -p foo -i r $(guix package -A '^r-a'|cut -f1)
> guix package: warning: Your Guix installation is 10 days old.
> guix package: warning: Consider running 'guix pull' followed by
> 'guix package -u' to get up-to-date packages and security updates.
>
> The following packages will be installed:
> r 3.4.1 /gnu/store/k0q4b6nq1cdyfh3267nmgkwspf7hv6pb-r-3.4.1
> r-acepack 1.4.1
> /gnu/store/2lnpmwk5n3g2567q0rj1cz2hfwmcaj4v-r-acepack-1.4.1
> r-acsnminer 0.16.8.25
> /gnu/store/dv7mrnh8nm0cga5caqay5hmx4cc5355a-r-acsnminer-0.16.8.25
> r-adaptivesparsity 1.4
> /gnu/store/vkiq4knbqm1rm6hsnbkq4ad0pgdsr653-r-adaptivesparsity-1.4
> r-ade4 1.7-8 /gnu/store/3455karydz6sfn5d78r088f812w5z99y-r-ade4-1.7-8
> r-affy 1.54.0
> /gnu/store/zv5fj0c5gdw27carm7mdvyisdnrnirl9-r-affy-1.54.0
> r-affyio 1.46.0
> /gnu/store/xgd50xlbq6nsjjk628y1n8scf4hwrrd8-r-affyio-1.46.0
> r-annotate 1.54.0
> /gnu/store/qbbwjr7k12ss32d7545pwr31lhg1ng07-r-annotate-1.54.0
> r-annotationdbi 1.38.2
> /gnu/store/vcmxw3plg8yygp58q4crr85710hr9mqk-r-annotationdbi-1.38.2
> r-annotationfilter 1.0.0
> /gnu/store/w2n1lz9051fhchc8v2c6yyq7dv7bsxgh-r-annotationfilter-1.0.0
> r-annotationforge 1.18.1
> /gnu/store/9vmr1lfx4g6v3h85d8jgaqn7cs2by8wy-r-annotationforge-1.18.1
> r-annotationhub 2.8.2
> /gnu/store/xyanxcl5dgj8fq415dr4ihm1prlsrz03-r-annotationhub-2.8.2
> r-ape 4.1 /gnu/store/0cy2kw2vifirbhp399db8lndfkyqgjva-r-ape-4.1
> r-aroma-light 3.6.0
> /gnu/store/rq0xawz5l9nq07cxz9kisk63yxasfcnl-r-aroma-light-3.6.0
> r-assertthat 0.2.0
> /gnu/store/dqq16x94nwkgyrliavf0w6gnhp1vxbha-r-assertthat-0.2.0
> r-auc 0.3.0 /gnu/store/fmzah3jzzy756sh4dir78nb8kcrn25pn-r-auc-0.3.0
>
> [...]
>
> The following environment variable definitions may be needed:
> export PATH="foo/bin${PATH:+:}$PATH"
> export R_LIBS_SITE="foo/site-library/${R_LIBS_SITE:+:}$R_LIBS_SITE"
> address@hidden ~/src/guix$ time ./pre-inst-env guix package --search-paths -p
> foo
> export PATH="foo/bin"
> export R_LIBS_SITE="foo/site-library/"
>
> real 0m0.170s
> user 0m0.107s
> sys 0m0.016s
> address@hidden ~/src/guix$ time ./pre-inst-env guix package --search-paths -p
> foo
> export PATH="foo/bin"
> export R_LIBS_SITE="foo/site-library/"
>
> real 0m0.158s
> user 0m0.097s
> sys 0m0.021s
> address@hidden ~/src/guix$ ./pre-inst-env strace -c guix package
> --search-paths -p foo
> export PATH="foo/bin"
> export R_LIBS_SITE="foo/site-library/"
> % time seconds usecs/call calls errors syscall
> ------ ----------- ----------- --------- --------- ----------------
> 69.68 0.005729 2 3516 3292 stat
> 14.96 0.001230 40 31 1 futex
> 4.14 0.000340 1 271 121 open
> 2.96 0.000243 1 182 mmap
> 2.89 0.000238 2 156 mprotect
> 1.14 0.000094 1 150 close
> 1.06 0.000087 1 110 3 lseek
> 0.91 0.000075 1 74 read
> 0.63 0.000052 10 5 clone
> 0.46 0.000038 1 28 brk
> 0.28 0.000023 1 46 fstat
> 0.19 0.000016 5 3 pipe2
> 0.18 0.000015 1 16 lstat
> 0.15 0.000012 2 5 1 ioctl
> 0.09 0.000007 1 7 clock_gettime
> 0.07 0.000006 1 7 rt_sigprocmask
> 0.06 0.000005 2 3 write
> 0.06 0.000005 2 3 fcntl
> 0.04 0.000003 2 2 getcwd
> 0.02 0.000002 0 5 rt_sigaction
> 0.02 0.000002 2 1 getrandom
> 0.00 0.000000 0 2 munmap
> 0.00 0.000000 0 2 2 access
> 0.00 0.000000 0 1 execve
> 0.00 0.000000 0 1 uname
> 0.00 0.000000 0 1 readlink
> 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 prlimit64
> ------ ----------- ----------- --------- --------- ----------------
> 100.00 0.008222 4636 3420 total
> --8<---------------cut here---------------end--------------->8---
>
> Everything looks OK here, but it could be that I did not pick the right
> set of packages to reproduce the problem.
>
> Could you come up with a simple way for me to reproduce it?
>
> TIA!
>
> Ludo’.
I couldn't install *all* R packages, but I used it on our shared R
profile:
$ guixr package --list-installed -p /gnu/profiles/per-language/r
ncurses 6.0 out /gnu/store/djvxj8r1xwvrm89xqjrd44wwaxc02i74-ncurses-6.0
coreutils 8.27 out
/gnu/store/ps92fz5p6l3mz9ddi388p1891r2q3fva-coreutils-8.27
grep 3.0 out /gnu/store/bxnxmg6vamnlp95skrgdqw7s86ag1f51-grep-3.0
sed 4.4 out /gnu/store/673v5pxadfdj1zkmpm90s6j89367w4af-sed-4.4
r-sparql 1.16 out
/gnu/store/5qhr4va0af65a0jrpj6nc7xdnw9s4345-r-sparql-1.16
r-blob 1.1.0 out /gnu/store/g17llpsbppkq7bkdibfmfkna9hdssfbv-r-blob-1.1.0
r-dexseq 1.22.0 out
/gnu/store/hsc2pgcz51sf3sq1n7yl7jwhpnz7jg5n-r-dexseq-1.22.0
r-ripseeker 1.14.0 out
/gnu/store/sh5q8r0v05r854i9p62prpgiw08q60n7-r-ripseeker-1.14.0
r-bsgenome-celegans-ucsc-ce10 1.4.0 out
/gnu/store/bmgapxyiqldlq4xa0a5sfariay6swa1h-r-bsgenome-celegans-ucsc-ce10-1.4.0
r-bsgenome-hsapiens-ucsc-hg19 1.4.0 out
/gnu/store/dq28v4mncd8a5rqnc5f3lq3lrmas1p8m-r-bsgenome-hsapiens-ucsc-hg19-1.4.0
r-bsgenome-hsapiens-1000genomes-hs37d5 0.99.1 out
/gnu/store/smv43q5p0fgiy1kyz9yaiw01q6zz5c9n-r-bsgenome-hsapiens-1000genomes-hs37d5-0.99.1
r-bsgenome-mmusculus-ucsc-mm10 1.4.0 out
/gnu/store/95k6r8c7sz66z51hc0x059fv7090qk1d-r-bsgenome-mmusculus-ucsc-mm10-1.4.0
r-qdnaseq 1.10.0 out
/gnu/store/7r9wazsllnflgpwbcwkcpb1wgl5vpvvv-r-qdnaseq-1.10.0
r-pracma 2.0.7 out
/gnu/store/ikwdwfqp9hf35iwc31bp9mswwnzyjs05-r-pracma-2.0.7
r-biomart 2.32.1 out
/gnu/store/5r3nwc4nawh4ldr5inrbys11cprbg442-r-biomart-2.32.1
r-rngtools 1.2.4 out
/gnu/store/4awn9jy8yp8xr0ma7izsww4b4i6av4yv-r-rngtools-1.2.4
r-pkgmaker 0.22 out
/gnu/store/mjfrgggip6jl4bx6i6ypbgqvbab91l50-r-pkgmaker-0.22
r-gridextra 2.3 out
/gnu/store/s618pfbmzcv405s730namha638ynpf8p-r-gridextra-2.3
r 3.4.1 out /gnu/store/2a8igkn9f5n4ag8ym9ysrmki2msnifyn-r-3.4.1
r-biocviews 1.44.0 out
/gnu/store/0cwz2zyj6h4pv7mhi26sx8r7p2xyj5zz-r-biocviews-1.44.0
r-bioccheck 1.12.0 out
/gnu/store/6d3wwas1xzs9g3msdilacy7xisj39dc0-r-bioccheck-1.12.0
r-ggplot2 2.2.1 out
/gnu/store/0v9g3p95scbq1wm0qvpv24d0308l78cm-r-ggplot2-2.2.1
r-gplots 3.0.1 out
/gnu/store/jba92jjlzq7xgvw4ac5n5lyr8k224k0v-r-gplots-3.0.1
r-pastecs 1.3-18 out
/gnu/store/0fb5329ipb76ggfj10csv4d3p3af81yn-r-pastecs-1.3-18
r-funcisnp 1.18.0 out
/gnu/store/6667xikkpdqp8cbn9q0v5zrq2s0b7i28-r-funcisnp-1.18.0
r-diffbind 2.2.12 out
/gnu/store/8mc3yl9j5s3brn63r34s3krg4xkdbayl-r-diffbind-2.2.12
r-edger 3.18.0 out
/gnu/store/96wqf9pcw0ikiwqqyx6w952svyv7h0ca-r-edger-3.18.0
r-rbgl 1.52.0 out
/gnu/store/25rkm6fc3abbw7ak77yxks46bd9fmxjd-r-rbgl-1.52.0
r-biocstyle 2.4.1 out
/gnu/store/zj5v2iwrcvm9vczbdpcw0mcr304j8j00-r-biocstyle-2.4.1
r-rcurl 1.95-0.1.2 out
/gnu/store/bk0yriz89j5arhz2qky3757zmpivnn1k-r-rcurl-1.95-0.1.2
r-s4vectors 0.14.3 out
/gnu/store/k41y6gp8sk4p4mfhkpq3yh5di79qap9b-r-s4vectors-0.14.3
r-xvector 0.16.0 out
/gnu/store/7an3mc6qpr9xprcwv944gaq9xn09syk5-r-xvector-0.16.0
r-xml2 1.1.1 out /gnu/store/60zmc0hk9z5shi5s4k3j8yp8vfklw2ik-r-xml2-1.1.1
r-iranges 2.10.2 out
/gnu/store/3hs9r87zsxnaq837rka8bsjm9gv1419p-r-iranges-2.10.2
r-biostrings 2.44.2 out
/gnu/store/rr2j9sf3dg24qy93jzwl84a09mscpw7y-r-biostrings-2.44.2
r-devtools 1.13.3 out
/gnu/store/xi3kjaif2vxk0c1wggraajsblakh5r4l-r-devtools-1.13.3
r-nmf 0.20.6 out /gnu/store/pbp6pk8di5h8rdql8rfmv9kqbd0b03nl-r-nmf-0.20.6
r-reshape2 1.4.2 out
/gnu/store/yd8pngfm523fr8nnpnh27qb4q79zvzzi-r-reshape2-1.4.2
r-variantannotation 1.22.3 out
/gnu/store/nlz40rw5gic8s1zqy8r5xqyg6lv2px0y-r-variantannotation-1.22.3
r-mutationalpatterns 1.2.1 out
/gnu/store/v3654hh4k291q429b0wvfyb7vw7f4ihn-r-mutationalpatterns-1.2.1
r-deseq2 1.16.1 out
/gnu/store/say07f2m9ixb6lvp7hqpy1yfr4nks648-r-deseq2-1.16.1
r-openssl 0.9.7 out
/gnu/store/qn7qn0dp5ff8bf2649g8s9i32pjlrfgh-r-openssl-0.9.7
r-curl 2.8.1 out /gnu/store/fwyfhhyn253vqny4yxsc0568l8qcps5c-r-curl-2.8.1
r-git2r 0.19.0 out
/gnu/store/2j74yg2znd6mz059mw0lv15wpjr7i13j-r-git2r-0.19.0
r-jsonlite 1.5 out
/gnu/store/004h1v4wy3hvjqms0bm8x114qmk1dl0b-r-jsonlite-1.5
r-rcpp 0.12.12 out
/gnu/store/fgm16p6pyxyjswzzh0xcaqzln7bilw86-r-rcpp-0.12.12
r-mime 0.5 out /gnu/store/ba5nx5mx4ji0mfdv4g8l40fjbcjjgi8m-r-mime-0.5
r-plyr 1.8.4 out /gnu/store/5dyby97wd6lg2n04gndcn0k7rm30k8fp-r-plyr-1.8.4
r-ggdendro 0.1-20 out
/gnu/store/lfj04k9p2hnma733qib54vapv0whrgbp-r-ggdendro-0.1-20
r-cowplot 0.8.0 out
/gnu/store/5y1f266cf9lfd7a8vk2in190fmz1j90m-r-cowplot-0.8.0
r-testthat 1.0.2 out
/gnu/store/02fp185nf106c5i4pz9jmkx7j8kkpxx1-r-testthat-1.0.2
r-bit64 0.9-7 out
/gnu/store/f7fpax2g3pniv5n6y3ysm50kmyskr0a2-r-bit64-0.9-7
r-rlang 0.1.2 out
/gnu/store/gvhx5rsd13fv30n7wfiwclrrhirzdwgw-r-rlang-0.1.2
r-biocinstaller 1.26.0 out
/gnu/store/pizcmi2k44v4vsk8m0bb4hh6n2qrw6fs-r-biocinstaller-1.26.0
r-motifbreakr 1.6.0 out
/gnu/store/cic9h7rdkk5w8810khna32bf5kjlpzl4-r-motifbreakr-1.6.0
Here's my timings:
$ time guixr package --search-paths -p /gnu/profiles/per-language/r
export PATH="/gnu/profiles/per-language/r/bin"
export R_LIBS_SITE="/gnu/profiles/per-language/r/site-library/"
export TERMINFO_DIRS="/gnu/profiles/per-language/r/share/terminfo"
real 1m3.771s
user 1m3.745s
sys 0m0.145
And the strace:
$ strace -c guixr package --search-paths -p /gnu/profiles/per-language/r
export PATH="/gnu/profiles/per-language/r/bin"
export R_LIBS_SITE="/gnu/profiles/per-language/r/site-library/"
export TERMINFO_DIRS="/gnu/profiles/per-language/r/share/terminfo"
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
98.31 0.139510 11626 12 6 wait4
0.77 0.001087 36 30 9 open
0.43 0.000615 21 29 8 stat
0.10 0.000144 24 6 clone
0.07 0.000095 5 19 mmap
0.05 0.000076 4 21 read
0.05 0.000064 2 26 close
0.04 0.000058 3 20 fstat
0.03 0.000049 5 9 1 access
0.03 0.000045 45 1 lstat
0.03 0.000039 1 48 rt_sigprocmask
0.02 0.000028 5 6 mprotect
0.01 0.000013 0 28 rt_sigaction
0.01 0.000008 2 4 lseek
0.01 0.000008 2 5 brk
0.01 0.000008 1 9 getuid
0.01 0.000008 1 9 getgid
0.01 0.000008 1 9 geteuid
0.01 0.000008 1 9 getegid
0.00 0.000007 1 6 rt_sigreturn
0.00 0.000007 1 8 1 fcntl
0.00 0.000005 3 2 pipe
0.00 0.000005 5 1 execve
0.00 0.000003 1 4 3 ioctl
0.00 0.000003 1 3 dup2
0.00 0.000003 3 1 arch_prctl
0.00 0.000002 1 2 prlimit64
0.00 0.000000 0 1 write
0.00 0.000000 0 2 getpid
0.00 0.000000 0 1 uname
0.00 0.000000 0 1 sysinfo
0.00 0.000000 0 1 getppid
0.00 0.000000 0 1 getpgrp
0.00 0.000000 0 1 faccessat
------ ----------- ----------- --------- --------- ----------------
100.00 0.141906 335 28 total
I don't understand why the numbers are so low on my end.
Note, this is /gnu served over NFS. We recently upgraded to SSDs in our
storage system, which caused reads to be faster. In the case of the
--search-paths, it is still very slow.
Kind regards,
Roel Janssen