{"thread":{"id":"11229","subject":"Performance problem, long run of identical hashes","startedAt":"2007-12-10T15:07:50Z","lastAt":"2007-12-10T20:11:15Z","messageCount":7,"participants":["Jon Smirl","Nicolas Pitre","David Kastrup"],"isPatch":false,"patchVersion":null,"patchTotal":null},"messages":[{"id":"62581","messageId":"9e4733910712100707i66e185bofe22805b8e0ba4d8@mail.gmail.com","threadId":"11229","inReplyTo":null,"subject":"Performance problem, long run of identical hashes","fromName":"Jon Smirl","fromEmail":"jonsmirl@gmail.com","sentAt":"2007-12-10T15:07:50Z","receivedAt":"2007-12-10T15:07:50Z","isPatch":false,"sender":{"key":"jonsmirl@gmail.com","avatar":"https://gravatar.com/avatar/cff3bf5bfdfa6708b905712ff91f0f9b8aaca161659f38c02b787920d5d28b7e?d=mp&s=160"},"body":"Running oprofile during my gcc repack shows this loop as the hottest\nplace in the code by far. I added some debug printfs which show that I\nhave a 100,000+ run of identical hash entries. Processing the 100,000\nentries also causes RAM consumption to explode.\n\ncreate_delta()\n\tfor (entry = index->hash[i]; entry < index->hash[i+1]; entry++) {\n\t\tconst unsigned char *ref = entry->ptr;\n\t\tconst unsigned char *src = data;\n\t\tunsigned int ref_size = ref_top - ref;\n\t\tif (entry->val != val)\n\t\t\tcontinue;\n\t\tif (ref_size > top - src)\n\t\t\tref_size = top - src;\n\t\tif (ref_size <= msize)\n\t\t\tbreak;\n\t\twhile (ref_size-- && *src++ == *ref)\n\t\t\tref++;\n\t\tif (msize < ref - entry->ptr) {\n\t\t\t/* this is our best match so far */\n\t\t\tmsize = ref - entry->ptr;\n\t\t\tmoff = entry->ptr - ref_data;\n\t\t\tif (msize >= 4096) /* good enough */\n\t\t\t\tbreak;\n\t\t}\n\t}\n\n-- \nJon Smirl\njonsmirl@gmail.com\n"},{"id":"62585","messageId":"alpine.LFD.0.99999.0712101037270.555@xanadu.home","threadId":"11229","inReplyTo":"9e4733910712100707i66e185bofe22805b8e0ba4d8@mail.gmail.com","subject":"Re: Performance problem, long run of identical hashes","fromName":"Nicolas Pitre","fromEmail":"nico@cam.org","sentAt":"2007-12-10T15:45:49Z","receivedAt":"2007-12-10T15:45:49Z","isPatch":false,"sender":{"key":"nico@fluxnic.net","avatar":"https://avatars.githubusercontent.com/u/702790?v=4"},"body":"On Mon, 10 Dec 2007, Jon Smirl wrote:\n\n> Running oprofile during my gcc repack shows this loop as the hottest\n> place in the code by far.\n\nWell, that is kind of expected.\n\n> I added some debug printfs which show that I\n> have a 100,000+ run of identical hash entries. Processing the 100,000\n> entries also causes RAM consumption to explode.\n\nThat is impossible. If you look at the code where those hash entries \nare created in create_delta_index(), you'll notice a hard limit of \nHASH_LIMIT (currently 64) is imposed on the number of identical hash \nentries.\n\n\nNicolas\n"},{"id":"62595","messageId":"85lk82plwv.fsf@lola.goethe.zz","threadId":"11229","inReplyTo":"alpine.LFD.0.99999.0712101037270.555@xanadu.home","subject":"Re: Performance problem, long run of identical hashes","fromName":"David Kastrup","fromEmail":"dak@gnu.org","sentAt":"2007-12-10T16:14:08Z","receivedAt":"2007-12-10T16:14:08Z","isPatch":false,"sender":{"key":"dak@gnu.org","avatar":"https://avatars.githubusercontent.com/u/52141349?v=4"},"body":"Nicolas Pitre writes:\n\n> On Mon, 10 Dec 2007, Jon Smirl wrote:\n>\n>> Running oprofile during my gcc repack shows this loop as the hottest\n>> place in the code by far.\n>\n> Well, that is kind of expected.\n>\n>> I added some debug printfs which show that I\n>> have a 100,000+ run of identical hash entries. Processing the 100,000\n>> entries also causes RAM consumption to explode.\n>\n> That is impossible. If you look at the code where those hash entries \n> are created in create_delta_index(), you'll notice a hard limit of \n> HASH_LIMIT (currently 64) is imposed on the number of identical hash \n> entries.\n\nWell, impossible is a strong word to use with respect to code: bugs are\npossible. However, we have the assertion\n\n\tassert(packed_entry - (struct index_entry *)mem == entries);\n\nin create_delta_index and that makes a pretty strong guarantee that the\nculling of hash entries should be effective. So at least the overall\n_number_ of entries should be consistent. If there is a bug, it might\nbe that they get garbled or something.\n\nIt is also not clear how this could cause an explosion of RAM\nconsumption in the loop.\n\n-- \nDavid Kastrup, Kriemhildstr. 15, 44793 Bochum\n"},{"id":"62589","messageId":"9e4733910712100820k1bd0959fsdfae92727826c6db@mail.gmail.com","threadId":"11229","inReplyTo":"alpine.LFD.0.99999.0712101037270.555@xanadu.home","subject":"Re: Performance problem, long run of identical hashes","fromName":"Jon Smirl","fromEmail":"jonsmirl@gmail.com","sentAt":"2007-12-10T16:20:40Z","receivedAt":"2007-12-10T16:20:40Z","isPatch":false,"sender":{"key":"jonsmirl@gmail.com","avatar":"https://gravatar.com/avatar/cff3bf5bfdfa6708b905712ff91f0f9b8aaca161659f38c02b787920d5d28b7e?d=mp&s=160"},"body":"On 12/10/07, Nicolas Pitre wrote:\n> On Mon, 10 Dec 2007, Jon Smirl wrote:\n>\n> > Running oprofile during my gcc repack shows this loop as the hottest\n> > place in the code by far.\n>\n> Well, that is kind of expected.\n>\n> > I added some debug printfs which show that I\n> > have a 100,000+ run of identical hash entries. Processing the 100,000\n> > entries also causes RAM consumption to explode.\n>\n> That is impossible. If you look at the code where those hash entries\n> are created in create_delta_index(), you'll notice a hard limit of\n> HASH_LIMIT (currently 64) is imposed on the number of identical hash\n> entries.\n\nOn 12/10/07, Jon Smirl wrote:\n> On 12/9/07, Jon Smirl wrote:\n> > > + if (victim) {\n> > > + sub_size = victim->remaining / 2;\n> > > + list = victim->list + victim->list_size - sub_size;\n> > > + while (sub_size && list[0]->hash &&\n> > > + list[0]->hash == list[-1]->hash) {\n> > > + list++;\n> >\n> > I think you needed to copy sub_size to another variable for this loop\n>\n> Copying sub_size was wrong. I believe you are checking for deltas on\n> the same file. It's probably that chain of 103,817 deltas that can't\n> be broken up.\n\nAt the end of multi-threaded repack one thread ends up with 45 minutes\nof work after all the other threads have exited. That's because it\nhits this loop and can't spit the list any more.\n\nIf the lists can't be over 64 identical entries, why do I get caught\nin this loop for 50,000+ iterations? If remove this loop the threads\nare balanced right to the end.\n\n-- \nJon Smirl\njonsmirl@gmail.com\n\n\n-- \nJon Smirl\njonsmirl@gmail.com\n"},{"id":"62592","messageId":"alpine.LFD.0.99999.0712101129050.555@xanadu.home","threadId":"11229","inReplyTo":"9e4733910712100820k1bd0959fsdfae92727826c6db@mail.gmail.com","subject":"Re: Performance problem, long run of identical hashes","fromName":"Nicolas Pitre","fromEmail":"nico@cam.org","sentAt":"2007-12-10T16:30:10Z","receivedAt":"2007-12-10T16:30:10Z","isPatch":false,"sender":{"key":"nico@fluxnic.net","avatar":"https://avatars.githubusercontent.com/u/702790?v=4"},"body":"On Mon, 10 Dec 2007, Jon Smirl wrote:\n\n> On 12/10/07, Nicolas Pitre wrote:\n> > On Mon, 10 Dec 2007, Jon Smirl wrote:\n> >\n> > > Running oprofile during my gcc repack shows this loop as the hottest\n> > > place in the code by far.\n> >\n> > Well, that is kind of expected.\n> >\n> > > I added some debug printfs which show that I\n> > > have a 100,000+ run of identical hash entries. Processing the 100,000\n> > > entries also causes RAM consumption to explode.\n> >\n> > That is impossible. If you look at the code where those hash entries\n> > are created in create_delta_index(), you'll notice a hard limit of\n> > HASH_LIMIT (currently 64) is imposed on the number of identical hash\n> > entries.\n> \n> On 12/10/07, Jon Smirl wrote:\n> > On 12/9/07, Jon Smirl wrote:\n> > > > + if (victim) {\n> > > > + sub_size = victim->remaining / 2;\n> > > > + list = victim->list + victim->list_size - sub_size;\n> > > > + while (sub_size && list[0]->hash &&\n> > > > + list[0]->hash == list[-1]->hash) {\n> > > > + list++;\n> > >\n> > > I think you needed to copy sub_size to another variable for this loop\n> >\n> > Copying sub_size was wrong. I believe you are checking for deltas on\n> > the same file. It's probably that chain of 103,817 deltas that can't\n> > be broken up.\n> \n> At the end of multi-threaded repack one thread ends up with 45 minutes\n> of work after all the other threads have exited. That's because it\n> hits this loop and can't spit the list any more.\n> \n> If the lists can't be over 64 identical entries, why do I get caught\n> in this loop for 50,000+ iterations? If remove this loop the threads\n> are balanced right to the end.\n\nCompletely different issue.\n\nPlease read my other answers.\n\n\nNicolas\n"},{"id":"62609","messageId":"85tzmqnxua.fsf@lola.goethe.zz","threadId":"11229","inReplyTo":"alpine.LFD.0.99999.0712101037270.555@xanadu.home","subject":"Re: Performance problem, long run of identical hashes","fromName":"David Kastrup","fromEmail":"dak@gnu.org","sentAt":"2007-12-10T19:39:25Z","receivedAt":"2007-12-10T19:39:25Z","isPatch":false,"sender":{"key":"dak@gnu.org","avatar":"https://avatars.githubusercontent.com/u/52141349?v=4"},"body":"Nicolas Pitre writes:\n\n> On Mon, 10 Dec 2007, Jon Smirl wrote:\n>\n>> Running oprofile during my gcc repack shows this loop as the hottest\n>> place in the code by far.\n>\n> Well, that is kind of expected.\n>\n>> I added some debug printfs which show that I\n>> have a 100,000+ run of identical hash entries. Processing the 100,000\n>> entries also causes RAM consumption to explode.\n>\n> That is impossible. If you look at the code where those hash entries \n> are created in create_delta_index(), you'll notice a hard limit of \n> HASH_LIMIT (currently 64) is imposed on the number of identical hash \n> entries.\n\nOn the other hand, if we have, say, laaaaaarge streaks of zeros, what\nhappens is that we have 64 hashes seeing them. Now about 4096 bytes are\ncompared, and then the comparison stops. Then it scans backwards to\nseek for more zeros (and finds about 64k of them before it stops) and\nfolds them into the current compacted form. Each of these backward\nscans (of which we have 64 in the worst case) is in a different memory\narea. So since we scan/compare areas of 64k for each advance of 4k, we\nhave an overscanning factor of 16 (for a worst case scenario).\n\nNot sure whether this is what we are seeing here. It would still not\nexplain exploding memory usage I think.\n\n-- \nDavid Kastrup, Kriemhildstr. 15, 44793 Bochum\n"},{"id":"62612","messageId":"alpine.LFD.0.99999.0712101458140.555@xanadu.home","threadId":"11229","inReplyTo":"85tzmqnxua.fsf@lola.goethe.zz","subject":"Re: Performance problem, long run of identical hashes","fromName":"Nicolas Pitre","fromEmail":"nico@cam.org","sentAt":"2007-12-10T20:11:15Z","receivedAt":"2007-12-10T20:11:15Z","isPatch":false,"sender":{"key":"nico@fluxnic.net","avatar":"https://avatars.githubusercontent.com/u/702790?v=4"},"body":"On Mon, 10 Dec 2007, David Kastrup wrote:\n\n> Nicolas Pitre writes:\n> \n> > On Mon, 10 Dec 2007, Jon Smirl wrote:\n> >\n> >> I added some debug printfs which show that I\n> >> have a 100,000+ run of identical hash entries. Processing the 100,000\n> >> entries also causes RAM consumption to explode.\n> >\n> > That is impossible. If you look at the code where those hash entries \n> > are created in create_delta_index(), you'll notice a hard limit of \n> > HASH_LIMIT (currently 64) is imposed on the number of identical hash \n> > entries.\n> \n> On the other hand, if we have, say, laaaaaarge streaks of zeros, what\n> happens is that we have 64 hashes seeing them. Now about 4096 bytes are\n> compared, and then the comparison stops.\n\nNo.\n\nWhat would happen in that case is that the first hash entry pointing \nsomewhere in the beginning of the zero chunk will match _at least_ 4096 \nbytes, probably much more, up to the end of the buffer if that is \npossible.\n\n> Then it scans backwards to\n> seek for more zeros (and finds about 64k of them before it stops)\n\nThe first hash entry for those zeroes is going to point at an offset not \ngreater than 15 bytes from the start of the zero area. So, unless both \nbuffers are going to match even before that zero area, the backward scan \nwill stop quickly.\n\n> folds them into the current compacted form. Each of these backward\n> scans (of which we have 64 in the worst case) is in a different memory\n> area. So since we scan/compare areas of 64k for each advance of 4k, we\n> have an overscanning factor of 16 (for a worst case scenario).\n\nActually, if we matched 100MB of zeroes, we'll just encode that in a \nsuite of 64KB copy operations, and continue scanning the buffer after \nthat 100MB.\n\nSo I don't see where your scan/compare areas of 64k for each advance of \n4k comes from.\n\n> Not sure whether this is what we are seeing here. It would still not\n> explain exploding memory usage I think.\n\nRight.\n\n\nNicolas\n"}]}