{"thread":{"id":"3521","subject":"cygwin: push/pull takes very long time","startedAt":"2006-03-02T13:26:06Z","lastAt":"2006-03-03T09:10:25Z","messageCount":5,"participants":["Alex Riesen","Christopher Faylor"],"isPatch":false,"patchVersion":null,"patchTotal":null},"messages":[{"id":"17032","messageId":"81b0412b0603020526w7db41994v54a96895c1a6e960@mail.gmail.com","threadId":"3521","inReplyTo":null,"subject":"cygwin: push/pull takes very long time","fromName":"Alex Riesen","fromEmail":"raa.lkml@gmail.com","sentAt":"2006-03-02T13:26:06Z","receivedAt":"2006-03-02T13:26:06Z","isPatch":false,"sender":{"key":"raa.lkml@gmail.com","avatar":"https://avatars.githubusercontent.com/u/324101?v=4"},"body":"Hi,\n\nI didn't really notice when it happened, but since some time\npush and pull takes *very* long. git-pack-objects appears to\nbe the major offender:\n$ git pull ../src march:march\nGenerating pack...\nDone counting 20238 objects.\nResult has 12 objects.\nDeltifying 12 objects.\n   8% (1/12) done\n\nIt's still working, half an hour since it was started.\nIt can be seen that it is constantly growing and shrinking\n(for about 20k,50k,80k,100k back and forth).\n\nI did a small instrumentation to figure out how much\nand how often is allocated, but it's waiting for the\ngit-pack-objects to finish. \"Counting objects\" was\nslow too, with git-rev-list \"pulsating\" in a similar\nway (most commonly allocated objects in the size\nrange from 16 to 256).\n\nI continue looking for the problem (I didn't do bisect yet,\nwant to wait for mem profile first), but any ideas on how\nto fix that are very welcome.\n"},{"id":"17059","messageId":"81b0412b0603020909p179ed9bx4ed8fc2ddf77e868@mail.gmail.com","threadId":"3521","inReplyTo":"81b0412b0603020526w7db41994v54a96895c1a6e960@mail.gmail.com","subject":"Re: cygwin: push/pull takes very long time","fromName":"Alex Riesen","fromEmail":"raa.lkml@gmail.com","sentAt":"2006-03-02T17:09:23Z","receivedAt":"2006-03-02T17:09:23Z","isPatch":false,"sender":{"key":"raa.lkml@gmail.com","avatar":"https://avatars.githubusercontent.com/u/324101?v=4"},"body":"On 3/2/06, Alex Riesen <raa.lkml@gmail.com> wrote:\n> It's still working, half an hour since it was started.\n> It can be seen that it is constantly growing and shrinking\n> (for about 20k,50k,80k,100k back and forth).\n\nThe distribution is (there are some git-commits and gitks\nprobably, here as git-read-tree?) below. The first number\nafter program name is lower range limit, the second - upper limit.\nThe number after them - counter of *alloc calls.\nThe strange pair 65536:99999 means very big objects, more than 1Mb.\nI'll cleanup the profiling code and send it as well soon\n(I had to instrument x*alloc).\n\n      git-read-tree:16:256      127002\n       git-rev-list:16:256      44775\n        git-read-tree:0:16      22577\n   git-pack-objects:16:256      12495\n git-pack-objects:256:4096      12303\ngit-pack-objects:4096:65536     6929\n     git-diff-index:16:256      4381\n     git-http-fetch:16:256      3535\n     git-diff-index:16:256      2914\n  git-write-tree:4096:65536     2876\n       git-http-fetch:0:16      2111\n     git-fetch-pack:16:256      1646\n       git-fetch-pack:0:16      1522\n     git-rev-list:256:4096      1067\n                   :16:256      976\n    git-read-tree:256:4096      965\n   git-http-fetch:256:4096      835\n                     :0:16      825\n         git-ls-files:0:16      791\n         git-rev-list:0:16      748\n   git-fetch-pack:256:4096      698\n    git-upload-pack:16:256      610\ngit-pack-objects:65536:1048576  594\n      git-rev-parse:16:256      571\n                 :256:4096      554\n        git-rev-parse:0:16      492\n      git-upload-pack:0:16      469\n  git-upload-pack:256:4096      248\n         git-cat-file:0:16      243\n    git-peek-remote:16:256      242\n       git-merge-base:0:16      229\n     git-merge-base:16:256      208\n       git-cat-file:16:256      167\n    git-rev-parse:256:4096      141\n      git-rev-parse:16:256      117\n        git-rev-parse:0:16      116\n     git-cat-file:256:4096      80\n     git-pack-objects:0:16      73\n       git-diff-index:0:16      65\n   git-merge-base:256:4096      59\ngit-pack-objects:65536:99999    54\n   git-current-branch:0:16      48\n       git-diff-index:0:16      47\n      git-diff-tree:16:256      42\n   git-diff-index:256:4096      36\n git-unpack-objects:16:256      31\n      git-diff-tree:16:256      30\n       git-ls-files:16:256      27\n   git-update-index:16:256      27\n   git-diff-index:256:4096      24\n     git-write-tree:16:256      23\n       git-cat-file:16:256      22\n"},{"id":"17073","messageId":"20060302215408.GC6183@steel.home","threadId":"3521","inReplyTo":"81b0412b0603020909p179ed9bx4ed8fc2ddf77e868@mail.gmail.com","subject":"Re: cygwin: push/pull takes very long time","fromName":"Alex Riesen","fromEmail":"raa.lkml@gmail.com","sentAt":"2006-03-02T21:54:08Z","receivedAt":"2006-03-02T21:54:08Z","isPatch":false,"sender":{"key":"raa.lkml@gmail.com","avatar":"https://avatars.githubusercontent.com/u/324101?v=4"},"body":"Alex Riesen, Thu, Mar 02, 2006 18:09:23 +0100:\n> I'll cleanup the profiling code and send it as well soon\n> (I had to instrument x*alloc).\n\nThis is not exactly the same. It counts free as well, even if that is\nnot really interesting - there are places were there is more frees\nthan allocs. Probably something missed or a result coming from libc.\n\nAlso it is _not_ the code I used for windows. I had to have a global\nvariable for argv[0], which needs modification of all main()s, which\ngets too easily out of sync.\n\nBTW, maybe someone has an idea as to how attach valgrind to everything?\n(I mean, without changing every script. Maybe modify git.c?)\n\nAnyway, here it is, could be useful for something.\n\n---\n\ndiff --git a/Makefile b/Makefile\nindex a5eb0c4..18fc802 100644\n--- a/Makefile\n+++ b/Makefile\n@@ -206,7 +206,7 @@ LIB_OBJS = \\\n \tquote.o read-cache.o refs.o run-command.o \\\n \tserver-info.o setup.o sha1_file.o sha1_name.o strbuf.o \\\n \ttag.o tree.o usage.o config.o environment.o ctype.o copy.o \\\n-\tfetch-clone.o \\\n+\tfetch-clone.o alloc.o \\\n \t$(DIFF_OBJS)\n \n LIBS = $(LIB_FILE)\ndiff --git a/alloc.c b/alloc.c\nnew file mode 100644\nindex 0000000..76727e6\n--- /dev/null\n+++ b/alloc.c\n@@ -0,0 +1,108 @@\n+/* simple allocation logging */\n+#include <unistd.h>\n+#include <limits.h>\n+#include <stdlib.h>\n+#include <stdio.h>\n+#include \"git-compat-util.h\"\n+\n+#undef free\n+\n+#define SHIFT 2\n+static unsigned cnts[12] = {0,0,0,0, 0,0,0,0};\n+static unsigned fcnt = 0;\n+\n+static int exit_hook = 1;\n+\n+static void alloc_profile()\n+{\n+\tchar argv0[PATH_MAX];\n+\tFILE *fp;\n+\tfp = fopen(\"/proc/self/cmdline\", \"r\");\n+\tif ( !fp ) {\n+\t\tsprintf(argv0, \"%d\", getpid());\n+\t} else {\n+\t\tfread(argv0, sizeof(argv0), 1, fp);\n+\t\tfclose(fp);\n+\t\tchar *s = strrchr(argv0, '/');\n+\t\tif ( s )\n+\t\t\tmemmove(argv0, s + 1, strlen(s));\n+\t}\n+\tfp = fopen(\"/tmp/git-alloc\", \"ab\");\n+\tif ( !fp )\n+\t\treturn;\n+\tunsigned i, c = 0;\n+\tfor ( i = 0; i < sizeof(cnts)/sizeof(*cnts); ++i ) {\n+\t\tif ( !cnts[i] )\n+\t\t\tcontinue;\n+\t\tfprintf(fp, \"%s %u %u:%u %u times\\n\",\n+\t\t\targv0,\n+\t\t\ti,\n+\t\t\ti ? 1 << i * SHIFT: 0,\n+\t\t\t1 << (i+1) * SHIFT,\n+\t\t\tcnts[i]);\n+\t\tc += cnts[i];\n+\t}\n+\tfprintf(fp, \"%s alloc-free = %u\\n\", argv0, c - fcnt);\n+\tfclose(fp);\n+}\n+\n+static inline void count(size_t size)\n+{\n+\tif ( exit_hook ) {\n+\t\texit_hook = 0;\n+\t\tatexit(alloc_profile);\n+\t}\n+        unsigned i = 0;\n+\twhile ( size && i < sizeof(cnts)/sizeof(*cnts) ) {\n+\t\tsize >>= SHIFT;\n+\t\tif ( size )\n+\t\t\t++i;\n+\t\telse {\n+\t\t\t++cnts[i];\n+\t\t\treturn;\n+\t\t}\n+\t}\n+\t++cnts[sizeof(cnts)/sizeof(*cnts)-1];\n+}\n+\n+void *xmalloc(size_t size)\n+{\n+\tvoid *ret = malloc(size);\n+\tcount(size);\n+\tif (!ret && !size)\n+\t\tret = malloc(1);\n+\tif (!ret)\n+\t\tdie(\"Out of memory, malloc failed, %u bytes requested\", size);\n+\treturn ret;\n+}\n+\n+void *xrealloc(void *ptr, size_t size)\n+{\n+\tvoid *ret = realloc(ptr, size);\n+\tcount(size);\n+\tif (!ret && !size)\n+\t\tret = realloc(ptr, 1);\n+\tif (!ret)\n+\t\tdie(\"Out of memory, realloc failed, %u bytes requested\", size);\n+\treturn ret;\n+}\n+\n+void *xcalloc(size_t nmemb, size_t size)\n+{\n+\tvoid *ret = calloc(nmemb, size);\n+\tcount(size);\n+\tif (!ret && (!nmemb || !size))\n+\t\tret = calloc(1, 1);\n+\tif (!ret)\n+\t\tdie(\"Out of memory, calloc failed\");\n+\treturn ret;\n+}\n+\n+void xfree(void *ptr)\n+{\n+\tif ( !ptr )\n+\t\treturn;\n+\tfree(ptr);\n+\t++fcnt;\n+}\n+\ndiff --git a/git-compat-util.h b/git-compat-util.h\nindex f982b8e..ab4f855 100644\n--- a/git-compat-util.h\n+++ b/git-compat-util.h\n@@ -73,35 +73,11 @@ extern void gitunsetenv(const char *);\n extern char *gitstrcasestr(const char *haystack, const char *needle);\n #endif\n \n-static inline void *xmalloc(size_t size)\n-{\n-\tvoid *ret = malloc(size);\n-\tif (!ret && !size)\n-\t\tret = malloc(1);\n-\tif (!ret)\n-\t\tdie(\"Out of memory, malloc failed\");\n-\treturn ret;\n-}\n-\n-static inline void *xrealloc(void *ptr, size_t size)\n-{\n-\tvoid *ret = realloc(ptr, size);\n-\tif (!ret && !size)\n-\t\tret = realloc(ptr, 1);\n-\tif (!ret)\n-\t\tdie(\"Out of memory, realloc failed\");\n-\treturn ret;\n-}\n-\n-static inline void *xcalloc(size_t nmemb, size_t size)\n-{\n-\tvoid *ret = calloc(nmemb, size);\n-\tif (!ret && (!nmemb || !size))\n-\t\tret = calloc(1, 1);\n-\tif (!ret)\n-\t\tdie(\"Out of memory, calloc failed\");\n-\treturn ret;\n-}\n+void *xmalloc(size_t size);\n+void *xrealloc(void *ptr, size_t size);\n+void *xcalloc(size_t nmemb, size_t size);\n+void xfree(void *ptr);\n+#define free(p) xfree(p)\n \n static inline ssize_t xread(int fd, void *buf, size_t len)\n {\ndiff --git a/prof-decode.sh b/prof-decode.sh\nnew file mode 100755\nindex 0000000..9c07e05\n--- /dev/null\n+++ b/prof-decode.sh\n@@ -0,0 +1,25 @@\n+#!/bin/bash\n+if [ $# = 0 ]; then\n+    set -- /tmp/git-alloc\n+fi\n+cat \"$@\" | perl -e '\n+    while(<>) {\n+        if (/(\\S*) \\d+ (\\d+:\\d+) (\\d+)/) {\n+\t\t$c{$1}->{$2} += $3;\n+\t\t$c{$1}->{all} += $3\n+\t}\n+        if (/(\\S*) alloc-free = (\\d+)/) { $d{$1} += $2 }\n+    }\n+    foreach $k (sort {$c{$b}->{all} <=> $c{$a}->{all}} grep {$c{$_}} keys %c) {\n+\tfor ( sort {\n+\t\tif ( $a eq \"all\" ) { -1 }\n+\t\telsif ( $b eq \"all\" ) { 1 }\n+\t\telse {\n+\t\t\"$a $b\" =~ /(\\d+):\\d+ (\\d+):\\d+/;\n+\t\t$1 <=> $2 }\n+\t    } grep { $c{$k}->{$_} } keys %{$c{$k}} ) {\n+\t    printf \"%20s\\t%20s\\t%d\\n\", $k, $_, $c{$k}->{$_}\n+\t}\n+\tprintf \"%20s\\t%d leaks\\n\\n\", $k, $d{$k}\n+    }\n+'\n"},{"id":"17088","messageId":"20060303002806.GB7497@trixie.casa.cgf.cx","threadId":"3521","inReplyTo":"20060302215408.GC6183@steel.home","subject":"Re: cygwin: push/pull takes very long time","fromName":"Christopher Faylor","fromEmail":"me@cgf.cx","sentAt":"2006-03-03T00:28:06Z","receivedAt":"2006-03-03T00:28:06Z","isPatch":false,"sender":{"key":"me@cgf.cx","avatar":null},"body":"On Thu, Mar 02, 2006 at 10:54:08PM +0100, Alex Riesen wrote:\n>Alex Riesen, Thu, Mar 02, 2006 18:09:23 +0100:\n>>I'll cleanup the profiling code and send it as well soon (I had to\n>>instrument x*alloc).\n>\n>This is not exactly the same.  It counts free as well, even if that is\n>not really interesting - there are places were there is more frees than\n>allocs.  Probably something missed or a result coming from libc.\n>\n>Also it is _not_ the code I used for windows.  I had to have a global\n>variable for argv[0], which needs modification of all main()s, which\n>gets too easily out of sync.\n\nI wasn't following this discussion closely so maybe this is useless\ninformation, but for Cygwin you can either use the undocumented global\n__argv or you can use /proc/cmdline.  /proc/self/cmdline is going to be\npretty slow, however.\n\nIt looks like pure Windows console apps define _argv in stdlib.h also\nbut I've never used this and don't know if it is what it looks like.\n\ncgf\n"},{"id":"17102","messageId":"81b0412b0603030110x73f080ao6a5798e339aa6355@mail.gmail.com","threadId":"3521","inReplyTo":"20060303002806.GB7497@trixie.casa.cgf.cx","subject":"Re: cygwin: push/pull takes very long time","fromName":"Alex Riesen","fromEmail":"raa.lkml@gmail.com","sentAt":"2006-03-03T09:10:25Z","receivedAt":"2006-03-03T09:10:25Z","isPatch":false,"sender":{"key":"raa.lkml@gmail.com","avatar":"https://avatars.githubusercontent.com/u/324101?v=4"},"body":"On 3/3/06, Christopher Faylor <me@cgf.cx> wrote:\n> On Thu, Mar 02, 2006 at 10:54:08PM +0100, Alex Riesen wrote:\n> >Alex Riesen, Thu, Mar 02, 2006 18:09:23 +0100:\n> >>I'll cleanup the profiling code and send it as well soon (I had to\n> >>instrument x*alloc).\n> >\n> >This is not exactly the same.  It counts free as well, even if that is\n> >not really interesting - there are places were there is more frees than\n> >allocs.  Probably something missed or a result coming from libc.\n> >\n> >Also it is _not_ the code I used for windows.  I had to have a global\n> >variable for argv[0], which needs modification of all main()s, which\n> >gets too easily out of sync.\n>\n> I wasn't following this discussion closely so maybe this is useless\n> information, but for Cygwin you can either use the undocumented global\n> __argv or you can use /proc/cmdline.  /proc/self/cmdline is going to be\n> pretty slow, however.\n\nOh, thanks. The speed is of no problem here: it's in atexit callback.\n\n> It looks like pure Windows console apps define _argv in stdlib.h also\n> but I've never used this and don't know if it is what it looks like.\n\nIt works as usual argv. I used \"char **__argv\", got the message from linker:\nInfo: resolving ___argv by linking to __imp____argv (auto-import)\nwhich I almost expected.\n"}]}