{"thread":{"id":"37685","subject":"Re: git svn's performance issue and strange pauses, and other thing","startedAt":"2014-10-07T18:20:46Z","lastAt":"2014-10-19T14:41:16Z","messageCount":3,"participants":["Hin-Tak Leung","Eric Wong","Jakob Stoklund Olesen"],"isPatch":false,"patchVersion":null,"patchTotal":null},"messages":[{"id":"250300","messageId":"1412706046.90413.YahooMailBasic@web172303.mail.ir2.yahoo.com","threadId":"37685","inReplyTo":null,"subject":"Re: git svn's performance issue and strange pauses, and other thing","fromName":"Hin-Tak Leung","fromEmail":"htl10@users.sourceforge.net","sentAt":"2014-10-07T18:20:46Z","receivedAt":"2014-10-07T18:20:46Z","isPatch":false,"sender":{"key":"htl10@users.sourceforge.net","avatar":null},"body":"------------------------------\nOn Tue, Oct 7, 2014 00:51 BST Hin-Tak Leung wrote:\n\n>------------------------------\n>On Sun, Oct 5, 2014 02:02 BST Eric Wong wrote:\n\n<snipped>\n>>Hin-Tak: have you tried Jakob's patches?  I've taken another look,\n>>signed-off and pushed to my master.\n\n... Then\n>I changed my mind, and decided what the hell, let's clone the whole\n>thing again :-). So I made a new directory, run 'git init', just copy\n>.git/config from the old reop and am doing 'git svn fetch --all' in the new empty\n>directory again.\n>\n>So far it seems to be good. But I am only at revision 35700-ish at the moment,\n>and the whole thing is 66700-ish. Oh, I forgot to mention that the strange\n>pauses seem to be followed by messages like these:\n>\n>W:svn cherry-pick ignored (/branches/R-2-12-branch:52939,54476,55265) - missing 492 commit(s) (eg 9bf20dca6a8b05dff28e6486b1613f10825972c9)\n>W:svn cherry-pick ignored (/branches/R-2-13-branch:55265,55432) - missing 231 commit(s) (eg 9290cf6ce2d7f6cca168cf326eed6e9fe760895f)\n>W:svn cherry-pick ignored (/branches/R-2-15-branch:58894,59717) - missing 405 commit(s) (eg ed84a373b33f728949edf3371829fc3414c343a8)\n>W:svn cherry-pick ignored (/branches/R-3-0-branch:62497) - missing 154 commit(s) (eg 9e4742d201771c9658417c2d2f83838e550e3162)\n>W:svn cherry-pick ignored (/trunk:\n>\n>So presumably I'd only see interesting behavior when there are a number of branches.\n>It seems the first branches are around revision 48000-ish, so I might have\n>to wait a bit.\n>\n>So far, the new clone hasn't created \".git/svn/.caches/\" yet; and memory consumption seems\n>okay also.\n\nThe changes definitely improve, as far as my impression goes. There was only one notable pause around\nr50651, and it is probably because the rather large \"Checking svn:mergeinfo changes since r15413\"\nfrom r15413? That took about 12 minutes. Other instances of \"W:svn cherry-pick ignored\"\nthough do take a while, are in the seconds region - before the code changes they could\nbe minutes, if memory serves.\n\n<--\n\tM\tsrc/library/tools/R/toHTML.R\nr50650 = bed91d435c535f2643cf0d48623fecf86d264bd9 (refs/remotes/trunk)\n\tM\tsrc/modules/X11/rotated.c\n\tM\tsrc/modules/X11/dataentry.c\nChecking svn:mergeinfo changes since r15413: 1 sources, 1 changed\nW:svn cherry-pick ignored (/trunk:28840) - missing 9372 commit(s) (eg cea6142c76300539a0d0c9c743738e31a9f7d523)\nr50651 = ad139a5bf91f9ad6690ff5fb4a3f71cea591a944 (refs/remotes/R-uthreads)\n-->\n\nThe new clone has:\n\n<--\n$ ls -ltr .git/svn/.caches/\ntotal 144788\n-rw-rw-r--. 1 Hin-Tak Hin-Tak  1166138 Oct  7 13:44 lookup_svn_merge.yaml\n-rw-rw-r--. 1 Hin-Tak Hin-Tak 72849741 Oct  7 13:48 check_cherry_pick.yaml\n-rw-rw-r--. 1 Hin-Tak Hin-Tak  1133855 Oct  7 13:49 has_no_changes.yaml\n-rw-rw-r--. 1 Hin-Tak Hin-Tak 73109005 Oct  7 13:53 _rev_list.yaml\n-->\n\nThe old clone has:\n\n<---\n$ ls -ltr .git/svn/.caches/\ntotal 318824\n-rw-rw-r--. 1 Hin-Tak Hin-Tak   5711724 Jul 24  2012 lookup_svn_merge.db\n-rw-rw-r--. 1 Hin-Tak Hin-Tak  30523628 Jul 24  2012 check_cherry_pick.db\n-rw-rw-r--. 1 Hin-Tak Hin-Tak    296592 Jul 24  2012 has_no_changes.db\n-rw-rw-r--. 1 Hin-Tak Hin-Tak  40241189 Oct  5 16:42 lookup_svn_merge.yaml\n-rw-rw-r--. 1 Hin-Tak Hin-Tak 225323456 Oct  5 16:49 check_cherry_pick.yaml\n-rw-rw-r--. 1 Hin-Tak Hin-Tak    242547 Oct  5 16:49 has_no_changes.yaml\n-rw-rw-r--. 1 Hin-Tak Hin-Tak  24120007 Oct  5 16:50 _rev_list.yaml\n-->\n\nI had to suspend somewhat around r59000 - but it is interesting to see\nthat the max memory consumption of the later part is almost double?\nand it also runs at 100% rather than 60% overall; I don't know what\nto make of that - probably just smaller changes versus\nlarger ones, or different time of day and network loads (yes,\nI guess it is just bandwidth-limited?, since the bulk of CPU time is in system\nrather than user).\n\nI am somwhat worry about the dramatic difference between the two .svn/.caches -\ncheck_cherry_pick.yaml is 225MB in one and 73MB in the other, and also\n_rev_list.yaml is opposite - 24MB vs 73MB. How do I reconcile that?\n\n<--\n\tM\tsrc/main/dotcode.c\n\tM\tdoc/NEWS.Rd\nr59140 = b6014a226aebf9e016c89c0bd1aca1979796a057 (refs/remotes/trunk)\n\tM\tsrc/main/dotcode.c\n\tM\tdoc/NEWS.Rd\nChecking svn:mergeinfo changes since r59138: 4 sources, 1 changed\nW:svn cherry-pick ignored (/trunk:59137,59140) - missing 369 commit(s) (eg 8a2a36083ba39be27fc9940acc3f51eab6a7a0c3)\nr59141 = 38c6d05f164d34e4b5cc545bda387be9d910f748 (refs/remotes/R-2-15-branch)\nConnection timed out: Connection timed out at /usr/share/perl5/vendor_perl/Git/SVN/Ra.pm line 290.\n\nCommand exited with non-zero status 1\n\tCommand being timed: \"git svn fetch --all\"\n\tUser time (seconds): 5642.19\n\tSystem time (seconds): 23552.44\n\tPercent of CPU this job got: 57%\n\tElapsed (wall clock) time (h:mm:ss or m:ss): 14:06:58\n\tAverage shared text size (kbytes): 0\n\tAverage unshared data size (kbytes): 0\n\tAverage stack size (kbytes): 0\n\tAverage total size (kbytes): 0\n\tMaximum resident set size (kbytes): 349324\n\tAverage resident set size (kbytes): 0\n\tMajor (requiring I/O) page faults: 39\n\tMinor (reclaiming a frame) page faults: 744713614\n\tVoluntary context switches: 4761489\n\tInvoluntary context switches: 8595950\n\tSwaps: 0\n\tFile system inputs: 7712\n\tFile system outputs: 121404296\n\tSocket messages sent: 0\n\tSocket messages received: 0\n\tSignals delivered: 0\n\tPage size (bytes): 4096\n\tExit status: 1\n-->\n<--\n\tM\tsrc/include/Defn.h\nr66719 = 1e3288d3ae4cfb15f6e4e4116f18d38b3efc5bb5 (refs/remotes/trunk)\n\tM\tdoc/NEWS.Rd\nr66720 = 1c184e5fc2b71a27767215a45a1270f3edbc616f (refs/remotes/trunk)\nChecked out HEAD:\n  https://svn.r-project.org/R/trunk r66720\ncreating empty directory: tests/Pkgs/exNSS4/man\n\tCommand being timed: \"git svn fetch --all\"\n\tUser time (seconds): 2126.00\n\tSystem time (seconds): 7852.44\n\tPercent of CPU this job got: 96%\n\tElapsed (wall clock) time (h:mm:ss or m:ss): 2:52:38\n\tAverage shared text size (kbytes): 0\n\tAverage unshared data size (kbytes): 0\n\tAverage stack size (kbytes): 0\n\tAverage total size (kbytes): 0\n\tMaximum resident set size (kbytes): 755256\n\tAverage resident set size (kbytes): 0\n\tMajor (requiring I/O) page faults: 6\n\tMinor (reclaiming a frame) page faults: 142730534\n\tVoluntary context switches: 898725\n\tInvoluntary context switches: 1842056\n\tSwaps: 0\n\tFile system inputs: 1800\n\tFile system outputs: 28606392\n\tSocket messages sent: 0\n\tSocket messages received: 0\n\tSignals delivered: 0\n\tPage size (bytes): 4096\n\tExit status: 0\n-->\n"},{"id":"250819","messageId":"20141019041238.GA8944@dcvr.yhbt.net","threadId":"37685","inReplyTo":"1412706046.90413.YahooMailBasic@web172303.mail.ir2.yahoo.com","subject":"Re: git svn's performance issue and strange pauses, and other thing","fromName":"Eric Wong","fromEmail":"normalperson@yhbt.net","sentAt":"2014-10-19T04:12:38Z","receivedAt":"2014-10-19T04:12:38Z","isPatch":false,"sender":{"key":"e@80x24.org","avatar":null},"body":"Hin-Tak Leung <htl10@users.sourceforge.net> wrote:\n> The new clone has:\n> \n> <--\n> $ ls -ltr .git/svn/.caches/\n> total 144788\n> -rw-rw-r--. 1 Hin-Tak Hin-Tak  1166138 Oct  7 13:44 lookup_svn_merge.yaml\n> -rw-rw-r--. 1 Hin-Tak Hin-Tak 72849741 Oct  7 13:48 check_cherry_pick.yaml\n> -rw-rw-r--. 1 Hin-Tak Hin-Tak  1133855 Oct  7 13:49 has_no_changes.yaml\n> -rw-rw-r--. 1 Hin-Tak Hin-Tak 73109005 Oct  7 13:53 _rev_list.yaml\n> -->\n> \n> The old clone has:\n\n<snip>\n> -rw-rw-r--. 1 Hin-Tak Hin-Tak  40241189 Oct  5 16:42 lookup_svn_merge.yaml\n> -rw-rw-r--. 1 Hin-Tak Hin-Tak 225323456 Oct  5 16:49 check_cherry_pick.yaml\n> -rw-rw-r--. 1 Hin-Tak Hin-Tak    242547 Oct  5 16:49 has_no_changes.yaml\n> -rw-rw-r--. 1 Hin-Tak Hin-Tak  24120007 Oct  5 16:50 _rev_list.yaml\n> -->\n> \n> I had to suspend somewhat around r59000 - but it is interesting to see\n> that the max memory consumption of the later part is almost double?\n> and it also runs at 100% rather than 60% overall; I don't know what\n> to make of that - probably just smaller changes versus\n> larger ones, or different time of day and network loads (yes,\n> I guess it is just bandwidth-limited?, since the bulk of CPU time is in system\n> rather than user).\n\ngit-svn memory usage is insane, and we need to reduce it.\n(on Linux, fork() performance is reduced as memory size of the parent\n grows, and I don't think we can easily call vfork() from Perl)\n\n> I am somwhat worry about the dramatic difference between the two .svn/.caches -\n> check_cherry_pick.yaml is 225MB in one and 73MB in the other, and also\n> _rev_list.yaml is opposite - 24MB vs 73MB. How do I reconcile that?\n\nCalling patterns changed, and it looks like Jakob's changes avoided some\ncalls.  The main thing to care about:\n\tDoes the repository history look right?\n\nThe check_cherry_pick cache can be made smaller, too:\n----------------------- 8< -----------------------------\nFrom: Eric Wong <normalperson@yhbt.net>\nSubject: [PATCH] git-svn: reduce check_cherry_pick cache overhead\n\nWe do not need to store entire lists of commits, only the\nnumber of incomplete and the first commit for reference.\nThis reduces the amount of data we need to store in memory\nand on disk stores.\n\nSigned-off-by: Eric Wong <normalperson@yhbt.net>\n---\n perl/Git/SVN.pm | 28 +++++++++++++++-------------\n 1 file changed, 15 insertions(+), 13 deletions(-)\n\ndiff --git a/perl/Git/SVN.pm b/perl/Git/SVN.pm\nindex 25dbcd5..b2d37cb 100644\n--- a/perl/Git/SVN.pm\n+++ b/perl/Git/SVN.pm\n@@ -1537,7 +1537,7 @@ sub _rev_list {\n \t@rv;\n }\n \n-sub check_cherry_pick {\n+sub check_cherry_pick2 {\n \tmy $base = shift;\n \tmy $tip = shift;\n \tmy $parents = shift;\n@@ -1552,7 +1552,8 @@ sub check_cherry_pick {\n \t\t\tdelete $commits{$commit};\n \t\t}\n \t}\n-\treturn (keys %commits);\n+\tmy @k = (keys %commits);\n+\treturn (scalar @k, $k[0]);\n }\n \n sub has_no_changes {\n@@ -1597,7 +1598,7 @@ sub tie_for_persistent_memoization {\n \t\tmkpath([$cache_path]) unless -d $cache_path;\n \n \t\tmy %lookup_svn_merge_cache;\n-\t\tmy %check_cherry_pick_cache;\n+\t\tmy %check_cherry_pick2_cache;\n \t\tmy %has_no_changes_cache;\n \t\tmy %_rev_list_cache;\n \n@@ -1608,11 +1609,11 @@ sub tie_for_persistent_memoization {\n \t\t\tLIST_CACHE => ['HASH' => \\%lookup_svn_merge_cache],\n \t\t;\n \n-\t\ttie_for_persistent_memoization(\\%check_cherry_pick_cache,\n-\t\t    \"$cache_path/check_cherry_pick\");\n-\t\tmemoize 'check_cherry_pick',\n+\t\ttie_for_persistent_memoization(\\%check_cherry_pick2_cache,\n+\t\t    \"$cache_path/check_cherry_pick2\");\n+\t\tmemoize 'check_cherry_pick2',\n \t\t\tSCALAR_CACHE => 'FAULT',\n-\t\t\tLIST_CACHE => ['HASH' => \\%check_cherry_pick_cache],\n+\t\t\tLIST_CACHE => ['HASH' => \\%check_cherry_pick2_cache],\n \t\t;\n \n \t\ttie_for_persistent_memoization(\\%has_no_changes_cache,\n@@ -1636,7 +1637,7 @@ sub tie_for_persistent_memoization {\n \t\t$memoized = 0;\n \n \t\tMemoize::unmemoize 'lookup_svn_merge';\n-\t\tMemoize::unmemoize 'check_cherry_pick';\n+\t\tMemoize::unmemoize 'check_cherry_pick2';\n \t\tMemoize::unmemoize 'has_no_changes';\n \t\tMemoize::unmemoize '_rev_list';\n \t}\n@@ -1648,7 +1649,8 @@ sub tie_for_persistent_memoization {\n \t\treturn unless -d $cache_path;\n \n \t\tfor my $cache_file ((\"$cache_path/lookup_svn_merge\",\n-\t\t\t\t     \"$cache_path/check_cherry_pick\",\n+\t\t\t\t     \"$cache_path/check_cherry_pick\", # old\n+\t\t\t\t     \"$cache_path/check_cherry_pick2\",\n \t\t\t\t     \"$cache_path/has_no_changes\")) {\n \t\t\tfor my $suffix (qw(yaml db)) {\n \t\t\t\tmy $file = \"$cache_file.$suffix\";\n@@ -1817,15 +1819,15 @@ sub find_extra_svn_parents {\n \t\t}\n \n \t\t# double check that there are no missing non-merge commits\n-\t\tmy (@incomplete) = check_cherry_pick(\n+\t\tmy ($ninc, $ifirst) = check_cherry_pick2(\n \t\t\t$merge_base, $merge_tip,\n \t\t\t$parents,\n \t\t\t@all_ranges,\n \t\t       );\n \n-\t\tif ( @incomplete ) {\n-\t\t\twarn \"W:svn cherry-pick ignored ($spec) - missing \"\n-\t\t\t\t.@incomplete.\" commit(s) (eg $incomplete[0])\\n\";\n+\t\tif ($ninc) {\n+\t\t\twarn \"W:svn cherry-pick ignored ($spec) - missing \" .\n+\t\t\t\t\"$ninc commit(s) (eg $ifirst)\\n\";\n \t\t} else {\n \t\t\twarn\n \t\t\t\t\"Found merge parent ($spec): \",\n-- \nEW\n"},{"id":"250830","messageId":"0F2DF34C-8134-4888-B081-216660F67BB6@2pi.dk","threadId":"37685","inReplyTo":"20141019041238.GA8944@dcvr.yhbt.net","subject":"Re: git svn's performance issue and strange pauses, and other thing","fromName":"Jakob Stoklund Olesen","fromEmail":"stoklund@2pi.dk","sentAt":"2014-10-19T14:41:16Z","receivedAt":"2014-10-19T14:41:16Z","isPatch":false,"sender":{"key":"stoklund@2pi.dk","avatar":"https://avatars.githubusercontent.com/u/12660495?v=4"},"body":"On Oct 18, 2014, at 21:12, Eric Wong <normalperson@yhbt.net> wrote:\n\n>> I am somwhat worry about the dramatic difference between the two .svn/.caches -\n>> check_cherry_pick.yaml is 225MB in one and 73MB in the other, and also\n>> _rev_list.yaml is opposite - 24MB vs 73MB. How do I reconcile that?\n> \n> Calling patterns changed, and it looks like Jakob's changes avoided some\n> calls.\n\nIt is possible that those functions don't need to be memoized any more. My patch is trying to avoid calling them with the same arguments over and over, and memoizing doesn't help when arguments are changing.\n\nThanks,\n/jakob"}]}