{"thread":{"id":"23309","subject":"Extremely slow progress during 'git reflog expire --all'","startedAt":"2010-04-02T19:54:14Z","lastAt":"2010-04-08T07:00:50Z","messageCount":15,"participants":["Frans Pop","Jeff King","Junio C Hamano"],"isPatch":false,"patchVersion":null,"patchTotal":null},"messages":[{"id":"138457","messageId":"201004022154.14793.elendil@planet.nl","threadId":"23309","inReplyTo":null,"subject":"Extremely slow progress during 'git reflog expire --all'","fromName":"Frans Pop","fromEmail":"elendil@planet.nl","sentAt":"2010-04-02T19:54:14Z","receivedAt":"2010-04-02T19:54:14Z","isPatch":false,"sender":{"key":"elendil@planet.nl","avatar":null},"body":"I wanted to to a 'git gc' on my kernel repo, but that seemed to end in a \nloop: loads of CPU usage, no output. Using 'ps' I found it's not 'git gc' \nitself, but 'git reflog' that's causing the problem.\n\n>From the strace below it does seem like it still makes some progress, but \nI've never had it take anywhere near this long before. Normally it starts \nthe count of objects almost immediately.\n\nIt's using hardly any memory at all but has one core going flat out.\n\nI'm seeing this with both git 1.6.6.1 and 1.7.0.3 on the same repo.\nEnvironment:\n- Debian amd64/Lenny; Core Duo x86_64 2.6.34-rc3 -> 1.6.6.1\n- Debian i386/Sid; chroot on the same machine -> 1.7.0.3\nI've also tried with 2.6.33 to rule out a kernel issue.\n\nHere's the tail end of an strace I ran. I broke it off after 9+ minutes, \nbut I had let it go for longer than that earlier. You can clearly see \nwhere it starts to \"stall\" at 21:40:14.\n\nCheers,\nFJP\n\n$ strace -t git reflog expire --all\n[...]\n21:40:11 open(\".git/logs/HEAD.lock\", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 4\n21:40:11 open(\".git/objects/db/315842dd99ce7fd59697df36185df4b807000a\", \nO_RDONLY|O_NOATIME) = 23\n21:40:11 fstat(23, {st_mode=S_IFREG|0444, st_size=289, ...}) = 0\n21:40:11 mmap(NULL, 289, PROT_READ, MAP_PRIVATE, 23, 0) = 0x7f9b135bb000\n21:40:11 close(23) = 0\n21:40:11 munmap(0x7f9b135bb000, 289) = 0\n21:40:11 open(\".git/logs/HEAD\", O_RDONLY) = 23\n21:40:11 fstat(23, {st_mode=S_IFREG|0644, st_size=171397, ...}) = 0\n21:40:11 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|\nMAP_ANONYMOUS, -1, 0) = 0x7f9b135bb000\n21:40:11 read(23, \"bea4c899f2b5fad80099aea979780ef19\"..., 4096) = 4096\n21:40:11 fstat(4, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0\n21:40:11 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|\nMAP_ANONYMOUS, -1, 0) = 0x7f9b135ba000\n21:40:11 read(23, \"aca305e8a0209efda740b522024cfdefe\"..., 4096) = 4096\n21:40:11 read(23, \"es\\n134a0f063d0c48f08b8731118c4732\"..., 4096) = 4096\n21:40:12 read(23, \"c82b7849a0fe 416c623fe337da58f52a\"..., 4096) = 4096\n21:40:12 brk(0x2029000) = 0x2029000\n21:40:12 brk(0x2058000) = 0x2058000\n21:40:12 brk(0x2080000) = 0x2080000\n21:40:12 brk(0x20a6000) = 0x20a6000\n21:40:12 brk(0x20cb000) = 0x20cb000\n21:40:12 brk(0x20ef000) = 0x20ef000\n21:40:12 mmap(NULL, 2101248, PROT_READ|PROT_WRITE, MAP_PRIVATE|\nMAP_ANONYMOUS, -1, 0) = 0x7f9b133b9000\n21:40:12 munmap(0x7f9b156a5000, 1052672) = 0\n21:40:12 brk(0x2113000) = 0x2113000\n21:40:12 brk(0x2138000) = 0x2138000\n21:40:12 brk(0x215c000) = 0x215c000\n21:40:12 brk(0x217e000) = 0x217e000\n21:40:12 brk(0x219f000) = 0x219f000\n21:40:12 brk(0x21c0000) = 0x21c0000\n21:40:12 brk(0x21e4000) = 0x21e4000\n21:40:12 brk(0x2208000) = 0x2208000\n21:40:12 brk(0x222e000) = 0x222e000\n21:40:12 brk(0x2252000) = 0x2252000\n21:40:12 brk(0x2275000) = 0x2275000\n21:40:12 brk(0x2299000) = 0x2299000\n21:40:12 brk(0x22bf000) = 0x22bf000\n21:40:12 brk(0x22e3000) = 0x22e3000\n21:40:12 brk(0x2309000) = 0x2309000\n21:40:12 brk(0x232f000) = 0x232f000\n21:40:12 brk(0x2355000) = 0x2355000\n21:40:12 brk(0x237a000) = 0x237a000\n21:40:12 brk(0x239e000) = 0x239e000\n21:40:12 brk(0x23c4000) = 0x23c4000\n21:40:12 brk(0x23e8000) = 0x23e8000\n21:40:12 brk(0x240b000) = 0x240b000\n21:40:12 brk(0x242e000) = 0x242e000\n21:40:12 brk(0x2454000) = 0x2454000\n21:40:13 brk(0x2476000) = 0x2476000\n21:40:13 brk(0x249b000) = 0x249b000\n21:40:13 brk(0x24c0000) = 0x24c0000\n21:40:13 brk(0x24e6000) = 0x24e6000\n21:40:13 brk(0x250b000) = 0x250b000\n21:40:13 brk(0x2531000) = 0x2531000\n21:40:13 brk(0x2556000) = 0x2556000\n21:40:13 brk(0x2578000) = 0x2578000\n21:40:13 brk(0x259d000) = 0x259d000\n21:40:13 mmap(NULL, 4198400, PROT_READ|PROT_WRITE, MAP_PRIVATE|\nMAP_ANONYMOUS, -1, 0) = 0x7f9b12fb8000\n21:40:13 munmap(0x7f9b133b9000, 2101248) = 0\n21:40:13 brk(0x25c5000) = 0x25c5000\n21:40:13 brk(0x25ee000) = 0x25ee000\n21:40:13 brk(0x260f000) = 0x260f000\n21:40:13 brk(0x2633000) = 0x2633000\n21:40:13 brk(0x2659000) = 0x2659000\n21:40:13 brk(0x267e000) = 0x267e000\n21:40:13 brk(0x26a3000) = 0x26a3000\n21:40:13 brk(0x26c8000) = 0x26c8000\n21:40:13 brk(0x26ec000) = 0x26ec000\n21:40:13 brk(0x2712000) = 0x2712000\n21:40:13 brk(0x2737000) = 0x2737000\n21:40:13 brk(0x275b000) = 0x275b000\n21:40:13 brk(0x2780000) = 0x2780000\n21:40:13 brk(0x27a6000) = 0x27a6000\n21:40:13 brk(0x27c9000) = 0x27c9000\n21:40:13 brk(0x27ec000) = 0x27ec000\n21:40:13 brk(0x2811000) = 0x2811000\n21:40:13 brk(0x2839000) = 0x2839000\n21:40:13 brk(0x285d000) = 0x285d000\n21:40:13 brk(0x2885000) = 0x2885000\n21:40:13 brk(0x28ac000) = 0x28ac000\n21:40:13 brk(0x28d0000) = 0x28d0000\n21:40:13 brk(0x28f5000) = 0x28f5000\n21:40:13 brk(0x291f000) = 0x291f000\n21:40:13 brk(0x2943000) = 0x2943000\n21:40:14 brk(0x2965000) = 0x2965000\n21:40:14 brk(0x2988000) = 0x2988000\n21:40:14 brk(0x29ac000) = 0x29ac000\n21:40:14 brk(0x29d1000) = 0x29d1000\n21:40:14 brk(0x29f7000) = 0x29f7000\n21:40:14 brk(0x2a1b000) = 0x2a1b000\n21:40:20 brk(0x2a3c000) = 0x2a3c000\n21:40:35 brk(0x2a5d000) = 0x2a5d000\n21:40:50 brk(0x2a7e000) = 0x2a7e000\n21:41:06 brk(0x2a9f000) = 0x2a9f000\n21:41:22 brk(0x2ac0000) = 0x2ac0000\n21:41:37 brk(0x2ae1000) = 0x2ae1000\n21:41:52 brk(0x2b02000) = 0x2b02000\n21:42:08 brk(0x2b23000) = 0x2b23000\n21:42:22 brk(0x2b44000) = 0x2b44000\n21:42:37 brk(0x2b65000) = 0x2b65000\n21:42:52 brk(0x2b86000) = 0x2b86000\n21:43:07 brk(0x2ba7000) = 0x2ba7000\n21:43:22 brk(0x2bc8000) = 0x2bc8000\n21:43:37 brk(0x2beb000) = 0x2beb000\n21:43:51 read(23, \"ab433be0e8a388d3354bdf15937 Frans\"..., 4096) = 4096\n21:43:53 brk(0x2c0c000) = 0x2c0c000\n21:44:04 read(23, \"nl> 1265475450 +0100\\trebase -i (e\"..., 4096) = 4096\n21:44:04 read(23, \"1265475836 +0100\\tcommit: parisc: \"..., 4096) = 4096\n21:44:05 brk(0x2c2d000) = 0x2c2d000\n21:44:05 read(23, \"0\\tcheckout: moving from master to\"..., 4096) = 4096\n21:44:05 read(23, \"c84e745ec814f386ef7f454295ba54d64\"..., 4096) = 4096\n21:44:05 read(23, \"792 1ff647af5425c749e4d625b807d3b\"..., 4096) = 4096\n21:44:05 brk(0x2c54000) = 0x2c54000\n21:44:05 brk(0x2c75000) = 0x2c75000\n21:44:12 brk(0x2c96000) = 0x2c96000\n21:44:25 brk(0x2cb9000) = 0x2cb9000\n21:44:37 brk(0x2cda000) = 0x2cda000\n21:44:50 brk(0x2cfb000) = 0x2cfb000\n21:45:01 brk(0x2d1c000) = 0x2d1c000\n21:45:14 brk(0x2d3d000) = 0x2d3d000\n21:45:26 brk(0x2d5e000) = 0x2d5e000\n21:45:38 brk(0x2d7f000) = 0x2d7f000\n21:45:50 brk(0x2da0000) = 0x2da0000\n21:46:03 brk(0x2dc1000) = 0x2dc1000\n21:46:14 brk(0x2de2000) = 0x2de2000\n21:46:27 brk(0x2e03000) = 0x2e03000\n21:46:39 brk(0x2e24000) = 0x2e24000\n21:46:51 brk(0x2e45000) = 0x2e45000\n21:47:03 brk(0x2e66000) = 0x2e66000\n21:47:15 brk(0x2e87000) = 0x2e87000\n21:47:27 brk(0x2ea8000) = 0x2ea8000\n21:47:40 brk(0x2ec9000) = 0x2ec9000\n21:47:52 brk(0x2eea000) = 0x2eea000\n21:48:04 brk(0x2f0b000) = 0x2f0b000\n21:48:17 read(23, \"ng HEAD\\n8d76bb3b759cba01d3cb9f6ab\"..., 4096) = 4096\n21:48:17 brk(0x2f2d000) = 0x2f2d000\n21:48:29 brk(0x2f4e000) = 0x2f4e000\n21:48:42 brk(0x2f6f000) = 0x2f6f000\n21:48:53 brk(0x2f90000) = 0x2f90000\n21:49:05 brk(0x2fb1000) = 0x2fb1000\n21:49:17 brk(0x2fd2000) = 0x2fd2000\n21:49:29 brk(0x2ff3000) = 0x2ff3000\n"},{"id":"138464","messageId":"20100402212858.GA28531@coredump.intra.peff.net","threadId":"23309","inReplyTo":"201004022154.14793.elendil@planet.nl","subject":"Re: Extremely slow progress during 'git reflog expire --all'","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2010-04-02T21:28:58Z","receivedAt":"2010-04-02T21:28:58Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Fri, Apr 02, 2010 at 09:54:14PM +0200, Frans Pop wrote:\n\n> I wanted to to a 'git gc' on my kernel repo, but that seemed to end in a \n> loop: loads of CPU usage, no output. Using 'ps' I found it's not 'git gc' \n> itself, but 'git reflog' that's causing the problem.\n> \n> From the strace below it does seem like it still makes some progress, but \n> I've never had it take anywhere near this long before. Normally it starts \n> the count of objects almost immediately.\n> \n> It's using hardly any memory at all but has one core going flat out.\n> \n> I'm seeing this with both git 1.6.6.1 and 1.7.0.3 on the same repo.\n> Environment:\n> - Debian amd64/Lenny; Core Duo x86_64 2.6.34-rc3 -> 1.6.6.1\n> - Debian i386/Sid; chroot on the same machine -> 1.7.0.3\n> I've also tried with 2.6.33 to rule out a kernel issue.\n> \n> Here's the tail end of an strace I ran. I broke it off after 9+ minutes, \n> but I had let it go for longer than that earlier. You can clearly see \n> where it starts to \"stall\" at 21:40:14.\n\nFWIW, I have seen this, too, and managed to get an strace snippet that\nlooked similar to what you saw (mostly memory allocation, and otherwise\nchewing on the CPU). I'm guessing there is some O(n^2) loop in there\nsomewhere. Unfortunately, mine actually completed after a few minutes\nand I wasn't able to replicate.\n\nCan you reproduce the problem on your repo? If so, can you possibly tar\nit up and make it available (probably just the .git directory would be\nenough)?\n\n-Peff\n"},{"id":"138466","messageId":"201004022350.20999.elendil@planet.nl","threadId":"23309","inReplyTo":"20100402212858.GA28531@coredump.intra.peff.net","subject":"Re: Extremely slow progress during 'git reflog expire --all'","fromName":"Frans Pop","fromEmail":"elendil@planet.nl","sentAt":"2010-04-02T21:50:19Z","receivedAt":"2010-04-02T21:50:19Z","isPatch":false,"sender":{"key":"elendil@planet.nl","avatar":null},"body":"On Friday 02 April 2010, Jeff King wrote:\n> Can you reproduce the problem on your repo? If so, can you possibly tar\n> it up and make it available (probably just the .git directory would be\n> enough)?\n\nYes, I can reproduce. I've run it a few times and broke it off each time \nbefore it finished as I really had no idea how much longer it might take.\n\n$ du -sh .git\n1008M .git\n\nI can make that available, but it's going to take a while to upload and I \ndon't want to leave it up too long as I'll be abusing a project service \nfor that. So the people who want to look at it would have grab it fairly \npromptly (within 2 days or so).\n\nIs that OK?\n\nCheers,\nFJP\n"},{"id":"138471","messageId":"20100402224100.GA997@coredump.intra.peff.net","threadId":"23309","inReplyTo":"201004022350.20999.elendil@planet.nl","subject":"Re: Extremely slow progress during 'git reflog expire --all'","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2010-04-02T22:41:00Z","receivedAt":"2010-04-02T22:41:00Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Fri, Apr 02, 2010 at 11:50:19PM +0200, Frans Pop wrote:\n\n> Yes, I can reproduce. I've run it a few times and broke it off each time \n> before it finished as I really had no idea how much longer it might take.\n> \n> $ du -sh .git\n> 1008M .git\n> \n> I can make that available, but it's going to take a while to upload and I \n> don't want to leave it up too long as I'll be abusing a project service \n> for that. So the people who want to look at it would have grab it fairly \n> promptly (within 2 days or so).\n> \n> Is that OK?\n\nThat would be fine. If even that is a problem, we can arrange off-list\nto get it from you privately and I can stick it somewhere for a week or\ntwo.\n\n-Peff\n"},{"id":"138499","messageId":"201004031629.01970.elendil@planet.nl","threadId":"23309","inReplyTo":"20100402224100.GA997@coredump.intra.peff.net","subject":"Re: Extremely slow progress during 'git reflog expire --all'","fromName":"Frans Pop","fromEmail":"elendil@planet.nl","sentAt":"2010-04-03T14:29:01Z","receivedAt":"2010-04-03T14:29:01Z","isPatch":false,"sender":{"key":"elendil@planet.nl","avatar":null},"body":"On Saturday 03 April 2010, Jeff King wrote:\n> > I can make that available, but it's going to take a while to upload\n> > and I don't want to leave it up too long as I'll be abusing a project\n> > service for that. So the people who want to look at it would have grab\n> > it fairly promptly (within 2 days or so).\n\nThe tarball is up at:\nhttp://alioth.debian.org/~fjp/.tmp/linux-2.6_reflog-issue.tar\n\nBecause of the Easter weekend I'll leave it up a bit longer. I plan to \nremove it sometime on Thursday.\n\nCheers,\nFJP\n"},{"id":"138511","messageId":"20100403203348.GA11433@coredump.intra.peff.net","threadId":"23309","inReplyTo":"201004031629.01970.elendil@planet.nl","subject":"Re: Extremely slow progress during 'git reflog expire --all'","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2010-04-03T20:33:49Z","receivedAt":"2010-04-03T20:33:49Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Sat, Apr 03, 2010 at 04:29:01PM +0200, Frans Pop wrote:\n\n> On Saturday 03 April 2010, Jeff King wrote:\n> > > I can make that available, but it's going to take a while to upload\n> > > and I don't want to leave it up too long as I'll be abusing a project\n> > > service for that. So the people who want to look at it would have grab\n> > > it fairly promptly (within 2 days or so).\n> \n> The tarball is up at:\n> http://alioth.debian.org/~fjp/.tmp/linux-2.6_reflog-issue.tar\n> \n> Because of the Easter weekend I'll leave it up a bit longer. I plan to \n> remove it sometime on Thursday.\n\nThanks, I was able to get it and reproduce your problem. The slowness is\nin the expire-unreachable code. You can work around it with:\n\n git config gc.reflogExpireUnreachable never\n\nObviously that's not really a fix, but it should let your \"git gc\" work.\n\nIt looks like we do two merge-base calculations for each reflog entry,\nwhich is what takes so long. Perhaps if we know we are going to do a\nlarge number of reachability checks, we can pre-mark all reachable\ncommits, and then each reflog entry would just need to check the commit\nmark.\n\nI don't have any more time now to look at it, but I am cc'ing Junio (who\nwrote the original expire-unreachable code) and Shawn (the resident\nreflog expert), who may have more input.\n\n-Peff\n"},{"id":"138512","messageId":"20100403203507.GA12262@coredump.intra.peff.net","threadId":"23309","inReplyTo":"201004031629.01970.elendil@planet.nl","subject":"Re: Extremely slow progress during 'git reflog expire --all'","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2010-04-03T20:35:07Z","receivedAt":"2010-04-03T20:35:07Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"[sorry, resend, I managed to totally screw up Shawn's email in the last\none. Stupid mutt aliases.]\n\nOn Sat, Apr 03, 2010 at 04:29:01PM +0200, Frans Pop wrote:\n\n> On Saturday 03 April 2010, Jeff King wrote:\n> > > I can make that available, but it's going to take a while to upload\n> > > and I don't want to leave it up too long as I'll be abusing a project\n> > > service for that. So the people who want to look at it would have grab\n> > > it fairly promptly (within 2 days or so).\n> \n> The tarball is up at:\n> http://alioth.debian.org/~fjp/.tmp/linux-2.6_reflog-issue.tar\n> \n> Because of the Easter weekend I'll leave it up a bit longer. I plan to \n> remove it sometime on Thursday.\n\nThanks, I was able to get it and reproduce your problem. The slowness is\nin the expire-unreachable code. You can work around it with:\n\n git config gc.reflogExpireUnreachable never\n\nObviously that's not really a fix, but it should let your \"git gc\" work.\n\nIt looks like we do two merge-base calculations for each reflog entry,\nwhich is what takes so long. Perhaps if we know we are going to do a\nlarge number of reachability checks, we can pre-mark all reachable\ncommits, and then each reflog entry would just need to check the commit\nmark.\n\nI don't have any more time now to look at it, but I am cc'ing Junio (who\nwrote the original expire-unreachable code) and Shawn (the resident\nreflog expert), who may have more input.\n\n-Peff\n"},{"id":"138547","messageId":"7vy6h36pt1.fsf@alter.siamese.dyndns.org","threadId":"23309","inReplyTo":"20100403203507.GA12262@coredump.intra.peff.net","subject":"Re: Extremely slow progress during 'git reflog expire --all'","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2010-04-04T18:22:18Z","receivedAt":"2010-04-04T18:22:18Z","isPatch":false,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jeff King writes:\n\n> Thanks, I was able to get it and reproduce your problem. The slowness is\n> in the expire-unreachable code. You can work around it with:\n>\n> git config gc.reflogExpireUnreachable never\n>\n> Obviously that's not really a fix, but it should let your \"git gc\" work.\n>\n> It looks like we do two merge-base calculations for each reflog entry,\n> which is what takes so long. Perhaps if we know we are going to do a\n> large number of reachability checks, we can pre-mark all reachable\n> commits, and then each reflog entry would just need to check the commit\n> mark.\n\nThanks for the analysis, but expire_reflog() that is run for each ref\nalready does that, I think. It first runs mark_reachable(), then walks\neach reflog entry for the ref to call expire_reflog_ent(), which in turn\ncalls unreachable() that first checks if mark_reachable() has marked the\ncommit, and if so we don't run in_merge_bases().\n\nBut if the commit in question is not reachable, then we end up running\nin_merge_bases() to double-check anyway, which is probably the symptom\nthat was observed.\n\nSo perhaps this is a workable compromise?\n\n builtin/reflog.c | 7 +++++++\n 1 files changed, 7 insertions(+), 0 deletions(-)\n\ndiff --git a/builtin/reflog.c b/builtin/reflog.c\nindex 64e45bd..7e278b8 100644\n--- a/builtin/reflog.c\n+++ b/builtin/reflog.c\n@@ -230,6 +230,13 @@ static int unreachable(struct expire_reflog_cb *cb, struct commit *commit, unsig\n \t/* Reachable from the current ref? Don't prune. */\n \tif (commit->object.flags & REACHABLE)\n \t\treturn 0;\n+\t/*\n+\t * Unless there was a clock skew, younger ones that are\n+\t * reachable should have been marked by mark_reachable().\n+\t */\n+\tif (cb->cmd->expire_total < commit->date)\n+\t\treturn 1;\n+\n \tif (in_merge_bases(commit, &cb->ref_commit, 1))\n \t\treturn 0;\n \n"},{"id":"138582","messageId":"20100405062621.GA30934@coredump.intra.peff.net","threadId":"23309","inReplyTo":"7vy6h36pt1.fsf@alter.siamese.dyndns.org","subject":"Re: Extremely slow progress during 'git reflog expire --all'","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2010-04-05T06:26:21Z","receivedAt":"2010-04-05T06:26:21Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Sun, Apr 04, 2010 at 11:22:18AM -0700, Junio C Hamano wrote:\n\n> Thanks for the analysis, but expire_reflog() that is run for each ref\n> already does that, I think. It first runs mark_reachable(), then walks\n> each reflog entry for the ref to call expire_reflog_ent(), which in turn\n> calls unreachable() that first checks if mark_reachable() has marked the\n> commit, and if so we don't run in_merge_bases().\n\nHmm. It looks like mark_reachable() stops traversing when it hits a\ncommit older than expire_total. I imagine that's to avoid going all the\nway to the roots. But if we hit any unreachable entry, in_merge_bases()\nis going to have to go all the way to the roots, anyway.\n\nIf we just marked everything, couldn't we then trust the REACHABLE\nvalue and not have to do the in_merge_bases double-check? It has worse\nbest-case cost (since we always go to the root), but better worst-case\n(since we can potentially go to the roots for each unreachable reflog\nentry).\n\nFor example:\n\n> +\t/*\n> +\t * Unless there was a clock skew, younger ones that are\n> +\t * reachable should have been marked by mark_reachable().\n> +\t */\n> +\tif (cb->cmd->expire_total < commit->date)\n> +\t\treturn 1;\n> +\n> \tif (in_merge_bases(commit, &cb->ref_commit, 1))\n> \t\treturn 0;\n\nIf we haven't done a \"reflog expire\" in a while, won't we have a bunch\nof old commits that will still need double-checked, and produce the same\nslow behavior? Or is that what your \"clock skew\" is meant to mean? That\nwe would have removed those old ones already assuming the commit date\nand the reflog entry for them match up? That's not necessarily true if\nyou move to an older commit, which freshens its reflog entry compared to\nthe commit date.\n\nI wonder if, in addition to your patch, we should remove the\ndouble-check in_merge_bases and simply report those old ones as\nreachable. We may be wrong, but we are erring on the side of keeping\nentries, and they will eventually expire in the regular cycle (i.e., 90\ndays instead of 30).\n\nAll of that being said, your patch does drop Frans' case down to about\n1s of CPU time, so perhaps it is not worth worrying about beyond that.\n\n-Peff\n"},{"id":"138656","messageId":"7v1vetpw63.fsf@alter.siamese.dyndns.org","threadId":"23309","inReplyTo":"20100405062621.GA30934@coredump.intra.peff.net","subject":"Re: Extremely slow progress during 'git reflog expire --all'","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2010-04-05T18:54:28Z","receivedAt":"2010-04-05T18:54:28Z","isPatch":false,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jeff King writes:\n\n> Hmm. It looks like mark_reachable() stops traversing when it hits a\n> commit older than expire_total. I imagine that's to avoid going all the\n> way to the roots. But if we hit any unreachable entry, in_merge_bases()\n> is going to have to go all the way to the roots, anyway.\n\nYeah, an alternative is to keep the list of commits where the initial\nmark_reachable() run stopped, and instead of doing in_merge_bases(),\nlazily restart the traversal all the way down to root, and then rely\nsolely on the REACHABLE bit from then on.\n\n> Or is that what your \"clock skew\" is meant to mean?\n\nWhat I meant was you commit A, a child B, rewind clock to commit its child\nC at an incorrect and old time, and fix clock to commit its child D which\nis at the tip of a ref. mark_reachable() will stop at C saying that is\nsufficiently old and recent A and B may be pruned too early.\n\n> I wonder if, in addition to your patch, we should remove the\n> double-check in_merge_bases and simply report those old ones as\n> reachable. We may be wrong, but we are erring on the side of keeping\n> entries, and they will eventually expire in the regular cycle (i.e., 90\n> days instead of 30).\n>\n> All of that being said, your patch does drop Frans' case down to about\n> 1s of CPU time, so perhaps it is not worth worrying about beyond that.\n\nI think a reasonable solution would be along the lines you described, but\nthe patch you are responding to does err on the wrong side when a clock\nskew is there. Does it matter? Probably not.\n"},{"id":"138710","messageId":"20100406060217.GF3901@coredump.intra.peff.net","threadId":"23309","inReplyTo":"7v1vetpw63.fsf@alter.siamese.dyndns.org","subject":"Re: Extremely slow progress during 'git reflog expire --all'","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2010-04-06T06:02:17Z","receivedAt":"2010-04-06T06:02:17Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Mon, Apr 05, 2010 at 11:54:28AM -0700, Junio C Hamano wrote:\n\n> Jeff King writes:\n> \n> > Hmm. It looks like mark_reachable() stops traversing when it hits a\n> > commit older than expire_total. I imagine that's to avoid going all the\n> > way to the roots. But if we hit any unreachable entry, in_merge_bases()\n> > is going to have to go all the way to the roots, anyway.\n> \n> Yeah, an alternative is to keep the list of commits where the initial\n> mark_reachable() run stopped, and instead of doing in_merge_bases(),\n> lazily restart the traversal all the way down to root, and then rely\n> solely on the REACHABLE bit from then on.\n\nAh, yeah, that is much more clever. It has the same worst case\nperformance as what I proposed, but is much more optimistic that we\nwon't have to do it at all.\n\n> > I wonder if, in addition to your patch, we should remove the\n> > double-check in_merge_bases and simply report those old ones as\n> > reachable. We may be wrong, but we are erring on the side of keeping\n> > entries, and they will eventually expire in the regular cycle (i.e., 90\n> > days instead of 30).\n> >\n> > All of that being said, your patch does drop Frans' case down to about\n> > 1s of CPU time, so perhaps it is not worth worrying about beyond that.\n> \n> I think a reasonable solution would be along the lines you described, but\n> the patch you are responding to does err on the wrong side when a clock\n> skew is there. Does it matter? Probably not.\n\nTrue. With the technique you mentioned above, you would reverse your\ntest and do:\n\n if (flags & REACHABLE)\n return 0;\n if (expanded_reachable_to_root)\n return 1; /* we know it's not */\n expand_reachable_to_root();\n return !(flags & REACHABLE);\n\nI don't think I care enough to do a patch, though. I don't have a\nproblem with you applying what you posted earlier.\n\n-Peff\n"},{"id":"138872","messageId":"7vochvcdkc.fsf_-_@alter.siamese.dyndns.org","threadId":"23309","inReplyTo":"20100406060217.GF3901@coredump.intra.peff.net","subject":"Re*: Extremely slow progress during 'git reflog expire --all'","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2010-04-07T18:39:15Z","receivedAt":"2010-04-07T18:39:15Z","isPatch":false,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jeff King writes:\n\n> True. With the technique you mentioned above, you would reverse your\n> test and do:\n>\n> if (flags & REACHABLE)\n> return 0;\n> if (expanded_reachable_to_root)\n> return 1; /* we know it's not */\n> expand_reachable_to_root();\n> return !(flags & REACHABLE);\n>\n> I don't think I care enough to do a patch, though. I don't have a\n> problem with you applying what you posted earlier.\n\nActually I do; I think it breaks correctness a big way (the second\nparagraph of the proposed log message of the following).\n\n-- >8 --\nSubject: [PATCH] reflog --expire-unreachable: avoid merge-base computation\n\nThe option tells the command to expire older reflog entries that refer to\ncommits that are no longer reachable from the tip of the ref the reflog is\nassociated with. To avoid repeated merge_base() invocations, we used to\nmark commits that are known to be reachable by walking the history from\nthe tip until we hit commits that are older than expire-total (which is\nthe timestamp before which all the reflog entries are expired).\n\nHowever, it is a different matter if a commit is _not_ known to be\nreachable and the commit is known to be unreachable. Because you can\nrewind a ref to an ancient commit and then reset it back to the original\ntip, a recent reflog entry can point at a commit that older than the\nexpire-total timestamp and we shouldn't expire it. For that reason, we\nhad to run merge-base computation when a commit is _not_ known to be\nreachable.\n\nThis introduces a lazy/on-demand traversal of the history to mark\nreachable commits in steps. As before, we mark commits that are newer\nthan expire-total to optimize the normal case before walking reflog, but\nwe dig deeper from the commits the initial step left off when we encounter\na commit that is not known to be reachable.\n\nSigned-off-by: Junio C Hamano \n---\n\n * By the way, the following diff is extremely hard to read, as for some\n reason \"diff\" failed to notice that the only change is that we have\n added lines at the beginning of mark_reachable(), modified only the\n latter half of unreachable(), and moved mark_reachable() from after\n unreachable() to before. Neither \"git diff --patience\" nor running GNU\n diff on to blobs helps. Hmph...\n\n builtin-reflog.c | 96 +++++++++++++++++++++++++++++++----------------------\n 1 files changed, 56 insertions(+), 40 deletions(-)\n\ndiff --git a/builtin-reflog.c b/builtin-reflog.c\nindex 7498210..9792090 100644\n--- a/builtin-reflog.c\n+++ b/builtin-reflog.c\n@@ -36,6 +36,8 @@ struct expire_reflog_cb {\n \tFILE *newlog;\n \tconst char *ref;\n \tstruct commit *ref_commit;\n+\tstruct commit_list *mark_list;\n+\tunsigned long mark_limit;\n \tstruct cmd_reflog_expire_cb *cmd;\n \tunsigned char last_kept_sha1[20];\n };\n@@ -210,46 +212,23 @@ static int keep_entry(struct commit **it, unsigned char *sha1)\n \treturn 1;\n }\n \n-static int unreachable(struct expire_reflog_cb *cb, struct commit *commit, unsigned char *sha1)\n+/*\n+ * Starting from commits in the cb->mark_list, mark commits that are\n+ * reachable from them. Stop the traversal at commits older than\n+ * the expire_limit and queue them back, so that the caller can call\n+ * us again to restart the traversal with longer expire_limit.\n+ */\n+static void mark_reachable(struct expire_reflog_cb *cb)\n {\n-\t/*\n-\t * We may or may not have the commit yet - if not, look it\n-\t * up using the supplied sha1.\n-\t */\n-\tif (!commit) {\n-\t\tif (is_null_sha1(sha1))\n-\t\t\treturn 0;\n-\n-\t\tcommit = lookup_commit_reference_gently(sha1, 1);\n-\n-\t\t/* Not a commit -- keep it */\n-\t\tif (!commit)\n-\t\t\treturn 0;\n-\t}\n-\n-\t/* Reachable from the current ref? Don't prune. */\n-\tif (commit->object.flags & REACHABLE)\n-\t\treturn 0;\n-\tif (in_merge_bases(commit, &cb->ref_commit, 1))\n-\t\treturn 0;\n-\n-\t/* We can't reach it - prune it. */\n-\treturn 1;\n-}\n+\tstruct commit *commit;\n+\tstruct commit_list *pending;\n+\tunsigned long expire_limit = cb->mark_limit;\n+\tstruct commit_list *leftover = NULL;\n \n-static void mark_reachable(struct commit *commit, unsigned long expire_limit)\n-{\n-\t/*\n-\t * We need to compute whether the commit on either side of a reflog\n-\t * entry is reachable from the tip of the ref for all entries.\n-\t * Mark commits that are reachable from the tip down to the\n-\t * time threshold first; we know a commit marked thusly is\n-\t * reachable from the tip without running in_merge_bases()\n-\t * at all.\n-\t */\n-\tstruct commit_list *pending = NULL;\n+\tfor (pending = cb->mark_list; pending; pending = pending->next)\n+\t\tpending->item->object.flags &= ~REACHABLE;\n \n-\tcommit_list_insert(commit, &pending);\n+\tpending = cb->mark_list;\n \twhile (pending) {\n \t\tstruct commit_list *entry = pending;\n \t\tstruct commit_list *parent;\n@@ -261,8 +240,11 @@ static void mark_reachable(struct commit *commit, unsigned long expire_limit)\n \t\tif (parse_commit(commit))\n \t\t\tcontinue;\n \t\tcommit->object.flags |= REACHABLE;\n-\t\tif (commit->date < expire_limit)\n+\t\tif (commit->date < expire_limit) {\n+\t\t\tcommit_list_insert(commit, &leftover);\n \t\t\tcontinue;\n+\t\t}\n+\t\tcommit->object.flags |= REACHABLE;\n \t\tparent = commit->parents;\n \t\twhile (parent) {\n \t\t\tcommit = parent->item;\n@@ -272,6 +254,36 @@ static void mark_reachable(struct commit *commit, unsigned long expire_limit)\n \t\t\tcommit_list_insert(commit, &pending);\n \t\t}\n \t}\n+\tcb->mark_list = leftover;\n+}\n+\n+static int unreachable(struct expire_reflog_cb *cb, struct commit *commit, unsigned char *sha1)\n+{\n+\t/*\n+\t * We may or may not have the commit yet - if not, look it\n+\t * up using the supplied sha1.\n+\t */\n+\tif (!commit) {\n+\t\tif (is_null_sha1(sha1))\n+\t\t\treturn 0;\n+\n+\t\tcommit = lookup_commit_reference_gently(sha1, 1);\n+\n+\t\t/* Not a commit -- keep it */\n+\t\tif (!commit)\n+\t\t\treturn 0;\n+\t}\n+\n+\t/* Reachable from the current ref? Don't prune. */\n+\tif (commit->object.flags & REACHABLE)\n+\t\treturn 0;\n+\n+\tif (cb->mark_list && cb->mark_limit) {\n+\t\tcb->mark_limit = 0; /* dig down to the root */\n+\t\tmark_reachable(cb);\n+\t}\n+\n+\treturn !(commit->object.flags & REACHABLE);\n }\n \n static int expire_reflog_ent(unsigned char *osha1, unsigned char *nsha1,\n@@ -348,8 +360,12 @@ static int expire_reflog(const char *ref, const unsigned char *sha1, int unused,\n \tcb.ref_commit = lookup_commit_reference_gently(sha1, 1);\n \tcb.ref = ref;\n \tcb.cmd = cmd;\n-\tif (cb.ref_commit)\n-\t\tmark_reachable(cb.ref_commit, cmd->expire_total);\n+\tif (cb.ref_commit) {\n+\t\tcb.mark_list = NULL;\n+\t\tcommit_list_insert(cb.ref_commit, &cb.mark_list);\n+\t\tcb.mark_limit = cmd->expire_total;\n+\t\tmark_reachable(&cb);\n+\t}\n \tfor_each_reflog_ent(ref, expire_reflog_ent, &cb);\n \tif (cb.ref_commit)\n \t\tclear_commit_marks(cb.ref_commit, REACHABLE);\n-- \n1.7.1.rc0.212.gbd88f\n"},{"id":"138873","messageId":"7vk4sjcddh.fsf@alter.siamese.dyndns.org","threadId":"23309","inReplyTo":"7vochvcdkc.fsf_-_@alter.siamese.dyndns.org","subject":"Re: Re*: Extremely slow progress during 'git reflog expire --all'","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2010-04-07T18:43:22Z","receivedAt":"2010-04-07T18:43:22Z","isPatch":false,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Side note.\n\nIt may be an improvement to dig the history even more incrementally.\n\nInside unreachable(), we currently dig immediately down to root, but it\nmay give us a better performance in a long history with reflog entries\nthat wildly jump everywhere in that history if we dug down to the\ntimestamp of the commit we are looking at. A patch to do so on top of the\nprevious one may look like this.\n\n builtin-reflog.c | 17 ++++++++++-------\n 1 files changed, 10 insertions(+), 7 deletions(-)\n\ndiff --git a/builtin-reflog.c b/builtin-reflog.c\nindex 9792090..42d225f 100644\n--- a/builtin-reflog.c\n+++ b/builtin-reflog.c\n@@ -274,16 +274,19 @@ static int unreachable(struct expire_reflog_cb *cb, struct commit *commit, unsig\n \t\t\treturn 0;\n \t}\n \n-\t/* Reachable from the current ref? Don't prune. */\n-\tif (commit->object.flags & REACHABLE)\n-\t\treturn 0;\n+\twhile (1) {\n+\t\t/* Reachable from the current ref? Don't prune. */\n+\t\tif (commit->object.flags & REACHABLE)\n+\t\t\treturn 0;\n \n-\tif (cb->mark_list && cb->mark_limit) {\n-\t\tcb->mark_limit = 0; /* dig down to the root */\n+\t\t/* Did we mark everything? Then we know we cannot reach it. */\n+\t\tif (!cb->mark_list || !cb->mark_limit)\n+\t\t\treturn 1;\n+\n+\t\t/* Dig down to the timestamp of this commit, or down to root. */\n+\t\tcb->mark_limit = (cb->mark_limit < commit->date) ? 0 : commit->date;\n \t\tmark_reachable(cb);\n \t}\n-\n-\treturn !(commit->object.flags & REACHABLE);\n }\n \n static int expire_reflog_ent(unsigned char *osha1, unsigned char *nsha1,\n-- \n1.7.1.rc0.212.gbd88f\n"},{"id":"138940","messageId":"20100408065221.GF30473@coredump.intra.peff.net","threadId":"23309","inReplyTo":"7vochvcdkc.fsf_-_@alter.siamese.dyndns.org","subject":"Re: Re*: Extremely slow progress during 'git reflog expire --all'","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2010-04-08T06:52:21Z","receivedAt":"2010-04-08T06:52:21Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Wed, Apr 07, 2010 at 11:39:15AM -0700, Junio C Hamano wrote:\n\n> Actually I do; I think it breaks correctness a big way (the second\n> paragraph of the proposed log message of the following).\n> [...]\n> However, it is a different matter if a commit is _not_ known to be\n> reachable and the commit is known to be unreachable. Because you can\n> rewind a ref to an ancient commit and then reset it back to the original\n> tip, a recent reflog entry can point at a commit that older than the\n> expire-total timestamp and we shouldn't expire it. For that reason, we\n> had to run merge-base computation when a commit is _not_ known to be\n> reachable.\n\nOh, right. Didn't I even mention that case earlier in the thread? I was\njust being dumb. Or maybe I was pretending to be dumb, so that I could\ntrick you into writing the patch. Who knows?\n\n> [patch]\n\nPatch looked fine from my reading. I no longer have Frans' gigantic test\nrepo available, though, so I can't test whether it fixes the problem\n(but I'm pretty sure it must from my earlier analysis).\n\n-Peff\n"},{"id":"138941","messageId":"20100408070050.GG30473@coredump.intra.peff.net","threadId":"23309","inReplyTo":"7vk4sjcddh.fsf@alter.siamese.dyndns.org","subject":"Re: Re*: Extremely slow progress during 'git reflog expire --all'","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2010-04-08T07:00:50Z","receivedAt":"2010-04-08T07:00:50Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Wed, Apr 07, 2010 at 11:43:22AM -0700, Junio C Hamano wrote:\n\n> Side note.\n> \n> It may be an improvement to dig the history even more incrementally.\n\nI doubt it matters much in practice. The important features of the\nsolution are:\n\n - for most refs, which are either all-reachable or which don't have\n clock skew, don't go to the roots at all. This is the fast case that\n we should do most of the time.\n\n - for others, don't go to the roots over and over for each entry. This\n is the slow case, but we just need to make sure it's a not the\n horrible slow case that Frans saw.\n\nYour suggestion speeds up the slow case a little bit, but it is already\nacceptably fast. Plus this is an optimistic optimization. There are\nstill cases where you might have to dig to the roots anyway (e.g.,\nwhenever you have anything unreachable).\n\n> Inside unreachable(), we currently dig immediately down to root, but it\n> may give us a better performance in a long history with reflog entries\n> that wildly jump everywhere in that history if we dug down to the\n> timestamp of the commit we are looking at. A patch to do so on top of the\n> previous one may look like this.\n\nWhy dig to the timestamp? You know you're looking for a particular\ncommit, so you can dig down to that commit. If it's reachable, stop\nthere and you have your answer. Any work you do beyond that might be\nused for a further entry lookup, but it might not at all. If it's not\nreachable, then you're going to end up digging down to the roots anyway.\n\nWith an unreachable ref and your scheme, you would just end up not\nfinding it, extending again, not finding it, extending again, etc. But\nyou can never be sure it's truly unreachable without going to the roots\nor assuming no clock skew, so that is what we'll end up doing.\n\n-Peff\n"}]}