Hi,
(Colin, something for you near the end; search ‘interesting’.)
Eli wrote:
> Dirk wrote:
> > $ find /usr/share/man -type f -exec bzgrep -l RLIMIT_NOFILE {} \;
...
> > find... man -K...
> >
> > real 107.45 real 96.34
> > user 117.06 user 70.11
> > sys 14.43 sys 26.86
...
> > $ time -p find /usr/share/man -type f | xargs bzgrep -l RLIMIT_NOFILE
...
> > real 24.30
> > user 32.34
> > sys 6.84
>
> Multiprocessing, obviously. Your CPU has more than one execution
> unit, so the pipe via xargs runs 'find' and 'bzgrep' in parallel on
> two different execution units. By contrast, "find -exec" runs them
> sequentially, in a single thread.
No, I don't think it's that.
With the first, find(1) does stop whilst waiting for bzgrep to grep a
single file. bzgrep may or may not run on the same core. The important
thing is the one bzgrep per file and its fork() and exec() overhead.
The second has find fill a pipe's buffer with paths and when that's
full, xargs's read can return. This continues until xargs either reads
end-of-file or reaches the argv[] limits. It then runs a single bzgrep
with many filenames. The fork+exec overhead is much reduced.
bzgrep is a shell script and has overhead before it gets to the
argument-processing loop. That overhead is suffered many times if
bzgrep is run once per file.
The *zgrep scripts are a poor option in general due to this
one-grep-per-file overhead. Better than nothing, but a grep which can
internally decompress all the different compression formats avoids this
shell overhead.
Here is an example. 260 files causes eight times as many clone(2)s,
i.e. forks. I've added an extra ‘×...’ column. The ls and xargs will
complete their work nearly instantly. All the wall-clock time is the
single run of zgrep.
$ pwd
/usr/share/man/man7
$ ls *.gz | wc -l
260
$
$ ls *.gz | LC_ALL=C strace -fc xargs -rd\\n zgrep -H not-to-be-found
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- ------ ----------------
93.70 27.510039 7555 3641 ×14 1560 wait4
0.85 0.248763 26 9389 mmap
0.68 0.198674 11 17166 rt_sigprocmask
0.56 0.165702 35 4691 mprotect
0.52 0.153146 6 22637 rt_sigaction
0.50 0.146029 21 6780 read
0.43 0.125451 10 12235 1040 close
0.31 0.091715 29 3132 openat
0.25 0.073542 11 6513 522 fcntl
0.24 0.070822 12 5728 2080 stat
0.23 0.068825 16 4171 fstat
0.20 0.057703 24 2348 brk
0.19 0.054838 69 786 4 execve
0.18 0.052849 25 2081 ×8 clone
0.17 0.051089 17 2862 782 access
0.15 0.043284 55 782 munmap
0.14 0.040012 48 819 write
0.11 0.031992 11 2870 260 lseek
0.11 0.031393 8 3902 dup2
0.08 0.023038 22 1041 pipe
0.07 0.021190 13 1560 rt_sigreturn
0.06 0.018363 11 1564 782 arch_prctl
0.05 0.016013 7 2081 ×8 getgid
0.05 0.015314 7 2081 ×8 getegid
0.05 0.015251 7 2081 ×8 getuid
0.05 0.014780 7 2081 ×8 geteuid
0.02 0.004703 18 260 ×1 sigaltstack
0.01 0.003685 13 264 ×1 prlimit64
0.01 0.003523 1 2084 ×8 getpid
0.01 0.003443 13 260 ×1 set_tid_address
0.01 0.003425 13 260 ×1 set_robust_list
0.00 0.000094 23 4 getdents64
0.00 0.000053 17 3 2 ioctl
0.00 0.000033 16 2 poll
0.00 0.000018 18 1 sysinfo
0.00 0.000014 14 1 getppid
0.00 0.000013 13 1 uname
0.00 0.000013 13 1 getpgrp
------ ----------- ----------- --------- --------- ----------------
100.00 29.358834 128163 7032 total
Compare with running sh(1) to run zcat and grep on each bunch of xargs's files.
$ ls *.gz | LC_ALL=C strace -fc sh -c 'xargs -rd\\n zcat | grep not-to-be-found'
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- ------ ----------------
82.18 0.150049 37512 4 1 wait4
5.92 0.010814 12 881 read
2.25 0.004116 14 286 ×1 openat
2.17 0.003966 13 299 ×1 write
1.33 0.002432 8 301 ×1 2 close
1.24 0.002263 30 74 mmap
1.19 0.002166 7 285 ×1 fstat
0.58 0.001060 17 62 16 stat
0.52 0.000954 34 28 mprotect
0.42 0.000766 12 63 rt_sigaction
0.35 0.000642 27 23 6 access
0.30 0.000543 24 22 rt_sigprocmask
0.19 0.000346 17 20 1 lseek
0.17 0.000310 62 5 munmap
0.14 0.000250 13 18 getuid
0.13 0.000242 18 13 4 ioctl
0.13 0.000238 13 18 getegid
0.13 0.000236 13 18 geteuid
0.11 0.000204 11 18 brk
0.11 0.000199 11 18 getgid
0.06 0.000116 11 10 5 arch_prctl
0.06 0.000106 9 11 1 fcntl
0.05 0.000083 10 8 getpid
0.04 0.000082 13 6 prlimit64
0.04 0.000076 38 2 pipe
0.03 0.000061 20 3 clone
0.03 0.000047 23 2 getpgrp
0.02 0.000044 22 2 sysinfo
0.02 0.000033 3 9 4 execve
0.02 0.000031 10 3 dup2
0.02 0.000030 30 1 set_tid_address
0.01 0.000023 11 2 uname
0.01 0.000022 22 1 set_robust_list
0.01 0.000014 7 2 poll
0.01 0.000014 14 1 rt_sigreturn
0.01 0.000010 5 2 getppid
0.00 0.000007 1 4 getdents64
0.00 0.000000 0 1 sigaltstack
------ ----------- ----------- --------- --------- ----------------
100.00 0.182595 2526 40 total
$
Fifty times fewer system calls. Especially expensive ones.
Now, here's the interesting bit. man here also forks once per file.
Presumably so the child can decompress the file and write to a pipe with
the existing search code in the parent reading from the other end
without caring the file is compressed. Removing the pipe and fork could
speed things up a bit. A function pointer would be one way.
$ LC_ALL=C strace -fc man -Ks7 not-to-be-found
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- ------ ----------------
61.90 1.890948 14 132630 read
32.05 0.979069 1882 520 ×2 260 wait4
1.68 0.051233 98 520 ×2 260 seccomp
0.90 0.027443 13 2096 ×8 close
0.61 0.018720 18 1024 write
0.59 0.017941 17 1040 ×4 rt_sigprocmask
0.53 0.016137 27 585 37 stat
0.49 0.015120 27 551 15 openat
0.26 0.007975 30 260 ×1 pipe
0.15 0.004705 18 260 ×1 clone
0.14 0.004345 16 260 ×1 rt_sigreturn
0.14 0.004254 16 263 ×1 ioctl
0.13 0.003824 14 262 ×1 getpid
0.10 0.003067 1 1573 rt_sigaction
0.08 0.002581 9 273 fstat
0.07 0.002052 3 520 ×2 prctl
0.07 0.002040 7 263 ×1 lseek
0.06 0.001959 7 260 ×1 dup
0.04 0.001115 2 520 ×2 dup2
0.01 0.000204 17 12 brk
0.00 0.000000 0 145 lstat
0.00 0.000000 0 31 mmap
0.00 0.000000 0 12 mprotect
0.00 0.000000 0 1 munmap
0.00 0.000000 0 1 1 access
0.00 0.000000 0 1 execve
0.00 0.000000 0 3 fcntl
0.00 0.000000 0 6 readlink
0.00 0.000000 0 1 umask
0.00 0.000000 0 1 sysinfo
0.00 0.000000 0 1 getuid
0.00 0.000000 0 1 getgid
0.00 0.000000 0 1 geteuid
0.00 0.000000 0 1 getegid
0.00 0.000000 0 3 fstatfs
0.00 0.000000 0 2 1 arch_prctl
0.00 0.000000 0 8 getdents64
------ ----------- ----------- --------- --------- ----------------
100.00 3.054732 143911 574 total
$
--
Cheers, Ralph.
