Re: Debugging git-commit slowness on a large repo

I've managed to speed up git-commit on large repos by 4x by removing some
safeguards that caused git to stat every file in the repo on commits that
touch a small number of files.  The diff, for illustrative purposes only,
is at:

    https://gist.github.com/1499621


With a repo with 1 million files (but few commits), the diff drops the
commit time down from 7.3 seconds to 1.8 seconds, a 75% decrease. The
optimizations are:

1. Remove call to refresh_cache_or_die that stats every file in the repo,
i think the purpose is to detect any changes between git-add and
git-commit.

2. Pass missing_ok=true to cache_tree_update. This causes the tree
generation code to not stat every file in the repo to verify it still
exists as a git object.

3. Remove pair discard_cache/read_cache_from, which rereads the index
file. I think this was in case a pre-commit hook changed the set of things
being committed.

It may be worth making some of these flag-enabled.



Josh


On 12/12/11 4:15 PM, "Joshua Redstone" [off-list ref] wrote:

Sorry for the poor formatting of the stack trace.

I've written two scripts to reproduce the slow commit behavior that I see.
I've posted both to:
  https://gist.github.com/1469760

To repro, first create a dir with lots of files (it defaults to creating 1
million files in 1000 dirs):

$ loadGen.py --baseDir=./bigdir

then, run the simulator scripts to generate and commit a series of small
changes to the repo:

$ git reset --hard HEAD && simulate.py ./bigdir git

The git reset is to clean up any cruft left over from a previous partial
invocation of simulate.py

Note that loadGen.py defaults to creating 1 million files and committing
them in one commit.  With a flash drive this took < 30 min, and subsequent
small commits in simulate.py took about 6 seconds.  With a hard-drive,
it's taking > 1hr (still waiting for it to finish).

Cheers,
Josh


On 12/8/11 4:17 PM, "Joshua Redstone" [off-list ref] wrote:

quoted

Btw, I also tried doing some very poor-man's profiling on "git commit"
without any of the readtree/writetree/updateindex commands.

Around 50% of the time was in (bottom few frames may have varied)

#1  0x00000000004c467e in find_pack_entry (sha1=0x1475a44 ,
e=0x7fff2621f070) at sha1_file.c:2027
#2  0x00000000004c57b0 in has_sha1_file (sha1=0x7fe2cd9c7900 "00") at
sha1_file.c:2567 
                
                
#3  0x000000000046e4af in update_one (it=<value optimized out>,
cache=<value optimized out>, entries=<value optimized out>, base=<value
optimized out>, baselen=<value optimized out>, missing_ok=<value
optimized
out>, dryrun=0) at cache-\
tree.c:333       
                
                
           
#4  0x000000000046e278 in update_one (it=<value optimized out>,
cache=<value optimized out>, entries=<value optimized out>, base=<value
optimized out>, baselen=<value optimized out>, missing_ok=<value
optimized
out>, dryrun=0) at cache-\
tree.c:285       
                
                
           
#5  0x000000000046e278 in update_one (it=<value optimized out>,
cache=<value optimized out>, entries=<value optimized out>, base=<value
optimized out>, baselen=<value optimized out>, missing_ok=<value
optimized
out>, dryrun=0) at cache-\
tree.c:285       
                
                
           
#6  0x000000000046e278 in update_one (it=<value optimized out>,
cache=<value optimized out>, entries=<value optimized out>, base=<value
optimized out>, baselen=<value optimized out>, missing_ok=<value
optimized
out>, dryrun=0) at cache-\
tree.c:285       
                
                
           
#7  0x000000000046e278 in update_one (it=<value optimized out>,
cache=<value optimized out>, entries=<value optimized out>, base=<value
optimized out>, baselen=<value optimized out>, missing_ok=<value
optimized
out>, dryrun=0) at cache-\
tree.c:285       
                
                
           
#8  0x000000000046e278 in update_one (it=<value optimized out>,
cache=<value optimized out>, entries=<value optimized out>, base=<value
optimized out>, baselen=<value optimized out>, missing_ok=<value
optimized
out>, dryrun=0) at cache-\
tree.c:285       
                
                
           
#9  0x000000000046e869 in cache_tree_update (it=<value optimized out>,
cache=<value optimized out>, entries=dwarf2_read_address: Corrupted DWARF
expression.      
                
) at cache-tree.c:379
                
                
           
#10 0x000000000041cade in prepare_to_commit (index_file=0x781740
".git/index", prefix=<value optimized out>, current_head=<value optimized
out>, s=0x7fff26220d00, author_ident=<value optimized out>) at
builtin/commit.c:866
#11 0x000000000041d891 in cmd_commit (argc=0, argv=0x7fff262213a0,
prefix=0x0) at builtin/commit.c:1407
                
                
#12 0x0000000000404bf7 in handle_internal_command (argc=4,
argv=0x7fff262213a0) at git.c:308
                
                
#13 0x0000000000404e2f in main (argc=4, argv=0x7fff262213a0) at git.c:512
                
                
           



And 30% of the time was in:

#0  0x00000034af2c34a5 in _lxstat () from /lib64/libc.so.6
                
                
           
#1  0x00000000004abe0f in refresh_cache_ent (istate=0x780940,
ce=0x7f8462a34e40, options=0, err=0x7fff6dd9f588) at
/usr/include/sys/stat.h:443
                
#2  0x00000000004ac1a0 in refresh_index (istate=0x780940, flags=<value
optimized out>, pathspec=<value optimized out>, seen=<value optimized
out>, header_msg=0x0) at read-cache.c:1133
                
#3  0x000000000041b60a in refresh_cache_or_die (refresh_flags=<value
optimized out>) at builtin/commit.c:331
                
                
#4  0x000000000041bc39 in prepare_index (argc=0, argv=0x7fff6dda0310,
prefix=0x0, current_head=<value optimized out>, is_status=<value
optimized
out>) at builtin/commit.c:414
                
#5  0x000000000041d878 in cmd_commit (argc=0, argv=0x7fff6dda0310,
prefix=0x0) at builtin/commit.c:1403
                
                
 


Josh


On 12/8/11 4:09 PM, "Joshua Redstone" [off-list ref] wrote:

quoted

On 12/7/11 5:39 PM, "Nguyen Thai Ngoc Duy" [off-list ref] wrote:

quoted

On Thu, Dec 8, 2011 at 5:48 AM, Joshua Redstone
[off-list ref]
wrote:

quoted

Hi Duy,
Thanks for the documentation link.

git ls-files shows 100k files, which matches # of files in the
working
tree ('find . -type f -print | wc -l').

Any chance you can split it into smaller repositories, or remove files
from working directory (e.g. if you store logs, you don't have to keep
logs from all time in working directory, they can be retrieved from
history).

It's not really feasible to split it into smaller repositories.  In
fact,
we're expecting it to grow between 3x and 5x in number of files and
number
of commits.

quoted

quoted

I added a 'git read-tree HEAD' before the git-add, and a 'git
write-tree'
after the add.  With that, the commit time slowed down to 8 seconds
per
commit, plus 4 more seconds for the read-tree/add/write-tree ops.
The
read-tree/add/write-tree each took about a second.

read-tree destroys stat info in index, refreshing 100k entries in
index in this case may take some time. Try this to see if commit time
reduces and how much time update-index takes

read-tree HEAD
update-index --refresh
add ....
write-tree
commit -q

I added the "update-index --refresh" and the time for commit became more
like 0.6 seconds.
In this setup: read-tree takes ~2 seconds, update-index takes ~8
seconds,
git-add takes 1 to 4 seconds, and write-tree takes less than 1 second.

quoted

quoted

As an experiment, I also tried removing the 'git read-tree' and just
having the git-write-tree.  That sped up commits to 0.6 seconds, but
the
overall time for add/write-tree/commit was still 3 to 6 seconds.

overall time is not really important because we duplicate work here
(write-tree is done as part of commit again). What I'm trying to do is
to determine how much time each operation in commit may take.
-- 
Duy