From mboxrd@z Thu Jan 1 00:00:00 1970 From: ludovic.courtes@inria.fr (Ludovic =?utf-8?Q?Court=C3=A8s?=) Subject: Re: Performance on NFS Date: Fri, 09 Jun 2017 15:46:44 +0200 Message-ID: <87a85hnvqm.fsf@gnu.org> References: <20170527105641.9426-1-mail@cbaines.net> <20170527123113.1ca668e7@cbaines.net> <87tw424cap.fsf@gnu.org> <87fufhkw85.fsf@gnu.org> <871sr0ok2h.fsf@gnu.org> <8760gbh2th.fsf@gnu.org> <87efuym57c.fsf@gnu.org> <87a85kt7ad.fsf_-_@gnu.org> Mime-Version: 1.0 Content-Type: multipart/mixed; boundary="=-=-=" Return-path: Received: from eggs.gnu.org ([2001:4830:134:3::10]:37877) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1dJKFW-0008PX-VV for guix-devel@gnu.org; Fri, 09 Jun 2017 09:46:52 -0400 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1dJKFT-0003Hk-0Z for guix-devel@gnu.org; Fri, 09 Jun 2017 09:46:51 -0400 In-Reply-To: (Roel Janssen's message of "Wed, 07 Jun 2017 15:06:07 +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@gnu.org, 27097@debbugs.gnu.org --=-=-= Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Hi Roel, Roel Janssen skribis: > You should know that we have 'submit' nodes that use the guixr wrapper > script to connect to the guix-daemon that runs on the 'hpcguix' node. > > Both have a /gnu mounted by a storage subsystem. > > I couldn't run the second command on a 'submit' node. But I could run > it in the 'hpcguix' node. OK. Side note: I think you can replace your =E2=80=98guixr=E2=80=99 wrapper by = just doing: export GUIX_DAEMON_SOCKET=3Dguix://hpcguix:1234 See . > The first command: > ------------------ > > [roel@hpc-submit1 ~]$ time guixr environment --ad-hoc coreutils --pure --= true > > real 0m38.415s > user 0m6.075s > sys 0m0.611s > > [roel@hpcguix ~]$ time guix environment --ad-hoc coreutils --pure -- true > > real 0m27.054s > user 0m4.254s > sys 0m0.383s > > > The second command: > ------------------- > > [roel@hpcguix ~]$ time guix environment --ad-hoc -e '(@ (gnu packages bas= e) coreutils)' --pure --no-substitutes --no-grafts -- true=20=20=20=20=20= =20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20= =20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20= =20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20= =20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20=20 > The following derivations will be built: > /gnu/store/9wczighnyz1bz43j4wawf09z180g3ywv-profile.drv > /gnu/store/ffsyhajbdcp1lcq6x65czghya1iydly8-info-dir.drv > /gnu/store/5gyl3l23ps6f8dgay4awybwq7n9j9pzk-fonts-dir.drv > /gnu/store/l2mwj2q4vnq2v5raxz64ra7jyphd2jyd-manual-database.drv > Creating manual page database for 1 packages... done in 5.524 s > > real 1m6.812s > user 0m2.969s > sys 0m0.325s > [roel@hpcguix ~]$ time guix environment --ad-hoc -e '(@ (gnu packages bas= e) coreutils)' --pure --no-substitutes --no-grafts -- true > > real 0m23.357s > user 0m2.802s > sys 0m0.340s > > > I suspect that the difference between the two commands is that one only > looks for one module, while the other looks in all modules. Looking at > the second run, I suppose the difference is quite small. Yeah, -e doesn=E2=80=99t seem to be much faster (there are still a lot of modules to load anyway.) At any rate, let=E2=80=99s see what we can do; 23 seconds is not okay. I did a quick experiment: --8<---------------cut here---------------start------------->8--- $ strace -o ,,s -s 123 guix environment --ad-hoc -e '(@ (gnu packages base)= coreutils)' --pure --no-substitutes --no-grafts -- true $ grep ^open ,,s |wc -l 1095 $ grep '^open.*ENOENT' ,,s |wc -l 136 $ grep -E '^(open|stat|lstat).*patches/gcc-arm-bug' ,,s |wc -l 27 $ grep -E '^(open|stat|lstat).*guix/build/utils' ,,s |wc -l 2190 --8<---------------cut here---------------end--------------->8--- After the patch below, I get: --8<---------------cut here---------------start------------->8--- $ grep -E '^(open|stat|lstat).*guix/build/utils' ,,s2 |wc -l 14 $ grep -E '^(open|stat|lstat).*patches/gcc-arm-bug' ,,s2 |wc -l 4 --8<---------------cut here---------------end--------------->8--- Here=E2=80=99s the big picture before and after: --8<---------------cut here---------------start------------->8--- $ strace -c guix environment --ad-hoc -e '(@ (gnu packages base) coreutils)= ' --pure --no-substitutes --no-grafts -- true % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 32.55 0.009781 1 10463 9158 stat 15.55 0.004673 1 8780 write 11.26 0.003385 3385 1 wait4 7.94 0.002387 20 122 12 futex 6.38 0.001917 0 5052 4 lstat 5.70 0.001713 2 1095 136 open 5.54 0.001664 1 2919 read 3.02 0.000909 2 525 mmap 2.96 0.000889 148 6 clone 2.50 0.000751 2 481 mprotect 2.00 0.000600 1 959 close 1.56 0.000469 1 898 3 lseek 1.10 0.000330 3 100 sendfile 0.88 0.000264 0 541 fstat 0.42 0.000127 1 175 brk 0.15 0.000044 2 22 rt_sigaction 0.09 0.000026 5 5 munmap 0.06 0.000019 1 18 rt_sigprocmask 0.06 0.000019 2 10 3 ioctl 0.03 0.000010 3 3 3 access 0.03 0.000010 2 6 1 fcntl 0.03 0.000009 0 23 clock_gettime 0.03 0.000008 2 5 prlimit64 0.02 0.000006 6 1 statfs 0.02 0.000005 2 3 pipe2 0.01 0.000004 2 2 getpid 0.01 0.000004 4 1 sysinfo 0.01 0.000003 3 1 dup2 0.01 0.000003 2 2 arch_prctl 0.01 0.000003 3 1 set_tid_address 0.01 0.000002 1 2 execve 0.01 0.000002 1 2 uname 0.01 0.000002 2 1 getuid 0.01 0.000002 2 1 getgid 0.01 0.000002 2 1 geteuid 0.01 0.000002 2 1 getegid 0.01 0.000002 2 1 getppid 0.01 0.000002 2 1 getpgrp 0.01 0.000002 2 1 set_robust_list 0.00 0.000001 0 16 readlink 0.00 0.000000 0 3 madvise 0.00 0.000000 0 1 socket 0.00 0.000000 0 1 connect 0.00 0.000000 0 1 getcwd 0.00 0.000000 0 2 sched_getaffinity 0.00 0.000000 0 1 getrandom ------ ----------- ----------- --------- --------- ---------------- 100.00 0.030051 32256 9320 total $ ./pre-inst-env strace -c guix environment --ad-hoc -e '(@ (gnu packages b= ase) coreutils)' --pure --no-substitutes --no-grafts -- true % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 35.19 0.004311 0 9423 8117 stat 25.25 0.003094 0 8780 write 9.99 0.001224 0 2895 read 7.88 0.000965 1 1062 122 open 6.39 0.000783 7 117 10 futex 3.80 0.000466 1 502 mmap 3.34 0.000409 1 474 mprotect 2.91 0.000357 0 940 close 2.14 0.000262 0 900 3 lseek 1.90 0.000233 0 518 fstat 0.59 0.000072 1 100 sendfile 0.26 0.000032 0 123 lstat 0.20 0.000025 0 78 brk 0.04 0.000005 0 23 clock_gettime 0.02 0.000003 1 5 munmap 0.02 0.000003 1 6 clone 0.02 0.000002 0 5 rt_sigaction 0.02 0.000002 0 15 rt_sigprocmask 0.01 0.000001 1 1 wait4 0.01 0.000001 1 1 arch_prctl 0.01 0.000001 1 2 sched_getaffinity 0.01 0.000001 0 3 prlimit64 0.00 0.000000 0 7 1 ioctl 0.00 0.000000 0 2 2 access 0.00 0.000000 0 1 madvise 0.00 0.000000 0 1 socket 0.00 0.000000 0 1 connect 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 set_tid_address 0.00 0.000000 0 1 set_robust_list 0.00 0.000000 0 3 pipe2 0.00 0.000000 0 1 getrandom ------ ----------- ----------- --------- --------- ---------------- 100.00 0.012252 25998 8255 total --8<---------------cut here---------------end--------------->8--- So that=E2=80=99s shaving ~20% of the syscalls (notice the number of =E2=80= =98lstat=E2=80=99 calls), which may make a difference on NFS. Could you give it a try and report back? This patch optimizes the =E2=80=98add-to-store=E2=80=99 on the client side.= Until now the caching strategy in =E2=80=98add-to-store=E2=80=99 was very conservativ= e: at each call it would =E2=80=98lstat=E2=80=99 the given file and use the stat as a = key in caching. Thus, if the file changed, we would notice and reopen it. The obvious downside is that we=E2=80=99d keep doing =E2=80=98lstat=E2=80= =99 for a case that=E2=80=99s unlikely. With this patch, we simply use the file name as the key in the =E2=80=98add-to-store=E2=80=99 cache. Though as you wrote before, =E2=80=98open=E2=80=99 is much more expensive t= hat =E2=80=98stat=E2=80=99 on NFS, so that=E2=80=99s where we should focus. Thanks, Ludo=E2=80=99. --=-=-= Content-Type: text/x-patch Content-Disposition: inline diff --git a/guix/store.scm b/guix/store.scm index c94dfea95..8acde18d0 100644 --- a/guix/store.scm +++ b/guix/store.scm @@ -830,10 +830,9 @@ bits are kept. HASH-ALGO must be a string such as \"sha256\". When RECURSIVE? is true, call (SELECT? FILE STAT) for each directory entry, where FILE is the entry's absolute file name and STAT is the result of 'lstat'; exclude entries for which SELECT? does not return true." - (let* ((st (false-if-exception (lstat file-name))) - (args `(,st ,basename ,recursive? ,hash-algo ,select?)) + (let* ((args `(,file-name ,basename ,recursive? ,hash-algo ,select?)) (cache (nix-server-add-to-store-cache server))) - (or (and st (hash-ref cache args)) + (or (hash-ref cache args) (let ((path (add-to-store server basename recursive? hash-algo file-name #:select? select?))) --=-=-=--