Re: upload-pack is slow with lots of refs

On Wed, Oct 3, 2012 at 11:20 PM, Jeff King [off-list ref] wrote:

Thanks for all that info, it's really useful.

quoted

 * A co-worker who was working on this today tried it on 1.7.12 and
   claimed that it had the same performance characteristics.

That's surprising to me. Can you try to verify those numbers?

I think he was wrong, I tested this on git.git by first creating a lot
of tags:

     parallel --eta "git tag -a -m"{}" test-again-{}" ::: $(git rev-list HEAD)

Then doing:

    git pack-refs --all
    git repack -A -d

And compiled with -g -O3 I get around 1.55 runs/s of git-upload-pack
on 1.7.8 and 2.59/s on the master branch.

quoted

 * I tried to profile it under gcc -pg && echo -n | ./git-upload-pack
   <repo> but it doesn't produce a profile like that, presumably
   because the process exits unsuccessfully.

If it's a recent version of Linux, you'll get much nicer results with
perf. Here's what my 400K-ref case looks like:

  $ time echo 0000 | perf record git-upload-pack . >/dev/null
  real    0m0.808s
  user    0m0.660s
  sys     0m0.136s

  $ perf report | grep -v ^# | head
  11.40%  git-upload-pack  libc-2.13.so        [.] vfprintf
   9.70%  git-upload-pack  git-upload-pack     [.] find_pack_entry_one
   7.64%  git-upload-pack  git-upload-pack     [.] check_refname_format
   6.81%  git-upload-pack  libc-2.13.so        [.] __memcmp_sse4_1
   5.79%  git-upload-pack  libc-2.13.so        [.] getenv
   4.20%  git-upload-pack  libc-2.13.so        [.] __strlen_sse42
   3.72%  git-upload-pack  git-upload-pack     [.] ref_entry_cmp_sslice
   3.15%  git-upload-pack  git-upload-pack     [.] read_packed_refs
   2.65%  git-upload-pack  git-upload-pack     [.] sha1_to_hex
   2.44%  git-upload-pack  libc-2.13.so        [.] _IO_default_xsputn

FWIW here are my results on the above pathological git.git

    $ uname -r; perf --version; echo 0000 | perf record
./git-upload-pack .>/dev/null; perf report | grep -v ^# | head
    3.2.0-2-amd64
    perf version 3.2.17
    [ perf record: Woken up 1 times to write data ]
    [ perf record: Captured and wrote 0.026 MB perf.data (~1131 samples) ]
        29.08%  git-upload-pack  libz.so.1.2.7       [.] inflate
        17.99%  git-upload-pack  libz.so.1.2.7       [.] 0xaec1
         6.21%  git-upload-pack  libc-2.13.so        [.] 0x117503
         5.69%  git-upload-pack  libcrypto.so.1.0.0  [.] 0x82c3d
         4.87%  git-upload-pack  git-upload-pack     [.] find_pack_entry_one
         3.18%  git-upload-pack  ld-2.13.so          [.] 0x886e
         2.96%  git-upload-pack  libc-2.13.so        [.] vfprintf
         2.83%  git-upload-pack  git-upload-pack     [.] search_for_subdir
         1.56%  git-upload-pack  [kernel.kallsyms]   [k] do_raw_spin_lock
         1.36%  git-upload-pack  libc-2.13.so        [.] vsnprintf

I wonder why your report doesn't note any time in libz. This is on
Debian testing, maybe your OS uses different strip settings so it
doesn't show up?

    $ ldd -r ./git-upload-pack
            linux-vdso.so.1 =>  (0x00007fff621ff000)
            libz.so.1 => /lib/x86_64-linux-gnu/libz.so.1 (0x00007f768feee000)
            libcrypto.so.1.0.0 =>
/usr/lib/x86_64-linux-gnu/libcrypto.so.1.0.0 (0x00007f768fb0a000)
            libpthread.so.0 => /lib/x86_64-linux-gnu/libpthread.so.0
(0x00007f768f8ed000)
            libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007f768f566000)
            libdl.so.2 => /lib/x86_64-linux-gnu/libdl.so.2 (0x00007f768f362000)
            /lib64/ld-linux-x86-64.so.2 (0x00007f7690117000