{"thread":{"id":"31920","subject":"Long clone time after \"done.\"","startedAt":"2012-10-23T18:30:56Z","lastAt":"2012-11-26T18:06:26Z","messageCount":13,"participants":["Uri Moszkowicz","Nguyen Thai Ngoc Duy","Jeff King"],"isPatch":false,"patchVersion":null,"patchTotal":null},"messages":[{"id":"201743","messageId":"CAMJd5AQBbnFqT5xrFuPOEsJevwDE=jUgBVFZ5KqTZk5zv5+NOw@mail.gmail.com","threadId":"31920","inReplyTo":null,"subject":"Long clone time after \"done.\"","fromName":"Uri Moszkowicz","fromEmail":"uri@4refs.com","sentAt":"2012-10-23T18:30:56Z","receivedAt":"2012-10-23T18:30:56Z","isPatch":false,"sender":{"key":"uri@4refs.com","avatar":null},"body":"I have a large repository which I ran \"git gc --aggressive\" on that\nI'm trying to clone on a local file system. I would expect it to\ncomplete very quickly with hard links but it's taking about 6min to\ncomplete with no checkout (git clone -n). I see the message \"Clining\ninto 'repos'... done.\" appear after a few seconds but then Git just\nhangs there for another 6min. Any idea what it's doing at this point\nand how I can speed it up?\n"},{"id":"201787","messageId":"CACsJy8DvNSVSUT_9ym52pVaDSNMk10WfaVGhfgQeC8+SOWSpEw@mail.gmail.com","threadId":"31920","inReplyTo":"CAMJd5AQBbnFqT5xrFuPOEsJevwDE=jUgBVFZ5KqTZk5zv5+NOw@mail.gmail.com","subject":"Re: Long clone time after \"done.\"","fromName":"Nguyen Thai Ngoc Duy","fromEmail":"pclouds@gmail.com","sentAt":"2012-10-24T04:29:00Z","receivedAt":"2012-10-24T04:29:00Z","isPatch":false,"sender":{"key":"pclouds@gmail.com","avatar":"https://avatars.githubusercontent.com/u/720?v=4"},"body":"On Wed, Oct 24, 2012 at 1:30 AM, Uri Moszkowicz wrote:\n> I have a large repository which I ran \"git gc --aggressive\" on that\n> I'm trying to clone on a local file system. I would expect it to\n> complete very quickly with hard links but it's taking about 6min to\n> complete with no checkout (git clone -n). I see the message \"Clining\n> into 'repos'... done.\" appear after a few seconds but then Git just\n> hangs there for another 6min. Any idea what it's doing at this point\n> and how I can speed it up?\n\n\"done.\" is printed by clone_local(), which is called in cmd_clone().\nAfter that there are just a few more calls. Maybe you could add a few\nprintf in between these calls, see which one takes most time?\n-- \nDuy\n"},{"id":"201813","messageId":"CAMJd5ASAshzH3VTMkiOZZd5ODMoJa73=awpC7q4H7K+DVbBjKw@mail.gmail.com","threadId":"31920","inReplyTo":"CACsJy8DvNSVSUT_9ym52pVaDSNMk10WfaVGhfgQeC8+SOWSpEw@mail.gmail.com","subject":"Re: Long clone time after \"done.\"","fromName":"Uri Moszkowicz","fromEmail":"uri@4refs.com","sentAt":"2012-10-24T17:14:17Z","receivedAt":"2012-10-24T17:14:17Z","isPatch":false,"sender":{"key":"uri@4refs.com","avatar":null},"body":"It all goes to pack_refs() in write_remote_refs called from\nupdate_remote_refs().\n\nOn Tue, Oct 23, 2012 at 11:29 PM, Nguyen Thai Ngoc Duy\n wrote:\n> On Wed, Oct 24, 2012 at 1:30 AM, Uri Moszkowicz wrote:\n>> I have a large repository which I ran \"git gc --aggressive\" on that\n>> I'm trying to clone on a local file system. I would expect it to\n>> complete very quickly with hard links but it's taking about 6min to\n>> complete with no checkout (git clone -n). I see the message \"Clining\n>> into 'repos'... done.\" appear after a few seconds but then Git just\n>> hangs there for another 6min. Any idea what it's doing at this point\n>> and how I can speed it up?\n>\n> \"done.\" is printed by clone_local(), which is called in cmd_clone().\n> After that there are just a few more calls. Maybe you could add a few\n> printf in between these calls, see which one takes most time?\n> --\n> Duy\n"},{"id":"202617","messageId":"CAMJd5ASL1UPfzUmfXqACuYuGhXQjJLqbsjq7dfpRpF4K-hZFtA@mail.gmail.com","threadId":"31920","inReplyTo":"CAMJd5AQBbnFqT5xrFuPOEsJevwDE=jUgBVFZ5KqTZk5zv5+NOw@mail.gmail.com","subject":"Re: Long clone time after \"done.\"","fromName":"Uri Moszkowicz","fromEmail":"uri@4refs.com","sentAt":"2012-11-07T17:32:37Z","receivedAt":"2012-11-07T17:32:37Z","isPatch":false,"sender":{"key":"uri@4refs.com","avatar":null},"body":"To elaborate from before, my repository is about 2GB and has about 7k\nbranches and tags with 15 years of history imported from CVS. I\ncreated a toy repository attempting to replicate the problem but\nhaven't had any luck so instead I launched Git in a debugger to see\nwhat operation is taking so long in \"git clone\". I stopped randomly in\nthe middle and stepped to the line which seems to be contributing the\nmost:\n\n #0 read_packed_sha1 (sha1=0xb0ee98\n\"\\017C\\205Wj\\001`\\254\\356\\307Z\\332\\367\\353\\233.\\375P}D\",\ntype=0x7fbfffe7a4, size=0x7fbfffe798) at sha1_file.c:2237\n #1 0x00000000004d366e in read_object (sha1=0xb0ee98\n\"\\017C\\205Wj\\001`\\254\\356\\307Z\\332\\367\\353\\233.\\375P}D\",\ntype=0x7fbfffe7a4, size=0x7fbfffe798) at sha1_file.c:2277\n #2 0x00000000004d3839 in read_sha1_file_extended (sha1=0xb0ee98\n\"\\017C\\205Wj\\001`\\254\\356\\307Z\\332\\367\\353\\233.\\375P}D\",\ntype=0x7fbfffe7a4, size=0x7fbfffe798, flag=) at\nsha1_file.c:2307\n #3 0x00000000004ae000 in read_sha1_file (sha1=0x7fbfffc5e0 \"\",\ntype=0x6be000, size=0x2b039b9010) at cache.h:730\n #4 parse_object (sha1=0xb0ee98\n\"\\017C\\205Wj\\001`\\254\\356\\307Z\\332\\367\\353\\233.\\375P}D\") at\nobject.c:212\n #5 0x00000000004ae9ec in handle_one_ref (path=0xb0eec0\n\"refs/tags/\", sha1=0xb0ee98\n\"\\017C\\205Wj\\001`\\254\\356\\307Z\\332\\367\\353\\233.\\375P}D\", flags=2,\ncb_data=) at pack-refs.\n #6 0x00000000004bc402 in do_one_ref (base=,\nfn=0x4ae8f0 , trim=, flags=0,\ncb_data=0x7fbfffe9c0, entry=0xb0ee90) at refs.c:527\n #7 0x00000000004bd38b in do_for_each_ref_in_dir (dir=0xb09be8,\noffset=, base=0x4fd9b0 \"\", fn=0x4ae8f0\n, trim=0, flags=0, cb_data=0x7fbfffe9c0) at refs.c:553\n #8 0x00000000004bd6cb in do_for_each_ref_in_dirs (dir1=0x6a8588,\ndir2=0xb0ab18, base=0x4fd9b0 \"\", fn=0x4ae8f0 , trim=0,\nflags=0, cb_data=0x7fbfffe9c0) at refs.c:599\n #9 0x00000000004bd6cb in do_for_each_ref_in_dirs (dir1=0x6a3118,\ndir2=0xb038b8, base=0x4fd9b0 \"\", fn=0x4ae8f0 , trim=0,\nflags=0, cb_data=0x7fbfffe9c0) at refs.c:599\n #10 0x00000000004bdb3f in do_for_each_ref (submodule=, base=0x4fd9b0 \"\", fn=0x4ae8f0 , trim=0, flags=0,\ncb_data=0x7fbfffe9c0) at refs.c:1288\n #11 0x00000000004aeaba in pack_refs (flags=) at pack-refs.c:133\n #12 0x000000000041da30 in write_remote_refs (local_refs=) at builtin/clone.c:470\n #13 update_remote_refs (refs=, mapped_refs=, remote_head_points_at=, branch_top=0x6a4210\n\"refs/remotes/origin/\", msg=0x6a1160 \"clone: from\n/z/umoszkow/git/clone/../merged/merged.git\") at bu\n #14 cmd_clone (argc=, argv=0x7fbffff1b0,\nprefix=) at builtin/clone.c:898\n #15 0x0000000000404eef in handle_internal_command (argc=3,\nargv=0x7fbffff1b0) at git.c:306\n #16 0x0000000000405347 in run_argv (argcp=,\nargv=) at git.c:513\n #17 main (argc=3, argv=0x7fbffff1b0) at git.c:588\n\nIt looks like handle_one_ref() is called for each ref and most result\nin a call to read_sha1_file(). It only takes a second or so for each\ncall but when you have thousands of them (one for each ref) it adds\nup. Adding --single-branch --branch doesn't appear to help as\nit is implemented afterwards. I would like to debug this problem\nfurther but am not familiar enough with the implementation to know\nwhat the next step is. Can anyone offer some suggestions? I don't see\nwhy a clone should be dependent on an O(#refs) operations.\n\nOn Tue, Oct 23, 2012 at 1:30 PM, Uri Moszkowicz wrote:\n> I have a large repository which I ran \"git gc --aggressive\" on that\n> I'm trying to clone on a local file system. I would expect it to\n> complete very quickly with hard links but it's taking about 6min to\n> complete with no checkout (git clone -n). I see the message \"Clining\n> into 'repos'... done.\" appear after a few seconds but then Git just\n> hangs there for another 6min. Any idea what it's doing at this point\n> and how I can speed it up?\n"},{"id":"202647","messageId":"20121108155607.GD15560@sigill.intra.peff.net","threadId":"31920","inReplyTo":"CAMJd5ASL1UPfzUmfXqACuYuGhXQjJLqbsjq7dfpRpF4K-hZFtA@mail.gmail.com","subject":"Re: Long clone time after \"done.\"","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2012-11-08T15:56:07Z","receivedAt":"2012-11-08T15:56:07Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Wed, Nov 07, 2012 at 11:32:37AM -0600, Uri Moszkowicz wrote:\n\n> #4 parse_object (sha1=0xb0ee98\n> \"\\017C\\205Wj\\001`\\254\\356\\307Z\\332\\367\\353\\233.\\375P}D\") at\n> object.c:212\n> #5 0x00000000004ae9ec in handle_one_ref (path=0xb0eec0\n> \"refs/tags/\", sha1=0xb0ee98\n> \"\\017C\\205Wj\\001`\\254\\356\\307Z\\332\\367\\353\\233.\\375P}D\", flags=2,\n> cb_data=) at pack-refs.\n>\n> [...]\n> \n> It looks like handle_one_ref() is called for each ref and most result\n> in a call to read_sha1_file().\n\nRight. When generating the packed-refs file, we include the \"peeled\"\nreference for a tag (i.e., the commit that a tag object points to). So\nwe have to actually read any tag objects to get the value.\n\nThe upload-pack program generates a similar list, and I recently added\nsome optimizations. This code path could benefit from some of them by\nusing \"peel_ref\" instead of hand-rolling the tag dereferencing. The main\noptimization, though, is reusing peeled values that are already in\npacked-refs; we would probably need some additional magic to reuse the\nvalues from the source repository.\n\nHowever:\n\n> It only takes a second or so for each call but when you have thousands\n> of them (one for each ref) it adds up.\n\nI am more concerned that it takes a second to read each tag. Even in my\npathological tests for optimizing upload-pack, peeling 50,000 refs took\nonly half a second.\n\n> Adding --single-branch --branch doesn't appear to help as\n> it is implemented afterwards. I would like to debug this problem\n> further but am not familiar enough with the implementation to know\n> what the next step is. Can anyone offer some suggestions? I don't see\n> why a clone should be dependent on an O(#refs) operations.\n\nDoes this patch help? In a sample repo with 5000 annotated tags, it\ndrops my local clone time from 0.20s to 0.11s. Which is a big percentage\nspeedup, but this code isn't taking a long time in the first place for\nme.\n\n---\ndiff --git a/pack-refs.c b/pack-refs.c\nindex f09a054..3344749 100644\n--- a/pack-refs.c\n+++ b/pack-refs.c\n@@ -40,13 +40,9 @@ static int handle_one_ref(const char *path, const unsigned char *sha1,\n \n \tfprintf(cb->refs_file, \"%s %s\\n\", sha1_to_hex(sha1), path);\n \tif (is_tag_ref) {\n-\t\tstruct object *o = parse_object(sha1);\n-\t\tif (o->type == OBJ_TAG) {\n-\t\t\to = deref_tag(o, path, 0);\n-\t\t\tif (o)\n-\t\t\t\tfprintf(cb->refs_file, \"^%s\\n\",\n-\t\t\t\t\tsha1_to_hex(o->sha1));\n-\t\t}\n+\t\tunsigned char peeled[20];\n+\t\tif (!peel_ref(path, peeled))\n+\t\t\tfprintf(cb->refs_file, \"^%s\\n\", sha1_to_hex(peeled));\n \t}\n \n \tif ((cb->flags & PACK_REFS_PRUNE) && !do_not_prune(flags)) {\n"},{"id":"202655","messageId":"CAMJd5AQ24u11BH6rMAHvR95N4ys6KHfEQKD1uLzr+=TDgN_69Q@mail.gmail.com","threadId":"31920","inReplyTo":"20121108155607.GD15560@sigill.intra.peff.net","subject":"Re: Long clone time after \"done.\"","fromName":"Uri Moszkowicz","fromEmail":"uri@4refs.com","sentAt":"2012-11-08T17:20:29Z","receivedAt":"2012-11-08T17:20:29Z","isPatch":false,"sender":{"key":"uri@4refs.com","avatar":null},"body":"I tried the patch but it doesn't appear to have helped :( Clone time\nwith it was ~32m.\n\nDo you all by any chance have a tool to obfuscate a repository?\nProbably I still wouldn't be permitted to distribute it but might make\nthe option slightly more palatable. Anything else that I can do to\nhelp debug this problem?\n\nOn Thu, Nov 8, 2012 at 9:56 AM, Jeff King wrote:\n> On Wed, Nov 07, 2012 at 11:32:37AM -0600, Uri Moszkowicz wrote:\n>\n>> #4 parse_object (sha1=0xb0ee98\n>> \"\\017C\\205Wj\\001`\\254\\356\\307Z\\332\\367\\353\\233.\\375P}D\") at\n>> object.c:212\n>> #5 0x00000000004ae9ec in handle_one_ref (path=0xb0eec0\n>> \"refs/tags/\", sha1=0xb0ee98\n>> \"\\017C\\205Wj\\001`\\254\\356\\307Z\\332\\367\\353\\233.\\375P}D\", flags=2,\n>> cb_data=) at pack-refs.\n>>\n>> [...]\n>>\n>> It looks like handle_one_ref() is called for each ref and most result\n>> in a call to read_sha1_file().\n>\n> Right. When generating the packed-refs file, we include the \"peeled\"\n> reference for a tag (i.e., the commit that a tag object points to). So\n> we have to actually read any tag objects to get the value.\n>\n> The upload-pack program generates a similar list, and I recently added\n> some optimizations. This code path could benefit from some of them by\n> using \"peel_ref\" instead of hand-rolling the tag dereferencing. The main\n> optimization, though, is reusing peeled values that are already in\n> packed-refs; we would probably need some additional magic to reuse the\n> values from the source repository.\n>\n> However:\n>\n>> It only takes a second or so for each call but when you have thousands\n>> of them (one for each ref) it adds up.\n>\n> I am more concerned that it takes a second to read each tag. Even in my\n> pathological tests for optimizing upload-pack, peeling 50,000 refs took\n> only half a second.\n>\n>> Adding --single-branch --branch doesn't appear to help as\n>> it is implemented afterwards. I would like to debug this problem\n>> further but am not familiar enough with the implementation to know\n>> what the next step is. Can anyone offer some suggestions? I don't see\n>> why a clone should be dependent on an O(#refs) operations.\n>\n> Does this patch help? In a sample repo with 5000 annotated tags, it\n> drops my local clone time from 0.20s to 0.11s. Which is a big percentage\n> speedup, but this code isn't taking a long time in the first place for\n> me.\n>\n> ---\n> diff --git a/pack-refs.c b/pack-refs.c\n> index f09a054..3344749 100644\n> --- a/pack-refs.c\n> +++ b/pack-refs.c\n> @@ -40,13 +40,9 @@ static int handle_one_ref(const char *path, const unsigned char *sha1,\n>\n> fprintf(cb->refs_file, \"%s %s\\n\", sha1_to_hex(sha1), path);\n> if (is_tag_ref) {\n> - struct object *o = parse_object(sha1);\n> - if (o->type == OBJ_TAG) {\n> - o = deref_tag(o, path, 0);\n> - if (o)\n> - fprintf(cb->refs_file, \"^%s\\n\",\n> - sha1_to_hex(o->sha1));\n> - }\n> + unsigned char peeled[20];\n> + if (!peel_ref(path, peeled))\n> + fprintf(cb->refs_file, \"^%s\\n\", sha1_to_hex(peeled));\n> }\n>\n> if ((cb->flags & PACK_REFS_PRUNE) && !do_not_prune(flags)) {\n"},{"id":"202668","messageId":"20121108203332.GQ15560@sigill.intra.peff.net","threadId":"31920","inReplyTo":"CAMJd5AQ24u11BH6rMAHvR95N4ys6KHfEQKD1uLzr+=TDgN_69Q@mail.gmail.com","subject":"Re: Long clone time after \"done.\"","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2012-11-08T20:33:32Z","receivedAt":"2012-11-08T20:33:32Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Nov 08, 2012 at 11:20:29AM -0600, Uri Moszkowicz wrote:\n\n> I tried the patch but it doesn't appear to have helped :( Clone time\n> with it was ~32m.\n\nThat sounds ridiculously long.\n\n> Do you all by any chance have a tool to obfuscate a repository?\n> Probably I still wouldn't be permitted to distribute it but might make\n> the option slightly more palatable. Anything else that I can do to\n> help debug this problem?\n\nI don't have anything already written. What platform are you on? If it's\nLinux, can you try using \"perf\" to record where the time is going?\n\nHow many refs do you have? What does:\n\n echo \"heads: $(git for-each-ref refs/heads | wc -l)\"\n echo \" tags: $(git for-each-ref refs/tags | wc -l)\"\n\nreport? How long does it take to look up a tag, like:\n\n time git cat-file tag refs/tags/some-tag\n\n?\n\n-Peff\n"},{"id":"202671","messageId":"CAMJd5ARLCk_WQTbyLciv0LnrMa_J0YstNsrq-hLYM5DXiO0hLA@mail.gmail.com","threadId":"31920","inReplyTo":"20121108203332.GQ15560@sigill.intra.peff.net","subject":"Re: Long clone time after \"done.\"","fromName":"Uri Moszkowicz","fromEmail":"uri@4refs.com","sentAt":"2012-11-08T21:49:32Z","receivedAt":"2012-11-08T21:49:32Z","isPatch":false,"sender":{"key":"uri@4refs.com","avatar":null},"body":"I'm using RHEL4. Looks like perf is only available with RHEL6.\n\nheads: 308\ntags: 9614\n\nLooking up the tags that way took a very long time by the way. \"git\ntag | wc -l\" was much quicker. I've already pruned a lot of tags to\nget to this number as well. The original repository had ~37k tags\nsince we used to tag every commit with CVS.\n\nAll my tags are packed so cat-file doesn't work:\nfatal: git cat-file refs/tags/some-tag: bad file\n\nOn Thu, Nov 8, 2012 at 2:33 PM, Jeff King wrote:\n> On Thu, Nov 08, 2012 at 11:20:29AM -0600, Uri Moszkowicz wrote:\n>\n>> I tried the patch but it doesn't appear to have helped :( Clone time\n>> with it was ~32m.\n>\n> That sounds ridiculously long.\n>\n>> Do you all by any chance have a tool to obfuscate a repository?\n>> Probably I still wouldn't be permitted to distribute it but might make\n>> the option slightly more palatable. Anything else that I can do to\n>> help debug this problem?\n>\n> I don't have anything already written. What platform are you on? If it's\n> Linux, can you try using \"perf\" to record where the time is going?\n>\n> How many refs do you have? What does:\n>\n> echo \"heads: $(git for-each-ref refs/heads | wc -l)\"\n> echo \" tags: $(git for-each-ref refs/tags | wc -l)\"\n>\n> report? How long does it take to look up a tag, like:\n>\n> time git cat-file tag refs/tags/some-tag\n>\n> ?\n>\n> -Peff\n"},{"id":"202672","messageId":"20121108221128.GA11186@sigill.intra.peff.net","threadId":"31920","inReplyTo":"CAMJd5ARLCk_WQTbyLciv0LnrMa_J0YstNsrq-hLYM5DXiO0hLA@mail.gmail.com","subject":"Re: Long clone time after \"done.\"","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2012-11-08T22:11:28Z","receivedAt":"2012-11-08T22:11:28Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Nov 08, 2012 at 03:49:32PM -0600, Uri Moszkowicz wrote:\n\n> I'm using RHEL4. Looks like perf is only available with RHEL6.\n\nYeah, RHEL4 is pretty ancient; I think it predates the invention of\n\"perf\".\n\n> heads: 308\n> tags: 9614\n> \n> Looking up the tags that way took a very long time by the way. \"git\n> tag | wc -l\" was much quicker. I've already pruned a lot of tags to\n> get to this number as well. The original repository had ~37k tags\n> since we used to tag every commit with CVS.\n\nHmm. I think for-each-ref will actually open the tag objects, but \"git\ntag\" will not. That would imply that reading the refs is fast, but\nopening objects is slow. I wonder why.\n\nHow many packs do you have in .git/objects/pack of the repository?\n\n> All my tags are packed so cat-file doesn't work:\n> fatal: git cat-file refs/tags/some-tag: bad file\n\nThe packing shouldn't matter. The point of the command is to look up the\nrefs/tags/some-tag ref (in packed-refs or in the filesystem), and then\nopen and write the pointed-to object to stdout. If that is not working,\nthen there is something seriously wrong going on.\n\n-Peff\n"},{"id":"202673","messageId":"CAMJd5ATX5Ru9Orp2t3p39q7tsNRfGjqDYGnf4-9QYNSTpQ-YuA@mail.gmail.com","threadId":"31920","inReplyTo":"20121108221128.GA11186@sigill.intra.peff.net","subject":"Re: Long clone time after \"done.\"","fromName":"Uri Moszkowicz","fromEmail":"uri@4refs.com","sentAt":"2012-11-08T22:16:59Z","receivedAt":"2012-11-08T22:16:59Z","isPatch":false,"sender":{"key":"uri@4refs.com","avatar":null},"body":"I ran \"git cat-file commit some-tag\" for every tag. They seem to be\nroughly uniformly distributed between 0s and 2s and about 2/3 of the\ntime seems to be system. My disk is mounted over NFS so I tried on the\nlocal disk and it didn't make a difference.\n\nI have only one 1.97GB pack. I ran \"git gc --aggressive\" before.\n\nOn Thu, Nov 8, 2012 at 4:11 PM, Jeff King wrote:\n> On Thu, Nov 08, 2012 at 03:49:32PM -0600, Uri Moszkowicz wrote:\n>\n>> I'm using RHEL4. Looks like perf is only available with RHEL6.\n>\n> Yeah, RHEL4 is pretty ancient; I think it predates the invention of\n> \"perf\".\n>\n>> heads: 308\n>> tags: 9614\n>>\n>> Looking up the tags that way took a very long time by the way. \"git\n>> tag | wc -l\" was much quicker. I've already pruned a lot of tags to\n>> get to this number as well. The original repository had ~37k tags\n>> since we used to tag every commit with CVS.\n>\n> Hmm. I think for-each-ref will actually open the tag objects, but \"git\n> tag\" will not. That would imply that reading the refs is fast, but\n> opening objects is slow. I wonder why.\n>\n> How many packs do you have in .git/objects/pack of the repository?\n>\n>> All my tags are packed so cat-file doesn't work:\n>> fatal: git cat-file refs/tags/some-tag: bad file\n>\n> The packing shouldn't matter. The point of the command is to look up the\n> refs/tags/some-tag ref (in packed-refs or in the filesystem), and then\n> open and write the pointed-to object to stdout. If that is not working,\n> then there is something seriously wrong going on.\n>\n> -Peff\n"},{"id":"202674","messageId":"20121108223319.GA11734@sigill.intra.peff.net","threadId":"31920","inReplyTo":"CAMJd5ATX5Ru9Orp2t3p39q7tsNRfGjqDYGnf4-9QYNSTpQ-YuA@mail.gmail.com","subject":"Re: Long clone time after \"done.\"","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2012-11-08T22:33:19Z","receivedAt":"2012-11-08T22:33:19Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Nov 08, 2012 at 04:16:59PM -0600, Uri Moszkowicz wrote:\n\n> I ran \"git cat-file commit some-tag\" for every tag. They seem to be\n> roughly uniformly distributed between 0s and 2s and about 2/3 of the\n> time seems to be system. My disk is mounted over NFS so I tried on the\n> local disk and it didn't make a difference.\n> \n> I have only one 1.97GB pack. I ran \"git gc --aggressive\" before.\n\nAh. NFS. That is almost certainly the source of the problem. Git will\naggressively mmap. I would not be surprised to find that RHEL4's NFS\nimplementation is not particularly fast at mmap-ing 2G files, and is\nspending a bunch of time in the kernel servicing the requests.\n\nAside from upgrading your OS or getting off of NFS, I don't have a lot\nof advice. The performance characteristics you are seeing are so\ngrossly off of what is normal that using git is probably going to be\npainful. Your 2s cat-files should be more like .002s. I don't think\nthere's anything for git to fix here.\n\nYou could try building with NO_MMAP, which will emulate it with pread.\nThat might fare better under your NFS implementation. Or it might be\njust as bad.\n\n-Peff\n"},{"id":"202675","messageId":"CAMJd5AQOH=uu1c3enr5fES+Bw4FHZuP++J7-aCM2B+f_G3YMtg@mail.gmail.com","threadId":"31920","inReplyTo":"20121108223319.GA11734@sigill.intra.peff.net","subject":"Re: Long clone time after \"done.\"","fromName":"Uri Moszkowicz","fromEmail":"uri@4refs.com","sentAt":"2012-11-08T23:35:08Z","receivedAt":"2012-11-08T23:35:08Z","isPatch":false,"sender":{"key":"uri@4refs.com","avatar":null},"body":"I tried on the local disk as well and it didn't help. I managed to\nfind a SUSE11 machine and tried it there but no luck so I think we can\neliminate NFS and OS as significant factors now.\n\nI ran with perf and here's the report:\n\nESC[31m 69.07%ESC[m git /lib64/libc-2.11.1.so\n [.] memcpy\nESC[31m 12.33%ESC[m git\n/git-1.8.0.rc2.suse11/bin/git [.]\nblk_SHA1_Block\nESC[31m 5.11%ESC[m git\n/zlib/local/lib/libz.so.1.2.5 [.]\ninflate_fast\nESC[32m 2.61%ESC[m git\n/zlib/local/lib/libz.so.1.2.5 [.]\nadler32\nESC[32m 1.98%ESC[m git /lib64/libc-2.11.1.so\n [.] _int_malloc\nESC[32m 0.86%ESC[m git [kernel]\n [k] clear_page_c\n\nDoes this help? Machine has 396GB of RAM if it matters.\n\nOn Thu, Nov 8, 2012 at 4:33 PM, Jeff King wrote:\n> On Thu, Nov 08, 2012 at 04:16:59PM -0600, Uri Moszkowicz wrote:\n>\n>> I ran \"git cat-file commit some-tag\" for every tag. They seem to be\n>> roughly uniformly distributed between 0s and 2s and about 2/3 of the\n>> time seems to be system. My disk is mounted over NFS so I tried on the\n>> local disk and it didn't make a difference.\n>>\n>> I have only one 1.97GB pack. I ran \"git gc --aggressive\" before.\n>\n> Ah. NFS. That is almost certainly the source of the problem. Git will\n> aggressively mmap. I would not be surprised to find that RHEL4's NFS\n> implementation is not particularly fast at mmap-ing 2G files, and is\n> spending a bunch of time in the kernel servicing the requests.\n>\n> Aside from upgrading your OS or getting off of NFS, I don't have a lot\n> of advice. The performance characteristics you are seeing are so\n> grossly off of what is normal that using git is probably going to be\n> painful. Your 2s cat-files should be more like .002s. I don't think\n> there's anything for git to fix here.\n>\n> You could try building with NO_MMAP, which will emulate it with pread.\n> That might fare better under your NFS implementation. Or it might be\n> just as bad.\n>\n> -Peff\n"},{"id":"203898","messageId":"CAMJd5AQAYt7tBVPrC6KVSa7nEfoWTAHnDZKUPS7QBCFxR5THkw@mail.gmail.com","threadId":"31920","inReplyTo":"CAMJd5AQOH=uu1c3enr5fES+Bw4FHZuP++J7-aCM2B+f_G3YMtg@mail.gmail.com","subject":"Re: Long clone time after \"done.\"","fromName":"Uri Moszkowicz","fromEmail":"uri@4refs.com","sentAt":"2012-11-26T18:06:26Z","receivedAt":"2012-11-26T18:06:26Z","isPatch":false,"sender":{"key":"uri@4refs.com","avatar":null},"body":"Hi guys,\nAny further interest on this scalability problem or should I move on?\n\nThanks,\nUri\n\nOn Thu, Nov 8, 2012 at 5:35 PM, Uri Moszkowicz wrote:\n> I tried on the local disk as well and it didn't help. I managed to\n> find a SUSE11 machine and tried it there but no luck so I think we can\n> eliminate NFS and OS as significant factors now.\n>\n> I ran with perf and here's the report:\n>\n> ESC[31m 69.07%ESC[m git /lib64/libc-2.11.1.so\n> [.] memcpy\n> ESC[31m 12.33%ESC[m git\n> /git-1.8.0.rc2.suse11/bin/git [.]\n> blk_SHA1_Block\n> ESC[31m 5.11%ESC[m git\n> /zlib/local/lib/libz.so.1.2.5 [.]\n> inflate_fast\n> ESC[32m 2.61%ESC[m git\n> /zlib/local/lib/libz.so.1.2.5 [.]\n> adler32\n> ESC[32m 1.98%ESC[m git /lib64/libc-2.11.1.so\n> [.] _int_malloc\n> ESC[32m 0.86%ESC[m git [kernel]\n> [k] clear_page_c\n>\n> Does this help? Machine has 396GB of RAM if it matters.\n>\n> On Thu, Nov 8, 2012 at 4:33 PM, Jeff King wrote:\n>> On Thu, Nov 08, 2012 at 04:16:59PM -0600, Uri Moszkowicz wrote:\n>>\n>>> I ran \"git cat-file commit some-tag\" for every tag. They seem to be\n>>> roughly uniformly distributed between 0s and 2s and about 2/3 of the\n>>> time seems to be system. My disk is mounted over NFS so I tried on the\n>>> local disk and it didn't make a difference.\n>>>\n>>> I have only one 1.97GB pack. I ran \"git gc --aggressive\" before.\n>>\n>> Ah. NFS. That is almost certainly the source of the problem. Git will\n>> aggressively mmap. I would not be surprised to find that RHEL4's NFS\n>> implementation is not particularly fast at mmap-ing 2G files, and is\n>> spending a bunch of time in the kernel servicing the requests.\n>>\n>> Aside from upgrading your OS or getting off of NFS, I don't have a lot\n>> of advice. The performance characteristics you are seeing are so\n>> grossly off of what is normal that using git is probably going to be\n>> painful. Your 2s cat-files should be more like .002s. I don't think\n>> there's anything for git to fix here.\n>>\n>> You could try building with NO_MMAP, which will emulate it with pread.\n>> That might fare better under your NFS implementation. Or it might be\n>> just as bad.\n>>\n>> -Peff\n"}]}