RFR(XS) 8249719: MethodHandle performance suffers from bad ResolvedMethodTable hash function

[Thomas Stüfe]

A manual test may be enough too, I mean how probable is it that this
particular error would ever resurface. Better would be, maybe, to just add
an assert into the insert path which fires if a bucket length is above a
certain threshold. That would catch all kinds of bad hashes, not just this
one case.

BTW maybe we should add a jcmd option to print this table, like we have for
the symbol- and stringtable.

Cheers Thomas

On Mon, Jul 27, 2020 at 8:44 PM <coleen.phillimore at oracle.com> wrote:

>
>
> On 7/27/20 2:33 PM, Volker Simonis wrote:
>
> I like this solution although it introduces a hard dependency on the exact
> log format. But that's probably not a big issue.
>
> Another possibility would probably be to add a gtest.
>
> But I'd also be happy to make the current test a manual test.
>
> Let's see what Coleen's opinion is. We can use her as a tiebreaker :)
>
> Otherwise I'll leave it up to Andrei to choose his preferred option :)
>
>
> So what I suggested is risky (I'm curious to see if it works).  My second
> choice is to make it a manual test.  Hopefully we won't be changing up the
> hashcode all the time and risk breaking this again.
> thanks,
> Coleen
>
>
>
> On Mon, Jul 27, 2020 at 8:04 PM Thomas Stüfe <thomas.stuefe at gmail.com>
> wrote:
>
>> Hi Andrei,
>>
>> I was afraid this might happen, but only occurred to me after the review.
>>
>> My proposal would be:
>>
>> - in resolvedMethodTable.cpp, extend the log message in log_insert() and
>> print out the hashcode too (e.g. "ResolvedMethod entry added for ...
>> (4711)").
>>
>> - In the test, start your test as a sub process, give it
>> -Xlog:membername+table=debug, and scan the output line for "ResolvedMethod
>> entry added for <your class name> (<hash>)". Extract the hash. Read two or
>> three lines and compare the hash.
>>
>> The advantage would be that you do not need to load 200k classes to see
>> that your regression test works, and it is timing independent. For examples
>> of sub process spawning and output scanning, there are many jtreg tests
>> already (e.g. runtime/ErrorHandling has a few).
>>
>> Just my 5 cent. Maybe the others have different proposals.
>>
>> Cheers, Thomas
>>
>>
>>
>>
>> On Mon, Jul 27, 2020 at 7:52 PM Andrei Pangin <andrei.pangin at gmail.com>
>> wrote:
>>
>>> Hi,
>>>
>>> Coleen, Thomas, thank you for your reviews. It turns out though that my
>>> new test times out on debug builds (thanks Volker for double-checking).
>>>
>>> Test Tier Platform Description
>>> runtime/MemberName/ResolvedMethodTableHash.java tier1
>>> linux-aarch64-debug Error: Program `...java' timed out (timeout set to
>>> ...ms, elapsed time including timeout handling was ...ms).
>>> runtime/MemberName/ResolvedMethodTableHash.java tier1 windows-x64-debug Error:
>>> Program
>>> `c\:\\ade\\mesos\\work_dir\\jib-master\\install\\...-07-27-0826248.andrei.pangin.source\\windows-x64-debug.jdk\\jdk-16\\fastdebug\\bin\\java'
>>> timed out (timeout set to ...ms, elapsed time including timeout handling
>>> was ...ms).
>>> runtime/MemberName/ResolvedMethodTableHash.java tier1 macosx-x64-debug Error:
>>> Program `...java' timed out (timeout set to ...ms, elapsed time including
>>> timeout handling was ...ms).
>>>
>>> Apparently, we can't rely on timing, since this test runs two orders of
>>> magnitude slower on debug JVM than on product one. I could simply mark the
>>> test as manual, or is there a better idea? Maybe, adjust the parameters and
>>> run the test automatically only on product or only on debug JVM? What do
>>> you think?
>>>
>>> Regards,
>>> Andrei
>>>
>>> сб, 25 июл. 2020 г. в 17:34, <coleen.phillimore at oracle.com>:
>>>
>>>>
>>>> Hi Andrei,
>>>> This looks good.  Thank you for finding this bug.  And thanks to Volker
>>>> for sponsoring it as well.
>>>> Nice to see you on the list, Andrei!
>>>> Coleen
>>>>
>>>> On 7/25/20 3:18 AM, Thomas Stüfe wrote:
>>>>
>>>> Hi, Andrei,
>>>>
>>>> Good find. I played around with a test of generating lots of lambdas
>>>> and yes, all the hashes are equal. With your patch invocation time went
>>>> down by half (that was for 10000 lambdas).
>>>>
>>>> The test looks fine though the normal way to do this seems to be jcod.
>>>> I personally don't care since the test is nice and self contained that way,
>>>> but someone from the Oracle runtime group should confirm this is fine
>>>> (ccing Coleen).
>>>>
>>>> JDK11 seems to be affected too.
>>>>
>>>> This probably also affects jruby.
>>>>
>>>> +1 from me.
>>>>
>>>> ..Thomas
>>>>
>>>> On Fri, Jul 24, 2020 at 4:53 PM Andrei Pangin <andrei.pangin at gmail.com>
>>>> wrote:
>>>>
>>>>> Hi,
>>>>>
>>>>> Please review a small fix to a not-so-small performance issue that
>>>>> we've
>>>>> seen when migrating a production application from JDK 8 to JDK 14.
>>>>>
>>>>> On certain workloads, where Nashorn produces thousands MethodHandles,
>>>>> ResolvedMethodTable operations become extremely slow due to degenerate
>>>>> hashcode. This patch basically fixes hashcode by including the method
>>>>> holder's name in the computation. More details in the bug report.
>>>>>
>>>>> CR: https://bugs.openjdk.java.net/browse/JDK-8249719
>>>>> Webrev: https://cr.openjdk.java.net/~apangin/8249719/webrev/
>>>>>
>>>>> Tested: tier1-2, hotspot*runtime
>>>>>
>>>>> I'll be glad if someone could sponsor the patch.
>>>>>
>>>>> Thank you,
>>>>> Andrei Pangin
>>>>>
>>>>
>>>>
>