{"thread":{"id":"17879","subject":"[PATCH] check_updates(): effective removal of cache entries marked CE_REMOVE","startedAt":"2009-02-18T22:18:03Z","lastAt":"2009-02-20T10:15:27Z","messageCount":8,"participants":["Kjetil Barvik","Linus Torvalds","Alex Riesen","Junio C Hamano","Johannes Schindelin"],"isPatch":true,"patchVersion":1,"patchTotal":null},"messages":[{"id":"105351","messageId":"1234995483-933-1-git-send-email-barvik@broadpark.no","threadId":"17879","inReplyTo":null,"subject":"[PATCH] check_updates(): effective removal of cache entries marked CE_REMOVE","fromName":"Kjetil Barvik","fromEmail":"barvik@broadpark.no","sentAt":"2009-02-18T22:18:03Z","receivedAt":"2009-02-18T22:18:03Z","isPatch":true,"sender":{"key":"barvik@broadpark.no","avatar":null},"body":"Below is oprofile output from GIT command 'git chekcout -q my-v2.6.25'\n(move from tag v2.6.27 to tag v2.6.25 of the Linux kernel):\n\nCPU: Core 2, speed 1999.95 MHz (estimated)\nCounted CPU_CLK_UNHALTED events (Clock cycles when not halted) with a unit\n mask of 0x00 (Unhalted core cycles) count 20000\nCounted INST_RETIRED_ANY_P events (number of instructions retired) with a\n unit mask of 0x00 (No unit mask) count 20000\nCPU_CLK_UNHALT...|INST_RETIRED:2...|\n samples| %| samples| %|\n------------------------------------\n 409247 100.000 342878 100.000 git\n CPU_CLK_UNHALT...|INST_RETIRED:2...|\n samples| %| samples| %|\n ------------------------------------\n 260476 63.6476 257843 75.1996 libz.so.1.2.3\n 100876 24.6492 64378 18.7758 kernel-2.6.28.4_2.vmlinux\n 30850 7.5382 7874 2.2964 libc-2.9.so\n 14775 3.6103 8390 2.4469 git\n 2020 0.4936 4325 1.2614 libcrypto.so.0.9.8\n 191 0.0467 32 0.0093 libpthread-2.9.so\n 58 0.0142 36 0.0105 ld-2.9.so\n 1 2.4e-04 0 0 libldap-2.3.so.0.2.31\n\nDetail list of the top 20 function entries (libz counted in one blob):\n\nCPU_CLK_UNHALTED INST_RETIRED_ANY_P\nsamples % samples % image name symbol name\n260476 63.6862 257843 75.2725 libz.so.1.2.3 /lib/libz.so.1.2.3\n16587 4.0555 3636 1.0615 libc-2.9.so memcpy\n7710 1.8851 277 0.0809 libc-2.9.so memmove\n3679 0.8995 1108 0.3235 kernel-2.6.28.4_2.vmlinux d_validate\n3546 0.8670 2607 0.7611 kernel-2.6.28.4_2.vmlinux __getblk\n3174 0.7760 1813 0.5293 libc-2.9.so _int_malloc\n2396 0.5858 3681 1.0746 kernel-2.6.28.4_2.vmlinux copy_to_user\n2270 0.5550 2528 0.7380 kernel-2.6.28.4_2.vmlinux __link_path_walk\n2205 0.5391 1797 0.5246 kernel-2.6.28.4_2.vmlinux ext4_mark_iloc_dirty\n2103 0.5142 1203 0.3512 kernel-2.6.28.4_2.vmlinux find_first_zero_bit\n2077 0.5078 997 0.2911 kernel-2.6.28.4_2.vmlinux do_get_write_access\n2070 0.5061 514 0.1501 git cache_name_compare\n2043 0.4995 1501 0.4382 kernel-2.6.28.4_2.vmlinux rcu_irq_exit\n2022 0.4944 1732 0.5056 kernel-2.6.28.4_2.vmlinux __ext4_get_inode_loc\n2020 0.4939 4325 1.2626 libcrypto.so.0.9.8 /usr/lib/libcrypto.so.0.9.8\n1965 0.4804 1384 0.4040 git patch_delta\n1708 0.4176 984 0.2873 kernel-2.6.28.4_2.vmlinux rcu_sched_grace_period\n1682 0.4112 727 0.2122 kernel-2.6.28.4_2.vmlinux sysfs_slab_alias\n1659 0.4056 290 0.0847 git find_pack_entry_one\n1480 0.3619 1307 0.3816 kernel-2.6.28.4_2.vmlinux ext4_writepage_trans_blocks\n\nNotice the memmove line, where the CPU did 7710 / 277 = 27.8 cycles\nper instruction, and compared to the total cycles spent inside the\nsource code of GIT for this command, all the memmove() calls\ntranslates to (7710 * 100) / 14775 = 52.2% of this.\n\nRetesting with a GIT program compiled for gcov usage, I found out that\nthe memmove() calls came from remove_index_entry_at() in read-cache.c,\nwhere we have:\n\n memmove(istate->cache + pos,\n istate->cache + pos + 1,\n (istate->cache_nr - pos) * sizeof(struct cache_entry *));\n\nremove_index_entry_at() is called 4902 times from check_updates() in\nunpack-trees.c, and each time called we move each cache_entry pointers\n(from the removed one) one step to the left.\n\nSince we have 28828 entries in the cache this time, and if we on\naverage move half of them each time, we in total move approximately\n4902 * 0.5 * 28828 * 4 = 282 629 712 bytes, or twice this amount if\neach pointer is 8 bytes (64 bit).\n\nOK, is seems that the function check_updates() is called 28 times, so\nthe estimated guess above had been more correct if check_updates() had\nbeen called only once, but the point is: we get lots of bytes moved.\n\nTo fix this, and use an O(N) algorithm instead, where N is the number\nof cache_entries, we delete/remove all entries in one loop through all\nentries.\n\n>From a retest, the new remove_marked_cache_entries() from the patch\nbelow, ended up with the following output line from oprofile:\n\n46 0.0105 15 0.0041 git remove_marked_cache_entries\n\nIf we can trust the numbers from oprofile in this case, we saved\napproximately ((7710 - 46) * 20000) / (2 * 1000 * 1000 * 1000) = 0.077\nseconds CPU time with this fix for this particular test. And notice\nthat now the CPU did only 46 / 15 = 3.1 cycles/instruction.\n\nSigned-off-by: Kjetil Barvik \n---\n cache.h | 1 +\n read-cache.c | 20 ++++++++++++++++++++\n unpack-trees.c | 4 +---\n 3 files changed, 22 insertions(+), 3 deletions(-)\n\ndiff --git a/cache.h b/cache.h\nindex 6141269..0b11e3e 100644\n--- a/cache.h\n+++ b/cache.h\n@@ -445,6 +445,7 @@ extern int add_index_entry(struct index_state *, struct cache_entry *ce, int opt\n extern struct cache_entry *refresh_cache_entry(struct cache_entry *ce, int really);\n extern void rename_index_entry_at(struct index_state *, int pos, const char *new_name);\n extern int remove_index_entry_at(struct index_state *, int pos);\n+extern void remove_marked_cache_entries(struct index_state *istate);\n extern int remove_file_from_index(struct index_state *, const char *path);\n #define ADD_CACHE_VERBOSE 1\n #define ADD_CACHE_PRETEND 2\ndiff --git a/read-cache.c b/read-cache.c\nindex ca4bec2..bb07371 100644\n--- a/read-cache.c\n+++ b/read-cache.c\n@@ -465,6 +465,26 @@ int remove_index_entry_at(struct index_state *istate, int pos)\n \treturn 1;\n }\n \n+/*\n+ * Remove all cache ententries marked for removal, that is where\n+ * CE_REMOVE is set in ce_flags. This is much more effective than\n+ * calling remove_index_entry_at() for each entry to be removed.\n+ */\n+void remove_marked_cache_entries(struct index_state *istate)\n+{\n+\tstruct cache_entry **ce_array = istate->cache;\n+\tunsigned int i, j;\n+\n+\tfor (i = j = 0; i < istate->cache_nr; i++) {\n+\t\tif (ce_array[i]->ce_flags & CE_REMOVE)\n+\t\t\tremove_name_hash(ce_array[i]);\n+\t\telse\n+\t\t\tce_array[j++] = ce_array[i];\n+\t}\n+\tistate->cache_changed = 1;\n+\tistate->cache_nr = j;\n+}\n+\n int remove_file_from_index(struct index_state *istate, const char *path)\n {\n \tint pos = index_name_pos(istate, path, strlen(path));\ndiff --git a/unpack-trees.c b/unpack-trees.c\nindex e3c3fa1..273b5da 100644\n--- a/unpack-trees.c\n+++ b/unpack-trees.c\n@@ -93,11 +93,9 @@ static int check_updates(struct unpack_trees_options *o)\n \t\t\tdisplay_progress(progress, ++cnt);\n \t\t\tif (o->update)\n \t\t\t\tunlink_entry(ce);\n-\t\t\tremove_index_entry_at(&o->result, i);\n-\t\t\ti--;\n-\t\t\tcontinue;\n \t\t}\n \t}\n+\tremove_marked_cache_entries(&o->result);\n \tremove_scheduled_dirs();\n \n \tfor (i = 0; i < index->cache_nr; i++) {\n-- \n1.6.1.349.g99fa5\n"},{"id":"105355","messageId":"alpine.LFD.2.00.0902181436390.21686@localhost.localdomain","threadId":"17879","inReplyTo":"1234995483-933-1-git-send-email-barvik@broadpark.no","subject":"Re: [PATCH] check_updates(): effective removal of cache entries marked CE_REMOVE","fromName":"Linus Torvalds","fromEmail":"torvalds@linux-foundation.org","sentAt":"2009-02-18T22:44:34Z","receivedAt":"2009-02-18T22:44:34Z","isPatch":true,"sender":{"key":"torvalds@linux-foundation.org","avatar":"https://avatars.githubusercontent.com/u/1024025?v=4"},"body":"\n\nOn Wed, 18 Feb 2009, Kjetil Barvik wrote:\n> \n> To fix this, and use an O(N) algorithm instead, where N is the number\n> of cache_entries, we delete/remove all entries in one loop through all\n> entries.\n\nAck. We've had things like this before. I'm somewhat surprised that it is \nnoticeable even in the \"o->update\" case (since I would have expected the \ncost of actually doing an unlink() to swamp the memmove overhead), but the \npatch looks obviously correct. \n\nLooking at the numbers, I guess it's not _really_ noticeable - it's 1.8% \nof git user-space time, which in turn is about 75% of total time, so it's \nnot a huge improvement, but I'll certainly ack it anyway as being the \nright thing to do. Every little bit helps. \n\n\t\t\tLinus\n"},{"id":"105411","messageId":"81b0412b0902190024t3fc7ab20r9a23c72270ac1033@mail.gmail.com","threadId":"17879","inReplyTo":"1234995483-933-1-git-send-email-barvik@broadpark.no","subject":"Re: [PATCH] check_updates(): effective removal of cache entries marked CE_REMOVE","fromName":"Alex Riesen","fromEmail":"raa.lkml@gmail.com","sentAt":"2009-02-19T08:24:01Z","receivedAt":"2009-02-19T08:24:01Z","isPatch":true,"sender":{"key":"raa.lkml@gmail.com","avatar":"https://avatars.githubusercontent.com/u/324101?v=4"},"body":"2009/2/18 Kjetil Barvik :\n> If we can trust the numbers from oprofile in this case, we saved\n> approximately ((7710 - 46) * 20000) / (2 * 1000 * 1000 * 1000) = 0.077\n> seconds CPU time with this fix for this particular test. And notice\n> that now the CPU did only 46 / 15 = 3.1 cycles/instruction.\n...\n> diff --git a/unpack-trees.c b/unpack-trees.c\n> index e3c3fa1..273b5da 100644\n> --- a/unpack-trees.c\n> +++ b/unpack-trees.c\n> @@ -93,11 +93,9 @@ static int check_updates(struct unpack_trees_options *o)\n> display_progress(progress, ++cnt);\n> if (o->update)\n> unlink_entry(ce);\n> - remove_index_entry_at(&o->result, i);\n> - i--;\n> - continue;\n> }\n> }\n> + remove_marked_cache_entries(&o->result);\n> remove_scheduled_dirs();\n>\n\nWhat commit is this change based on? It does not apply to any\nof Junio's master, next, or pu...\n"},{"id":"105413","messageId":"86ocwy3ido.fsf@broadpark.no","threadId":"17879","inReplyTo":"81b0412b0902190024t3fc7ab20r9a23c72270ac1033@mail.gmail.com","subject":"Re: [PATCH] check_updates(): effective removal of cache entries marked CE_REMOVE","fromName":"Kjetil Barvik","fromEmail":"barvik@broadpark.no","sentAt":"2009-02-19T09:06:59Z","receivedAt":"2009-02-19T09:06:59Z","isPatch":true,"sender":{"key":"barvik@broadpark.no","avatar":null},"body":"Alex Riesen writes:\n\n> 2009/2/18 Kjetil Barvik :\n>> If we can trust the numbers from oprofile in this case, we saved\n>> approximately ((7710 - 46) * 20000) / (2 * 1000 * 1000 * 1000) = 0.077\n>> seconds CPU time with this fix for this particular test. And notice\n>> that now the CPU did only 46 / 15 = 3.1 cycles/instruction.\n> ...\n>> diff --git a/unpack-trees.c b/unpack-trees.c\n>> index e3c3fa1..273b5da 100644\n>> --- a/unpack-trees.c\n>> +++ b/unpack-trees.c\n>> @@ -93,11 +93,9 @@ static int check_updates(struct unpack_trees_options *o)\n>> display_progress(progress, ++cnt);\n>> if (o->update)\n>> unlink_entry(ce);\n>> - remove_index_entry_at(&o->result, i);\n>> - i--;\n>> - continue;\n>> }\n>> }\n>> + remove_marked_cache_entries(&o->result);\n>> remove_scheduled_dirs();\n>>\n>\n> What commit is this change based on? It does not apply to any\n> of Junio's master, next, or pu...\n\n It was based on 'pu', and not a uptodate one. Sorry about that, I\n will update the patch based on master, and include it together with\n the 2 'USE_NSEC'-patches, which I posted some few days ago.\n\n -- kjetil\n"},{"id":"105573","messageId":"7vskm9ftcq.fsf@gitster.siamese.dyndns.org","threadId":"17879","inReplyTo":"1234995483-933-1-git-send-email-barvik@broadpark.no","subject":"Re: [PATCH] check_updates(): effective removal of cache entries marked CE_REMOVE","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2009-02-20T07:41:25Z","receivedAt":"2009-02-20T07:41:25Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"I've queued this in 'next' as part of your earlier series, together with\nthe remaining patches..\n\nI am also a bit surprised that it would make a noticeable difference in\nreal life.\n"},{"id":"105586","messageId":"86vdr5iis0.fsf@broadpark.no","threadId":"17879","inReplyTo":"7vskm9ftcq.fsf@gitster.siamese.dyndns.org","subject":"Re: [PATCH] check_updates(): effective removal of cache entries marked CE_REMOVE","fromName":"Kjetil Barvik","fromEmail":"barvik@broadpark.no","sentAt":"2009-02-20T09:01:35Z","receivedAt":"2009-02-20T09:01:35Z","isPatch":true,"sender":{"key":"barvik@broadpark.no","avatar":null},"body":"Junio C Hamano writes:\n\n> I've queued this in 'next' as part of your earlier series, together with\n> the remaining patches..\n\n Thanks!!\n\n> I am also a bit surprised that it would make a noticeable difference in\n> real life.\n\n I guess that 77 milliseconds compared to 15 seconds is not noticable\n for the Linux checkout test, but since this is an algorithmic\n reduction from O(N^2) to O(N), I would guess that for big working\n trees it can be more noticable.\n\n -- kjetil\n"},{"id":"105590","messageId":"alpine.DEB.1.00.0902201014180.10279@pacific.mpi-cbg.de","threadId":"17879","inReplyTo":"86vdr5iis0.fsf@broadpark.no","subject":"Re: [PATCH] check_updates(): effective removal of cache entries marked CE_REMOVE","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2009-02-20T09:14:41Z","receivedAt":"2009-02-20T09:14:41Z","isPatch":true,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi,\n\nOn Fri, 20 Feb 2009, Kjetil Barvik wrote:\n\n> I guess that 77 milliseconds compared to 15 seconds is not noticable\n\nI guess you meant 15 milliseconds? ;-)\n\nCiao,\nDscho\n"},{"id":"105597","messageId":"86iqn5ifcw.fsf@broadpark.no","threadId":"17879","inReplyTo":"alpine.DEB.1.00.0902201014180.10279@pacific.mpi-cbg.de","subject":"Re: [PATCH] check_updates(): effective removal of cache entries marked CE_REMOVE","fromName":"Kjetil Barvik","fromEmail":"barvik@broadpark.no","sentAt":"2009-02-20T10:15:27Z","receivedAt":"2009-02-20T10:15:27Z","isPatch":true,"sender":{"key":"barvik@broadpark.no","avatar":null},"body":"Johannes Schindelin writes:\n\n> Hi,\n>\n> On Fri, 20 Feb 2009, Kjetil Barvik wrote:\n>\n>> I guess that 77 milliseconds compared to 15 seconds is not noticable\n>\n> I guess you meant 15 milliseconds? ;-)\n\n Ok, I guess I was thinkning abouth the 77 milliseconds reduction of\n the total time this git chekcout' test take, and the total time is 15\n seconds.\n\n -- kjetil, :-)\n\n\n \n"}]}