status performance and ... chdir

[Robert Collins]

The nice thing about experiments is you can be staggered by the result.

Executive summary: we should chdir. Lots.

I wrote a trivial C program. It does roughly what _walkdirs_utf8 does.

Here are four timing runs, reading the contents of a mozilla tree:

:!time find ../test-repos/mozilla/ -size 0 -size 1

real    0m0.344s
user    0m0.092s
sys     0m0.236s


:!rm -f readdir && LANG=C CFLAGS="-O1 -g -DCHDIR=0" make readdir && time ./readdir
cc -O1 -g -DCHDIR=0    readdir.c   -o readdir
Count: 5769

real    0m0.686s
user    0m0.212s
sys     0m0.432s

:!rm -f readdir && LANG=C CFLAGS="-O1 -g -DCHDIR=1" make readdir && time ./readdir
cc -O1 -g -DCHDIR=1    readdir.c   -o readdir
Count: 5769

real    0m0.473s
user    0m0.176s
sys     0m0.292s

:!PYTHONPATH=. python -m timeit -s "from bzrlib.osutils import _walkdirs_utf8 as walkdirs" "print len(list(walkdirs('../test-repos/mozilla')))"
10 loops, best of 3: 695 msec per loop

Thats a little hard to read. Heres a summary:
tuned python C extension(no chdir): 695ms
adhoc C program (no chdir)        : 686ms
tuned python C extension(chdir)   : 615ms
adhoc C program (chdir)           : 473ms
find                              : 344ms

Thats right. A large chunk of why ``find`` is so much faster than bzr at
stat is *because we don't chdir*.

The test code is attached, for your... entertainment. In particular my
little C program hasn't been profiled (in the gprof/oprofile sense) *at
all*.

Oh, also some strace data, find and 'readdir' respectively.

:!strace -c find ~/source/baz/test-repos/mozilla/ -size 0 -size 1
Process 4980 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 37.05    0.001425           0     54787           lstat
 23.69    0.000911           0     11592           getdents
 13.75    0.000529           0     17342        13 open
 11.41    0.000439           0     17331           close
  8.16    0.000314           0     11544           fchdir
  5.28    0.000203           0      5770           stat
  0.65    0.000025           0      5787           fstat
  0.00    0.000000           0         3           read
  0.00    0.000000           0        22           mmap
  0.00    0.000000           0         2           mprotect
  0.00    0.000000           0         2           munmap
  0.00    0.000000           0         3           brk
  0.00    0.000000           0         2           ioctl
  0.00    0.000000           0         3         3 access
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         1           uname
  0.00    0.000000           0         1           fcntl
  0.00    0.000000           0         1           arch_prctl
------ ----------- ----------- --------- --------- ----------------
100.00    0.003846                124194        16 total

:!strace -c ./readdir
Count: 5769
Process 4986 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 63.16    0.004200           0     54785           lstat
 25.88    0.001721           0     11592           getdents
  7.25    0.000482           0      5772           open
  2.23    0.000148           0      5772           close
  1.49    0.000099           0      5773           fstat
  0.00    0.000000           0         1           read
  0.00    0.000000           0         1           write
  0.00    0.000000           0         9           mmap
  0.00    0.000000           0         2           mprotect
  0.00    0.000000           0         1           munmap
  0.00    0.000000           0         9           brk
  0.00    0.000000           0         3         3 access
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         1           fcntl
  0.00    0.000000           0         1           arch_prctl
------ ----------- ----------- --------- --------- ----------------
100.00    0.006650                 83723         3 total



-Rob

-- 
GPG key available at: <http://www.robertcollins.net/keys.txt>.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: readdir.c
Type: text/x-csrc
Size: 5610 bytes
Desc: not available
Url : https://lists.ubuntu.com/archives/bazaar/attachments/20080910/821d1616/attachment.c 
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 189 bytes
Desc: This is a digitally signed message part
Url : https://lists.ubuntu.com/archives/bazaar/attachments/20080910/821d1616/attachment.pgp