Questions about ... Lambda Form Compilation

Sat Oct 7 06:42:53 UTC 2017

Thank you Vladimir!

We are aware of MethodHandle get customization after calling over 127 times
(thank you for the explanation in
http://mail.openjdk.java.net/pipermail/mlvm-dev/2017-May/006755.html as
well! ). And thus we are trying to avoid continuously instantiating them.

For this case, the MethodHandle get continuously instantiated should be
cached by LoadingCache in Guava. We are looking into why the cache fails to
work in the expected way. Will get back if we have any new observations or
findings!

Thank you for the help!

Best,
Wenlei

On Tue, Oct 3, 2017 at 4:54 AM, Vladimir Ivanov <
vladimir.x.ivanov at oracle.com> wrote:

> Hi,
>
> 2. For the same cluster, we also see over half of machines repeatedly
>> experiencing full GC due to Metaspace full. We dump JSTACK for every
>> minute
>> during 30 minutes, and see many threads are trying to compile the exact
>> same lambda form throughout the 30-minute period.
>>
>> Here is an example stacktrace on one machine. The LambdaForm triggers the
>> compilation on that machine is always LambdaForm$MH/170067652. Once it's
>> compiled, it should use the new compiled lambda form. We don't know why
>> it's still trying to compile the same lambda form again and again. --
>> Would
>> it be because the compiled lambda form somehow failed to load? This might
>> relate to the negative number of loaded classes.
>>
>
> What you are seeing here is LambdaForm customization (8069591 [1]).
>
> Customization creates a new LambdaForm instance specialized for a
> particular MethodHandle instance (no LF sharing possible). It was designed
> to alleviate performance penalty when inlining through a MH invoker doesn't
> happen and enables JIT-compilers to compile the whole method handle chain
> into a single nmethod. Without customization a method handle chain breaks
> up into a chain of small nmethods (1 nmethod per LambdaForm) and calls
> between them start dominate the execution time. (More details are available
> in [2].)
>
> Customization takes place once a method handle has been invoked through
> MH.invoke/invokeExact() more than 127 times.
>
> Considering you observe continuous customization, it means there are
> method handles being continuously instantiated and used which share the
> same lambda form (LambdaForm$MH/170067652). It leads to excessive
> generation of VM anonymous classes and creates memory pressure in Metaspace.
>
> As a workaround, you can try to disable LF customization
> (java.lang.invoke.MethodHandle.CUSTOMIZE_THRESHOLD=-1).
>
> But I'd suggest to look into why the application continuously creates
> method handles. As you noted, it doesn't play well with existing heuristics
> aimed at maximum throughput which assume the application behavior
> "stabilizes" over time.
>
> Best regards,
> Vladimir Ivanov
>
> [1] https://bugs.openjdk.java.net/browse/JDK-8069591
>
> [2] http://cr.openjdk.java.net/~vlivanov/talks/2015-JVMLS_State_of_JLI.pdf
>     slides #45-#50
>
>      "20170926_232912_39740_3vuuu.1.79-4-76640" #76640 prio=5 os_prio=0
>> tid=0x00007f908006dbd0 nid=0x150a6 runnable [0x00007f8bddb1b000]
>>         java.lang.Thread.State: RUNNABLE
>>              at sun.misc.Unsafe.defineAnonymousClass(Native Method)
>>              at java.lang.invoke.InvokerBytecodeGenerator.
>> loadAndInitializeInvokerClass(InvokerBytecodeGenerator.java:284)
>>              at java.lang.invoke.InvokerBytecodeGenerator.loadMethod(
>> InvokerBytecodeGenerator.java:276)
>>              at java.lang.invoke.InvokerBytecodeGenerator.
>> generateCustomizedCode(InvokerBytecodeGenerator.java:618)
>>              at java.lang.invoke.LambdaForm.compileToBytecode(LambdaForm.
>> java:654)
>>              at java.lang.invoke.LambdaForm.prepare(LambdaForm.java:635)
>>              at java.lang.invoke.MethodHandle.
>> updateForm(MethodHandle.java:
>> 1432)
>>              at java.lang.invoke.MethodHandle.
>> customize(MethodHandle.java:
>> 1442)
>>              at java.lang.invoke.Invokers.mayb
>> eCustomize(Invokers.java:407)
>>              at java.lang.invoke.Invokers.chec
>> kCustomized(Invokers.java:398)
>>              at java.lang.invoke.LambdaForm$MH/170067652.invokeExact_MT(
>> LambdaForm$MH)
>>              at com.facebook.presto.operator.aggregation.MinMaxHelper.
>> combineStateWithState(MinMaxHelper.java:141)
>>              at com.facebook.presto.operator.aggregation.
>> MaxAggregationFunction.combine(MaxAggregationFunction.java:108)
>>              at java.lang.invoke.LambdaForm$DMH/1607453282.invokeStatic_
>> L3_V(LambdaForm$DMH)
>>              at java.lang.invoke.LambdaForm$BMH/1118134445.reinvoke(
>> LambdaForm$BMH)
>>              at java.lang.invoke.LambdaForm$MH/1971758264.
>> linkToTargetMethod(LambdaForm$MH)
>>              at com.facebook.presto.$gen.IntegerIntegerMaxGroupedAccumu
>> lator_3439.addIntermediate(Unknown Source)
>>              at com.facebook.presto.operator.aggregation.builder.
>> InMemoryHashAggregationBuilder$Aggregator.processPage(
>> InMemoryHashAggregationBuilder.java:367)
>>              at com.facebook.presto.operator.aggregation.builder.
>> InMemoryHashAggregationBuilder.processPage(InMemoryHashAggregationBuilder
>> .java:138)
>>              at com.facebook.presto.operator.HashAggregationOperator.
>> addInput(HashAggregationOperator.java:400)
>>              at com.facebook.presto.operator.D
>> river.processInternal(Driver.
>> java:343)
>>              at com.facebook.presto.operator.Driver.lambda$processFor$6(
>> Driver.java:241)
>>              at com.facebook.presto.operator.Driver$$Lambda$765/
>> 442308692.get(Unknown
>> Source)
>>              at com.facebook.presto.operator.Driver.tryWithLock(Driver.
>> java:614)
>>              at com.facebook.presto.operator.D
>> river.processFor(Driver.java:
>> 235)
>>              at com.facebook.presto.execution.SqlTaskExecution$
>> DriverSplitRunner.processFor(SqlTaskExecution.java:622)
>>              at com.facebook.presto.execution.executor.
>> PrioritizedSplitRunner.process(PrioritizedSplitRunner.java:163)
>>              at com.facebook.presto.execution.executor.TaskExecutor$
>> TaskRunner.run(TaskExecutor.java:485)
>>              at java.util.concurrent.ThreadPoolExecutor.runWorker(
>> ThreadPoolExecutor.java:1142)
>>              at java.util.concurrent.ThreadPoolExecutor$Worker.run(
>> ThreadPoolExecutor.java:617)
>>              at java.lang.Thread.run(Thread.java:748)
>>      ...
>>
>>
>>
>> Both issues go away after we restart the JVM, and the same query won't
>> trigger the LambdaForm compilation issue, so it looks like the JVM enters
>> some weird state.  We are wondering if there is any thoughts on what could
>> trigger these issues? Or is there any suggestions about how to further
>> investigate it next time we see the VM in this state?
>>
>> Thank you.
>>
>>
>>

-- 
Best Regards,
Wenlei Xie (谢文磊)

Email: wenlei.xie at gmail.com