From mboxrd@z Thu Jan 1 00:00:00 1970 From: ludo@gnu.org (Ludovic =?utf-8?Q?Court=C3=A8s?=) Subject: Re: Performance regression on NFS with new manifest version Date: Fri, 22 Sep 2017 11:55:26 +0200 Message-ID: <87377fukfl.fsf@gnu.org> References: <873790o4q1.fsf@elephly.net> <87mv6ssyy0.fsf@gnu.org> Mime-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Return-path: Received: from eggs.gnu.org ([2001:4830:134:3::10]:44594) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1dvKgH-0006j5-Lw for guix-devel@gnu.org; Fri, 22 Sep 2017 05:55:35 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1dvKgD-00069g-Ku for guix-devel@gnu.org; Fri, 22 Sep 2017 05:55:33 -0400 In-Reply-To: (Roel Janssen's message of "Tue, 22 Aug 2017 17:32:41 +0200") List-Id: "Development of GNU Guix and the GNU System distribution." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: guix-devel-bounces+gcggd-guix-devel=m.gmane.org@gnu.org Sender: "Guix-devel" To: Roel Janssen Cc: guix-devel Hello Roel, I=E2=80=99m finally going back to this issue=E2=80=A6 Roel Janssen skribis: > Ludovic Court=C3=A8s writes: > >> Hi, >> >> Roel Janssen 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 comma= nd >>>>> 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 =E2=80=98strace=E2=80=99) 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-acsn= miner-0.16.8.25 r-adaptivesparsity 1.4 /gnu/store/vkiq4knbqm1rm6hsnbkq4ad0pgdsr653-r-ada= ptivesparsity-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.4= 6.0 r-annotate 1.54.0 /gnu/store/qbbwjr7k12ss32d7545pwr31lhg1ng07-r-annotate= -1.54.0 r-annotationdbi 1.38.2 /gnu/store/vcmxw3plg8yygp58q4crr85710hr9mqk-r-ann= otationdbi-1.38.2 r-annotationfilter 1.0.0 /gnu/store/w2n1lz9051fhchc8v2c6yyq7dv7bsxgh-r-a= nnotationfilter-1.0.0 r-annotationforge 1.18.1 /gnu/store/9vmr1lfx4g6v3h85d8jgaqn7cs2by8wy-r-a= nnotationforge-1.18.1 r-annotationhub 2.8.2 /gnu/store/xyanxcl5dgj8fq415dr4ihm1prlsrz03-r-anno= tationhub-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-assertt= hat-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=3D"foo/bin${PATH:+:}$PATH" export R_LIBS_SITE=3D"foo/site-library/${R_LIBS_SITE:+:}$R_LIBS_SITE" ludo@ribbon ~/src/guix$ time ./pre-inst-env guix package --search-paths -p = foo export PATH=3D"foo/bin" export R_LIBS_SITE=3D"foo/site-library/" real 0m0.170s user 0m0.107s sys 0m0.016s ludo@ribbon ~/src/guix$ time ./pre-inst-env guix package --search-paths -p = foo export PATH=3D"foo/bin" export R_LIBS_SITE=3D"foo/site-library/" real 0m0.158s user 0m0.097s sys 0m0.021s ludo@ribbon ~/src/guix$ ./pre-inst-env strace -c guix package --search-path= s -p foo export PATH=3D"foo/bin" export R_LIBS_SITE=3D"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=E2=80=99.