(unknown)

I am trying to create a working tree for people to read from and have it update from a bare repository regularly.  Right now I am using git-pull to fetch the changes, but it’s running slow due to the size of my repo and the speed of the hardware as it seems to be checking the working tree for any changes. 

Is there a way to make the pull ignore the local working tree and only look at files that are changed in the change sets being pulled?

Bevan

2009/5/7 Bevan Watkiss <bevan.watkiss@cloakware.com>:

Assuming you didn't modify that directory you pull into, git pull will do almost exactly what you described. Almost, because the operation (the merge) will involve looking for local changes (committed and not).

It should be faster to do something like this:

  git fetch && git reset --hard origin/master

Again, assuming the directory supposed to be read-only. Otherwise, you have to merge (i.e. git pull).

It's the looking for local changes I'm trying to avoid. Doing a reset still goes over the tree, which isn't helpful.

Basically I have a copy of my tree where only git can write to it, so I know the files are right. The NAS box I have the tree on is slow, so reading the tree adds about 10 minutes to the process when I only want to update a few files.

-----Original Message-----
From: Alex Riesen [mailto:raa.lkml@gmail.com] 
Sent: May 7, 2009 1:14 PM
To: Bevan Watkiss
Cc: git@vger.kernel.org
Subject: Re:

2009/5/7 Bevan Watkiss <bevan.watkiss@cloakware.com>:

the

look

Assuming you didn't modify that directory you pull into, git pull will do almost exactly what you described. Almost, because the operation (the merge) will involve looking for local changes (committed and not).

It should be faster to do something like this:

  git fetch && git reset --hard origin/master

Again, assuming the directory supposed to be read-only. Otherwise, you have to merge (i.e. git pull).

2009/5/7 Bevan Watkiss <bevan.watkiss@cloakware.com>:

The stat(2) is slow? Then try setting core.ignoreStat (see manpage of git config) to true: git config core.ignorestat true and read below.

Try "git checkout origin/master". It uses index and shouldn't checkout files which are uptodate with the index. And actually, git merge should fast-forward, in your case and will update just the changed files...

Of course, you can always compare HEAD and origin/master, and resolve the changes yourself (see git diff -z --name-status), but it is unlikely to be any faster.

Still took 11 minutes.

The idea I've come up with today is something along the lines of git fetch origin/master git log --name-only ..<hash> | xargs git checkout -f --

This should work to quickly keep my files upto date, and I can then periodically pull properly to move the HEAD.

Thanks for the info

Bevan

-----Original Message-----
From: Alex Riesen [mailto:raa.lkml@gmail.com] 
Sent: May 7, 2009 2:18 PM
To: Bevan Watkiss
Cc: git@vger.kernel.org
Subject: Re:

2009/5/7 Bevan Watkiss <bevan.watkiss@cloakware.com>:

still

The stat(2) is slow? Then try setting core.ignoreStat (see manpage of git config) to true: git config core.ignorestat true and read below.

know

the

Try "git checkout origin/master". It uses index and shouldn't checkout files which are uptodate with the index. And actually, git merge should fast-forward, in your case and will update just the changed files...

Of course, you can always compare HEAD and origin/master, and resolve the changes yourself (see git diff -z --name-status), but it is unlikely to be any faster.

[Please don't top-post...]

On 2009.05.07 14:48:20 -0400, Bevan Watkiss wrote:

IIRC, to see the effects of core.ignorestat, you need to have updated all files once. So you might need, for example, "git checkout -f HEAD" (not sure if a plain checkout is enough) once first, and then the future "git checkout $something" should be faster.

Björn

On Thu, 7 May 2009, Bevan Watkiss wrote:

Ouch.

You could try doing

	[core]
		preloadindex = true

and see if that helps some of your loads. It does limit even the parallel tree stat to 20 or so, but if most of your cost is in just doing the lstat() over the files to see that they haven't changed, you might be getting a factor-of-20 speedup for at least _some_ of what you do.

If you can, it might also be interesting to see system call trace patterns (with times!) to see if there is something obviously horribly bad going on. If you're running under Linux, and don't think the data contains anything very private, send me the output of "strace -f -T" of the most problematic operations, and maybe I can see if I can come up with anything interesting.

I have long refused to use networked filesystems because I used to find them -so- painful when working with CVS, so none of my performance work has ever really directly concentrated on long-latency filesystems. Even the index preload was all done "blind" with other people reporting issues (and happily I could see some of the effects with local filesystems and multiple CPU's ;).

			Linus
	

Looking at the trace it does appear that most of this is the lstat. It's the problem of having many tiny files on a network drive, and trying to use git for something it's not meant.

The log has 265430 lines of lstat and 10887 other lines. If you still want the log file I'll strip out the directory names and send it off.

It would be nice to have an option that you can pull only the files that changed in the changesets you are updating and ignore the state of the other files.

Bevan

-----Original Message-----
From: Linus Torvalds [mailto:torvalds@linux-foundation.org] 
Sent: May 7, 2009 2:56 PM
To: Bevan Watkiss
Cc: 'Alex Riesen'; git@vger.kernel.org
Subject: RE: 

On Thu, 7 May 2009, Bevan Watkiss wrote:

know

the

Ouch.

You could try doing

	[core]
		preloadindex = true

and see if that helps some of your loads. It does limit even the parallel tree stat to 20 or so, but if most of your cost is in just doing the lstat() over the files to see that they haven't changed, you might be getting a factor-of-20 speedup for at least _some_ of what you do.

If you can, it might also be interesting to see system call trace patterns (with times!) to see if there is something obviously horribly bad going on. If you're running under Linux, and don't think the data contains anything very private, send me the output of "strace -f -T" of the most problematic operations, and maybe I can see if I can come up with anything interesting.

I have long refused to use networked filesystems because I used to find them -so- painful when working with CVS, so none of my performance work has ever really directly concentrated on long-latency filesystems. Even the index preload was all done "blind" with other people reporting issues (and happily I could see some of the effects with local filesystems and multiple CPU's ;).

			Linus
	

On Thu, 7 May 2009, Bevan Watkiss wrote:

Actually, if it's just the lstat's, then it's not all that interesting any more, it's a known problem with at least a known _partial_ solution.

However, I think it turns out that we've only enabled the index preloading with "git diff" and "git commit". Not on "git checkout".

So start off doing that

AND apply the following patch to git, and see how much (if any) that helps. It sounds like you have a pretty damn large repository, together with a slow filesystem. It really could be a big improvement.

The patch is TOTALLY UNTESTED. It also worries me that 'git checkout' seems to do _two_ 'lstat()' calls per file. I didn't look any more closely, but there may be other issues here.

		Linus

---
 builtin-checkout.c |    4 ++--
 1 files changed, 2 insertions(+), 2 deletions(-)

On Thu, 7 May 2009, Linus Torvalds wrote:

Hmm. The second pass comes from 

	show_local_changes(&new->commit->object);

(this is the "git checkout" without actual filenames), and is suppressed if we ask for a quiet checkout. But it's sad how it re-loads the index. I wonder where the CE_VALID bit got dropped.

			Linus

Linus Torvalds <torvalds@linux-foundation.org> writes:

I do not think you mean CE_VALID; CE_UPTODATE isn't it?

On Thu, 7 May 2009, Junio C Hamano wrote:

Yes, sorry.

		Linus

On Thu, 7 May 2009, Linus Torvalds wrote:

Ahh. It's not actually dropped, it's still there.

It's just that 'get_stat_data()' doesn't check it, when asking for noncached data.

The logic of 'get_stat_data()' is that it will return the stat data from the filesystem (unless we explicitly ask for just the cached case, in which case it will take it from the cache entry directly).

However, the code doesn't realize that if ce_uptodate() is true, then we already know the stat data, so no need to do the lstat() again, and we can take it all from the cache entry regardless of whether we asked for filesystem data or cached data.

So here's a better patch. It should cut down the 'lstat()' calls from "git checkout" a lot.

It looks obvious enough, and it passes testing (and now "git checkout" only does about as many lstat's as there are files in the repository, and they seem to all be properly asynchronous if 'core.preloadindex' is set.

Somebody should check. It would be interesting to hear about whether this makes a performance impact, especially with slow filesystems and/or other operating systems that have a relatively higher cost for 'lstat()'.

		Linus

---
 builtin-checkout.c |    4 ++--
 diff-lib.c         |    2 +-
 2 files changed, 3 insertions(+), 3 deletions(-)

On Thu, 7 May 2009, Linus Torvalds wrote:

this patch is worthwhile in itself, but the use case that is presented here is slightly different, and I wonder if it's common enough to be worth having a config option for.

his use case (as I understand it) is that the working tree is never updated by anything other than git. it never recieves patches or manual edits.

as such _any_ lstats of the tree are a waste of time. if git knows what was checked out before and what is being checked out now, it can find what files need to be changed.

this situation is not common for most developers, but it would be reasonable for build farms, so it's not just a one-person issue.

David Lang

On Thu, 7 May 2009, david@lang.hm wrote:

Well, you can certainly just use the CE_VALID bit in the index too (and this time I really mean CE_VALID). But it won't help anybody else, so it wouldn't be nearly as interesting. And I wonder how badly that code has rotted, thanks to not getting used.

But yes, one thing to do would be

	git update-index --assume-unchanged --refresh

which should hopefully set the bit, and then after that setting 'core.ignoreStat' should hopefully keep it set.

Of course, you had then better _never_ make any mistakes and touch the files with non-git commands.

And hope that the code still works ;)

		Linus

On Thu, 7 May 2009, Linus Torvalds wrote:

even with this a git checkout -f should replace all files, correct?

David Lang

On Thu, 7 May 2009, david@lang.hm wrote:

Hmm. I don't think so.

As far as I recall, "-f" only overrides certain errors (like unmerged files or not up-to-date content), it doesn't change behavior wrt files that git thinks are already up-to-date.

But I didn't check.

		Linus

On Thu, 7 May 2009, Linus Torvalds wrote:

what about a reset --hard? (is there any command that would force the files to be re-written, no matter what git thinks is already there)

David Lang

On Thu, 7 May 2009, david@lang.hm wrote:

No, not "git reset --hard" either, I think. Git very much tries to avoid rewriting files, and if you've told it that file contents are stable, it will believe you.

In fact, I think people used CE_VALID explicitly for the missing parts of "partial checkouts", so if we'd suddenly start writing files despite them being marked as ok in the tree, I think we'd have broken that part.

(Although again - I'm not sure who would use CE_VALID and friends).

If you want to force everything to be rewritten, you should just remove the index (or remove the specific entries in it if you want to do it just to a particular file) and then do a "git checkout" to re-read and re-populate the tree.

But I'm not really seeing why you want to do this. If you told git that it shouldn't care about the working tree, why do you now want it do care?

			Linus

On Thu, 7 May 2009, Linus Torvalds wrote:

to be able to manually recover from the case where someone did things that they weren't supposed to

removing the index and doing a checkout would be a reasonable thing to do (at least conceptually), I will admit that I don't remember ever seeing a command (or discussion of one) that would let me do that.

On Friday 08 May 2009, david@lang.hm wrote:

What about:

  rm .git/index
  git checkout -f

or maybe:

  git update-index --no-assume-unchanged --refresh
  git checkout -f

Hm?

....Johan

Added the patch and now the time is down to 4 1/2 minutes. Still a little slow for my needs though.

Since I'm looking for a more instantaneous update I'll probably use
something more along the lines of
	git fetch origin/master
	git log --name-only ..HEAD
to get the list of files that have changed and copy them from a local
repository.  Nightly doing a real pull to confirm the files are correct and
up to date.

Bevan

2009/5/7 Linus Torvalds <torvalds@linux-foundation.org>:

I did (cygwin). My guess, the improvement is completely dwarfed by the other overheads (like starting git and writing files).

# Without the patch real 11m22.338s user 0m54.629s sys 8m33.638s

# With checkout index preload real 11m14.361s user 0m46.609s sys 7m56.300s

The script:

#!/bin/sh

if [ "$1" = setup ]; then
    for i in 1 2 3 4
    do
        n=$(date)
        for f in `seq 1 10000`
        do
            echo "$n" >file$f
        done
        git add .
        printf "Commit $i:"
        git commit -m"$n"
    done
    exit
fi

export GIT_EXEC_PATH=/d/git-win
time for f in `seq 1 10`
do
    $GIT_EXEC_PATH/git checkout master~3 &&
    $GIT_EXEC_PATH/git checkout master~2 &&
    $GIT_EXEC_PATH/git checkout master~1 &&
    $GIT_EXEC_PATH/git checkout master
done
exit

On Fri, 8 May 2009, Alex Riesen wrote:

Oh, I meant "git checkout" as in not even switching branches, or perhaps switching branches but just changing a single file (among thousands).

If you actually end up re-writing all files, then yes, it will obviously be totally dominated by other things.

For example, in the kernel, switching between two branches that only differ in one file (Makefile) went from 0.18 seconds down to 0.14 seconds for me just because of the fewer lstat() calls.

Noticeable? No. But it might be more noticeable on some other OS, or with some networked filesystem.

		Linus

Linus Torvalds wrote:

plain 'git checkout' on linux kernel over NFS.

Best time without patch: 1.20 seconds

  0.45user 0.71system 0:01.20elapsed 96%CPU (0avgtext+0avgdata 0maxresident)k
  0inputs+0outputs (0major+15467minor)pagefaults 0swaps

Best time with patch (core.preloadindex = true): 1.10 seconds

  0.43user 4.00system 0:01.10elapsed 402%CPU (0avgtext+0avgdata 0maxresident)k
  0inputs+0outputs (0major+13999minor)pagefaults 0swaps

Best time with patch (core.preloadindex = false): 0.84 seconds

  0.42user 0.39system 0:00.84elapsed 96%CPU (0avgtext+0avgdata 0maxresident)k
  0inputs+0outputs (0major+13965minor)pagefaults 0swaps

Best time with read_cache_preload patch only: 1.38 seconds

  0.45user 4.42system 0:01.38elapsed 352%CPU (0avgtext+0avgdata 0maxresident)k
  0inputs+0outputs (0major+13990minor)pagefaults 0swaps

The read_cache_preload() changes actually slow things down for me for this case.

Reduction in lstat's gives a nice 30% improvement.

-brandon

On Fri, 8 May 2009, Brandon Casey wrote:

Thanks.

Ok, that is _disgusting_. The parallelism clearly works (402%CPU), but the system time overhead is horrible. Going from 0.39s system time to 4s of system time is really quite nasty.

Is there any possibility you could oprofile this (run it in a loop to get better profiles)? It very much sounds like some serious lock contention, and I'd love to hear more about exactly which lock it's hitting.

Also, you're already almost totally CPU-bound, with 96% CPU for the single-threaded csase. So you may be running over NFS, but your NFS server is likely pretty good and/or the client just captures everything in the caches anyway.

I don't recall what the Linux NFS stat cache timeout is, but it's less than a minute. I suspect that you ran things in a tight loop, which is why you then got effectively the local caching behavior for the best times.

Can you do a "best time" check but with a 60-second pause between runs (and before), to see what happens when the client doesn't do caching?

Yeah, here you're not getting any advantage of fewer lstats, and you show the same "almost entirely CPU-bound on four cores" behavior, and the same (probable) lock contention that has pushed the system time way up.

Yes, I think the one-liner lstat avoidance is a real fix regardless. And the preloading sounds like it hits serialization overhead in the kernel, which I'm not at all surprised at, but not being surprised doesn't mean that I'm not interested to hear where it is.

The Linux VFS dcache itself should scale better than that (but who knows - cacheline ping-pong due to lock contention can easily cause a 10x slowdown even without being _totally_ contended all the time). So I would _suspect_ that it's some NFS lock that you're seeing, but I'd love to know more.

Btw, those system times are pretty high to begin with, so I'd love to know kernel version and see a profile even without the parallel case and presumably lock contention. Because while I probably have a faster machine anyway, what I see iis:

	[torvalds@nehalem linux]$ /usr/bin/time git checkout
	0.13user 0.05system 0:00.19elapsed 98%CPU (0avgtext+0avgdata 0maxresident)k
	0inputs+0outputs (0major+13334minor)pagefaults 0swaps

ie my "system" time is _much_ lower than yours (and lower than your system time). This is the 'without patch' time, btw, so this has extra lstat's. And my system time is still lower than my user time, so I wonder where all _your_ system time comes from. Your system time is much more comparable to user time even in the good case, and I wonder why?

Could be just that kernel code tends to have more cache misses, and my 8MB cache captures it all, and yours doesn't. Regardless, a profile would be very interesting.

			Linus

Linus Torvalds wrote:

Possibly, I'll see if our sysadmin has time to "play".

Yeah, that's what I did.

No problem.

Something is definitely up.

I provided timing results for your original preload_cache implementation which affected status and diff, which was part of the justification for merging it in.

   http://article.gmane.org/gmane.comp.version-control.git/100998

You can see that cold cache system time for 'git status' went from 0.36 to 0.52 seconds. Fine. I just ran it again, and now I'm getting system time of 10 seconds! This is the same machine.

Similarly for the cold cache 'git checkout' reruns:

Best without patch: 6.02 (systime 1.57)

  0.43user 1.57system 0:06.02elapsed 33%CPU (0avgtext+0avgdata 0maxresident)k
  5336inputs+0outputs (12major+15472minor)pagefaults 0swaps

Best with patch (preload_cache,lstat reduction): 2.69 (systime 10.47)

  0.45user 10.47system 0:02.69elapsed 405%CPU (0avgtext+0avgdata 0maxresident)k
  5336inputs+0outputs (12major+13985minor)pagefaults 0swaps

OS: Centos4.7

$ cat /proc/version Linux version 2.6.9-78.0.17.ELsmp (mockbuild@builder16.centos.org) (gcc version 3.4.6 20060404 (Red Hat 3.4.6-9)) #1 SMP Thu Mar 12 20:05:15 EDT 2009

-brandon

Brandon Casey wrote:

Here's an strace of 'git checkout':

Before (cold cache):
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 98.60    6.365501         111     57432           lstat64
  0.50    0.031984         359        89         2 close
  0.25    0.015818         115       137        77 open
  0.12    0.007670          23       339           write
  0.09    0.005631         110        51           munmap
  0.08    0.004873          49        99        69 stat64
  0.07    0.004771         140        34        15 access
  0.05    0.003083         280        11         5 waitpid
  0.05    0.002973          10       284           brk
  0.04    0.002816         469         6           execve
<snip>

After (cold cache, no lstat fix, just cache_preload):
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 90.90   23.717981         413     57432           lstat64
  8.72    2.273917      162423        14         2 futex
  0.12    0.032241         948        34           close
  0.04    0.011507         202        57           munmap
  0.04    0.009648         132        73           mmap2
  0.03    0.008508         149        57        20 open
  0.03    0.007771         311        25           mprotect
  0.03    0.007758         388        20           clone
  0.03    0.007548          23       334           write
  0.02    0.005247         262        20        10 access

-brandon

On Fri, 8 May 2009, Brandon Casey wrote:

Yes, interesting. I really smells like it's all fixed performance and there is a single lock around it. That 111us -> 413us increase is very consistent with four cores all serializing on the same lock. So it parallelizes to all four cores, but then will take exactly as long in total.

Quite frankly, 2.6.9 is so old that I have absolutely _no_ memory of what we used to do back then. Not that I follow NFS all that much even now - I did some of the original page cache and dentry work on the Linux NFS client way back when, but that was when I actually used NFS (and we were converting everything to the page cache).

I've long since forgotten everything I knew, and I'm just as happy about that. But clearly something is bad, and equally clearly it worked much better for you a couple of months ago. Which does imply that there's probably some centos issues.

Can you ask your MIS people if it would be possible to at least _test_ a new kernel? In 2.6.9, I'm quite frankly inclined to just say "it will likely never get fixed unless centos knows what it is", but if you test a more modern kernel and see similar issues, then I'll be intrigued.

It's kind of sad, but at the same time, NFS was using the BKL up into 2.6.26 or something like that (about a year ago). And your kernel is based on something _much_ older.

That said, even with the BKL, NFS should allow all the actual IO to be done in parallel (since the BKL is dropped on scheduling). But it's really wasting a _lot_ of CPU time, and that hurts you enormously, even though the cold-cache case still seems to win, judging by your other email:

so there's a _huge_ increase in system time (again), but the change from 33% CPU -> 405% CPU makes up for it and you get lower elapsed times.

But that 7x increase in system time really is sad. I do suspect it's likely due to spinning on the BKL. And if so, then a modern kernel should fix it.

			Linus

Linus Torvalds wrote:

Makes sense to me.

In case you're not aware CentOS is just repacked RHEL. I'm not sure if centos has the resources for investigating problems. We also have RHEL licenses, so hopefully I'll be able to come up with something to submit to them.

I think it's possible. Just not on this specific machine. Not sure what we have lying around multi-processor wise. Also, it won't happen until next week since it's late Friday afternoon here.

btw, I've since done some more testing on some centos5.3 boxes we have. I get similar results (less ancient kernel 2.6.18). I've also scanned through the errata announcements that RedHat has released for their kernel updates. A few of them involve NFS. Possibly, whatever RedHat modified in the 5.X kernel was also backported to the 4.X kernel.

Thanks, I'll try to test next week.

-brandon

On Fri, 8 May 2009, Brandon Casey wrote:

Yes, 2.6.18 is still much too old to matter from a locking standpoint. 

When people initially worried about scalability, the issues were more about server side stuff and the cached cases. NFS (as a client) is certainly used on the server side too, but it tends to be a somewhat secondary worry where only specific parts really matter. So people worked a lot more on the core kernel, and on local high-performance filesystem scaling.

Only lately have we been pretty aggressive about finally really getting rid of the old "single big lock" (BKL) model entirely, or moving outwards from the core.

And while we removed the BKL from the normal NFS read/write paths long long ago, all the name lookup and directory handling code still had it until a year ago.

That, btw, is directly explained by perceived scalability issues: NFS is fairly often used as the backing store for a database and scaling thus matters there. But databases tend to keep their few big files open and use pread/pwrite - so pathname lookup is not nearly as significant for server ops as plain read/write.

(Pathname lookup is important for things like web servers etc, but they rely heavily on caching for that, and the cached case scales fine).

That is very possibly the case. Expanding the BKL usage in some case could easily trigger the lock getting contention - and the way lock contention works, once you get a just even a small _hint_ of contention, things often fall off a cliff. The contention slows locking down, which in turn causes more CPU usage, which in turn causes _more_ contention.

So even a small amount of extra locking - or even just slowing down some code that was inside the lock - can have catastrophic behavioural changes when the lock is close to being a problem. You do not get a nice gradual slowdown at all - you just hit a hard wall.

I guess I should really try to set up some fileserver here at home to improve my test coverage. And to do better backups (or the little private data I have that I can't just mirror out to the world by turning it into an open-source project ;^)

				Linus

On Fri, 8 May 2009, Brandon Casey wrote:

Grr.

Ok, if that's really the true kernel version (2.6.9), then that's some ancient kernel there. At the same time it's obviously been recompiled recently, so it got updated. At a guess, something got screwed up. But I have absolutely _no_ way to even guess what kernel patches centos puts in their ancient kernel builds.

Perhaps a centos bugzilla entry might be appropriate? Somebody there might know what changed.

Of course, it _could_ be an external change too, where the NFS server or timing changed just enough to trigger a pre-existing issue. But that would be pretty unlikely.

			Linus

* Linus Torvalds <torvalds@linux-foundation.org> writes:
| So here's a better patch. It should cut down the 'lstat()' calls from
| "git checkout" a lot.
|
| It looks obvious enough, and it passes testing (and now "git checkout"
| only does about as many lstat's as there are files in the repository,
| and they seem to all be properly asynchronous if 'core.preloadindex'
| is set.

  I did a test by switching from v2.6.27 to v2.6.25, and now the only
  "lstat()-difference" between with and without the -q option is 2
  lstat() calls extra done without the -q option.  And, compared to over
  41 000 lstat() calls, that is not noticable. Very good!

| Somebody should check. It would be interesting to hear about whether
| this makes a performance impact, especially with slow filesystems
| and/or other operating systems that have a relatively higher cost for
| 'lstat()'.

  Below is a table which is output from

      strace -o result -T git checkout my-v2.6.25   /* from my-v2.6.27 */

  where the "result" file is run through a perl script to pretty print it:

TOTAL 113988 100.000% OK:107252 NOT: 6736 6.263578 sec 55 usec/call lstat64 41114 36.069% OK: 35829 NOT: 5285 0.710936 sec 17 usec/call open 15027 13.183% OK: 13872 NOT: 1155 0.559302 sec 37 usec/call unlink 14379 12.614% OK: 14374 NOT: 5 3.720167 sec 259 usec/call write 14207 12.464% OK: 14207 NOT: 0 0.754196 sec 53 usec/call close 13872 12.170% OK: 13872 NOT: 0 0.185572 sec 13 usec/call fstat64 13862 12.161% OK: 13862 NOT: 0 0.169952 sec 12 usec/call rmdir 551 0.483% OK: 269 NOT: 282 0.035534 sec 64 usec/call brk 510 0.447% OK: 510 NOT: 0 0.014804 sec 29 usec/call mkdir 174 0.153% OK: 174 NOT: 0 0.102625 sec 590 usec/call mmap2 102 0.089% OK: 102 NOT: 0 0.001725 sec 17 usec/call read 68 0.060% OK: 68 NOT: 0 0.000999 sec 15 usec/call munmap 61 0.054% OK: 61 NOT: 0 0.005037 sec 83 usec/call access 20 0.018% OK: 12 NOT: 8 0.000348 sec 17 usec/call mprotect 13 0.011% OK: 13 NOT: 0 0.000193 sec 15 usec/call stat64 7 0.006% OK: 7 NOT: 0 0.000109 sec 16 usec/call getcwd 3 0.003% OK: 3 NOT: 0 0.000053 sec 18 usec/call chdir 3 0.003% OK: 3 NOT: 0 0.000048 sec 16 usec/call fcntl64 3 0.003% OK: 3 NOT: 0 0.000036 sec 12 usec/call rename 2 0.002% OK: 2 NOT: 0 0.001553 sec 776 usec/call setitimer 2 0.002% OK: 2 NOT: 0 0.000028 sec 14 usec/call getdents64 2 0.002% OK: 2 NOT: 0 0.000039 sec 20 usec/call uname 1 0.001% OK: 1 NOT: 0 0.000013 sec 13 usec/call time 1 0.001% OK: 1 NOT: 0 0.000011 sec 11 usec/call futex 1 0.001% OK: 1 NOT: 0 0.000013 sec 13 usec/call readlink 1 0.001% OK: 0 NOT: 1 0.000018 sec 18 usec/call execve 1 0.001% OK: 1 NOT: 0 0.000256 sec 256 usec/call getrlimit 1 0.001% OK: 1 NOT: 0 0.000011 sec 11 usec/call

  So, if the numbers from strace is trustable, 0.71 seconds is used on
  41 114 calls to lstat64().  But, look at the unlink line, where each
  call took 259 microseconds (= 0.259 milliseconds), and all 14 379
  calls took 3.72 seconds.

  It should be noted that when switching branch the other way (from .25
  to .27), the unlink() calls used less time (below 160 microseconds
  each).  Also note that the above was tested by only 3 runs.  Warm
  cache.  ext4 disk partition with git compiled with the USE_NSEC=1
  option.

  Most (all?) of the unlink() calls seems to be from the following lines
  from the checkout_entry() funciton in entry.c

	/*
	 * We unlink the old file, to get the new one with the
	 * right permissions (including umask, which is nasty
	 * to emulate by hand - much easier to let the system
	 * just do the right thing)
	 */
	if (S_ISDIR(st.st_mode)) {
		/* If it is a gitlink, leave it alone! */
		if (S_ISGITLINK(ce->ce_mode))
			return 0;
		if (!state->force)
			return error("%s is a directory", path);
		remove_subtree(path);
	} else if (unlink(path))
		return error("unable to unlink old '%s' (%s)", path, strerror(errno));

  -- kjetil

On Fri, 8 May 2009, Kjetil Barvik wrote:

The system call times from strace are not really trustworthy. The overhead of tracing and in particular all the context switching back and forth between the tracer and the tracee means that the numbers should be taken with a large grain of salt.

That said, they definitely aren't totally made up, and they tend to show real issues.

In this particular case, what is going on is that 'lstat()' does no IO at all, while 'unlink()' generally at the very least will add things to some journal etc, and when the journal fills up, it will force IO.

So doing 15k unlink() calls really is _much_ more expensive than doing 41k lstat() calls, since the latter will never force any IO at all (ok, so even doing just an lstat() may add atime updates etc to directories, but even if atime is enabled, that tends to only trigger one IO per second at most, and we never have to do any sync IO).

I don't think they are really "260 us each" or "160 us each". It's rather more likely that there are a few that are big due to forced IO, and most are in the couple of us case.

		Linus