{"thread":{"id":"27632","subject":"git checkout running very slowly (>12s)","startedAt":"2011-06-15T19:30:55Z","lastAt":"2011-06-21T14:44:53Z","messageCount":7,"participants":["Andrew Cameron","Andreas Ericsson","Jeff King"],"isPatch":false,"patchVersion":null,"patchTotal":null},"messages":[{"id":"170079","messageId":"loom.20110615T213016-856@post.gmane.org","threadId":"27632","inReplyTo":null,"subject":"git checkout running very slowly (>12s)","fromName":"Andrew Cameron","fromEmail":"andrew@worksmartlabs.com","sentAt":"2011-06-15T19:30:55Z","receivedAt":"2011-06-15T19:30:55Z","isPatch":false,"sender":{"key":"andrew@worksmartlabs.com","avatar":null},"body":"Some git operations (notably checkouts) are taking a very long time to execute.\nHere is a shell session which illustrates the problem.\n\n$ time git branch foo\ngit branch foo  0.01s user 0.00s system 77% cpu 0.016 total\n$ time git checkout foo\nSwitched to branch 'foo'\ngit checkout foo  11.73s user 0.18s system 99% cpu 11.937 total\n$ time git checkout master\nSwitched to branch 'master'\ngit checkout master  11.62s user 0.18s system 99% cpu 11.813 total\n$ git count-objects -v\ncount: 953\nsize: 527012\nin-pack: 153432\npacks: 7\nsize-pack: 1986072\nprune-packable: 0\ngarbage: 0\n\nI tried doing a sparse checkout to eliminate approximately 40,000 files from the \ncheckout, and furthermore doing git update-index --skip-worktree on a tree which \ncontained about another 16,600 files, but neither had any noticeable effect on \ncheckout times.\n\n---\nAndrew Cameron\n"},{"id":"170098","messageId":"4DF9363F.6080009@op5.se","threadId":"27632","inReplyTo":"loom.20110615T213016-856@post.gmane.org","subject":"Re: git checkout running very slowly (>12s)","fromName":"Andreas Ericsson","fromEmail":"ae@op5.se","sentAt":"2011-06-15T22:46:23Z","receivedAt":"2011-06-15T22:46:23Z","isPatch":false,"sender":{"key":"ae@op5.se","avatar":"https://gravatar.com/avatar/426e89595c75a8f5252dd0c989e5fabe5bcac616e68557427ad9aef6b0ca342a?d=mp&s=160"},"body":"On 06/15/2011 09:30 PM, Andrew Cameron wrote:\n> Some git operations (notably checkouts) are taking a very long time to execute.\n> Here is a shell session which illustrates the problem.\n> \n> $ time git branch foo\n> git branch foo  0.01s user 0.00s system 77% cpu 0.016 total\n\nCreating a branch is just a matter of creating a new ref. In this\ncase, you're doing it on the currently checked out ref. That's a\nconstant-time operation that is always very quick.\n\n> $ time git checkout foo\n> Switched to branch 'foo'\n> git checkout foo  11.73s user 0.18s system 99% cpu 11.937 total\n\nIf this sequence of commands is accurate, that's a bit weird. If\nyou've got another branch checked out first and then switch it\nwould be understandable, considering the size of the repository.\nWe should probably still do a tree-by-tree comparison to see\nwhich files are changed though, but I thought that's already\ndone to avoid superfluous work and allow worktree changes to\ncarry over to other branches. What version of git are you using?\n\n> $ time git checkout master\n> Switched to branch 'master'\n> git checkout master  11.62s user 0.18s system 99% cpu 11.813 total\n> $ git count-objects -v\n> count: 953\n> size: 527012\n> in-pack: 153432\n> packs: 7\n> size-pack: 1986072\n> prune-packable: 0\n> garbage: 0\n> \n\nThese figures are nowhere near as interesting as those from\n  git ls-files | wc -l\nafter the checkout is completed.\n\n-- \nAndreas Ericsson                   andreas.ericsson@op5.se\nOP5 AB                             www.op5.se\nTel: +46 8-230225                  Fax: +46 8-230231\n\nConsidering the successes of the wars on alcohol, poverty, drugs and\nterror, I think we should give some serious thought to declaring war\non peace.\n"},{"id":"170101","messageId":"loom.20110616T010709-333@post.gmane.org","threadId":"27632","inReplyTo":"4DF9363F.6080009@op5.se","subject":"Re: git checkout running very slowly (>12s)","fromName":"Andrew Cameron","fromEmail":"andrew@worksmartlabs.com","sentAt":"2011-06-15T23:16:03Z","receivedAt":"2011-06-15T23:16:03Z","isPatch":false,"sender":{"key":"andrew@worksmartlabs.com","avatar":null},"body":"Andreas Ericsson <ae <at> op5.se> writes:\n\n> \n> On 06/15/2011 09:30 PM, Andrew Cameron wrote:\n> > Some git operations (notably checkouts) are taking a very long time to \nexecute.\n> > Here is a shell session which illustrates the problem.\n> > \n> > $ time git branch foo\n> > git branch foo  0.01s user 0.00s system 77% cpu 0.016 total\n> \n> Creating a branch is just a matter of creating a new ref. In this\n> case, you're doing it on the currently checked out ref. That's a\n> constant-time operation that is always very quick.\n> \n> > $ time git checkout foo\n> > Switched to branch 'foo'\n> > git checkout foo  11.73s user 0.18s system 99% cpu 11.937 total\n> \n> If this sequence of commands is accurate, that's a bit weird. If\n> you've got another branch checked out first and then switch it\n> would be understandable, considering the size of the repository.\n> We should probably still do a tree-by-tree comparison to see\n> which files are changed though, but I thought that's already\n> done to avoid superfluous work and allow worktree changes to\n> carry over to other branches. What version of git are you using?\n\nI suppose I forgot to illustrate that, when I created \"foo\" I was on \"master\".  \nThe order branch checkouts was master -> foo -> master, and both transitions \ntook ~12s despite pointing to the same commit and using a clean working tree.  I \nimagine you inferred all of that, but if not, now you know.\n\n$ git --version\ngit version 1.7.0.4\n\n> > $ time git checkout master\n> > Switched to branch 'master'\n> > git checkout master  11.62s user 0.18s system 99% cpu 11.813 total\n> > $ git count-objects -v\n> > count: 953\n> > size: 527012\n> > in-pack: 153432\n> > packs: 7\n> > size-pack: 1986072\n> > prune-packable: 0\n> > garbage: 0\n> > \n> \n> These figures are nowhere near as interesting as those from\n>   git ls-files | wc -l\n> after the checkout is completed.\n> \n\n$ git checkout master\nSwitched to branch 'master'\n$ git ls-files | wc -l\n90831\n"},{"id":"170320","messageId":"loom.20110620T221426-685@post.gmane.org","threadId":"27632","inReplyTo":"loom.20110616T010709-333@post.gmane.org","subject":"Re: git checkout running very slowly (>12s)","fromName":"Andrew Cameron","fromEmail":"andrew@worksmartlabs.com","sentAt":"2011-06-20T20:26:37Z","receivedAt":"2011-06-20T20:26:37Z","isPatch":false,"sender":{"key":"andrew@worksmartlabs.com","avatar":null},"body":"Andrew Cameron <andrew <at> worksmartlabs.com> writes:\n\n> \n> $ git --version\n> git version 1.7.0.4\n> \n\nIn the interest of leaving a message of hope in the archives for users \nexperiencing this same problem, I will record to the list that I managed to \nsolve the problem, if not understand it.  As you can see in the transcript \nabove, I had been using an older version of git:\n\n> $ git --version\n> git version 1.7.0.4\n\nAfter running sudo apt-get build-dep git-core and then building git from\nsource, we see this instead:\n\n> $ git --version\n> git version 1.7.5.4\n\nAnd the success story:\n\n$ time git checkout master\nSwitched to branch 'master'\ngit checkout master  0.88s user 0.25s system 99% cpu 1.135 total\n$ time git checkout -\nSwitched to branch 'newbranch'\ngit checkout -  0.87s user 0.25s system 99% cpu 1.121 total\n\nIt might be interesting to note that both before and after upgrading git, \nrunning \"strace -c git checkout master\" in an attempt to figure out where all my \ntime was spent was *not* particularly helpful.  An excerpt from strace's output \nfrom before the upgrade:\n\n% time     seconds  usecs/call     calls    errors syscall\n------ ----------- ----------- --------- --------- ----------------\n100.00    0.003499           0     90884         7 lstat64\n\nAnd another one from afterwards:\n\n% time     seconds  usecs/call     calls    errors syscall\n------ ----------- ----------- --------- --------- ----------------\n 99.24    0.003276           0     90886         7 lstat64\n\nIn other words, it appears that an efficient lstat implementation was not the \nkey factor in this problem.  The root cause remains a mystery, but in my case, \nthe solution was to upgrade Git.\n\nThanks for reading.\n"},{"id":"170345","messageId":"20110621004452.GA3064@sigill.intra.peff.net","threadId":"27632","inReplyTo":"loom.20110620T221426-685@post.gmane.org","subject":"Re: git checkout running very slowly (>12s)","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2011-06-21T00:44:52Z","receivedAt":"2011-06-21T00:44:52Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Mon, Jun 20, 2011 at 08:26:37PM +0000, Andrew Cameron wrote:\n\n> In other words, it appears that an efficient lstat implementation was not the \n> key factor in this problem.  The root cause remains a mystery, but in my case, \n> the solution was to upgrade Git.\n\nIf you can reliably trigger the problem by switching versions and you\nare still curious and want to spend a little more time on it, you may be\nable to bisect the fix to solve the mystery.\n\nKeep in mind that you are bisecting a fix, not a regression, so your\nmeanings of \"good\" and \"bad\" will be opposite of what you expect. I.e.,\n\"bad\" commits will have the fix, and \"good\" commits will not (I know\nthis is confusing; it's an artifact of the way bisect works).\n\n-Peff\n"},{"id":"170385","messageId":"20110621143437.GB18700@sigill.intra.peff.net","threadId":"27632","inReplyTo":"20110621004452.GA3064@sigill.intra.peff.net","subject":"Re: git checkout running very slowly (>12s)","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2011-06-21T14:34:37Z","receivedAt":"2011-06-21T14:34:37Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Mon, Jun 20, 2011 at 08:44:52PM -0400, Jeff King wrote:\n\n> > In other words, it appears that an efficient lstat implementation\n> > was not the key factor in this problem.  The root cause remains a\n> > mystery, but in my case, the solution was to upgrade Git.\n> \n> If you can reliably trigger the problem by switching versions and you\n> are still curious and want to spend a little more time on it, you may\n> be able to bisect the fix to solve the mystery.\n\nI was curious, and your issue was easy to replicate, so I bisected it\nmyself. The fix was:\n\n  commit e53e6b4433f264250c2e586167caf61721b0185c\n  Author: Brian Downing <bdowning@lavos.net>\n  Date:   Thu Jun 10 21:59:07 2010 -0500\n\n      unpack-trees: Make index lookahead less pessimal\n\nwhich went into v1.7.1.1.\n\n-Peff\n"},{"id":"170386","messageId":"BANLkTikJDHUbt8X+W-W66YNL4qDnwthB3w@mail.gmail.com","threadId":"27632","inReplyTo":"20110621143437.GB18700@sigill.intra.peff.net","subject":"Re: git checkout running very slowly (>12s)","fromName":"Andrew Cameron","fromEmail":"andrew@worksmartlabs.com","sentAt":"2011-06-21T14:44:53Z","receivedAt":"2011-06-21T14:44:53Z","isPatch":false,"sender":{"key":"andrew@worksmartlabs.com","avatar":null},"body":"On Tue, Jun 21, 2011 at 10:34 AM, Jeff King <peff@peff.net> wrote:\n\n> I was curious, and your issue was easy to replicate, so I bisected it\n> myself. The fix was:\n>\n>  commit e53e6b4433f264250c2e586167caf61721b0185c\n>  Author: Brian Downing <bdowning@lavos.net>\n>  Date:   Thu Jun 10 21:59:07 2010 -0500\n>\n>      unpack-trees: Make index lookahead less pessimal\n>\n> which went into v1.7.1.1.\n>\n> -Peff\n>\n\nYou beat me to it.  Thanks for the suggestion and the investigative work!\n\nAndrew\n"}]}