Questions about negative loaded classes and Lambda Form Compilation

[Wenlei Xie]

Hi,

We are still seeing this on 1.8.0_144. Just wondering these is any idea
what might cause this, or what kind of thing we can do to investigate the
VM is in this state?

Thank you !!

BTW: I note the attachment doesn't seem to work. So here is the link to
screenshot about the negative number of loaded classes: https://imgur.com/a/
kGbto

On Wed, Sep 27, 2017 at 11:03 AM, Wenlei Xie <wenlei.xie at gmail.com> wrote:

> Hi,
>
> We recently see some weird behavior of JVM in our production cluster. We
> are running JDK 1.8.0_131.
>
> 1. On more than half of the machines (200 out of 400 machines), we see he
> JMX counter report negative LoadedClassCount, see attached jmxcounter.png.
>
> After some further dig, we note UnloadedClassCount is larger than
> TotalLoadedClassCount. And  LoadedClassCount (-695,710) =
> TotalLoadedClassCount - UnloadedClassCount . PerfCounter reports the same
> number, here is the result on the same machine:
>
>     $ jcmd 307 PerfCounter.print | grep -i class | grep -i java.cls
>     java.cls.loadedClasses=192004392
>     java.cls.sharedLoadedClasses=0
>     java.cls.sharedUnloadedClasses=0
>     java.cls.unloadedClasses=192700102
>
>
>
> 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.
>
>
>     "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.InvokerByteco
> deGenerator.loadAndInitializeInvokerClass(InvokerBytecodeGen
> erator.java:284)
>             at java.lang.invoke.InvokerByteco
> deGenerator.loadMethod(InvokerBytecodeGenerator.java:276)
>             at java.lang.invoke.InvokerByteco
> deGenerator.generateCustomizedCode(InvokerBytecodeGenerator.java:618)
>             at java.lang.invoke.LambdaForm.co
> mpileToBytecode(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.maybeCustomize(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.a
> ggregation.MinMaxHelper.combineStateWithState(MinMaxHelper.java:141)
>             at com.facebook.presto.operator.a
> ggregation.MaxAggregationFunction.combine(MaxAggregationFunction.java:108)
>             at java.lang.invoke.LambdaForm$DM
> H/1607453282.invokeStatic_L3_V(LambdaForm$DMH)
>             at java.lang.invoke.LambdaForm$BM
> H/1118134445.reinvoke(LambdaForm$BMH)
>             at java.lang.invoke.LambdaForm$MH
> /1971758264.linkToTargetMethod(LambdaForm$MH)
>             at com.facebook.presto.$gen.Integ
> erIntegerMaxGroupedAccumulator_3439.addIntermediate(Unknown Source)
>             at com.facebook.presto.operator.a
> ggregation.builder.InMemoryHashAggregationBuilder$Aggregator
> .processPage(InMemoryHashAggregationBuilder.java:367)
>             at com.facebook.presto.operator.a
> ggregation.builder.InMemoryHashAggregationBuilder.processPag
> e(InMemoryHashAggregationBuilder.java:138)
>             at com.facebook.presto.operator.H
> ashAggregationOperator.addInput(HashAggregationOperator.java:400)
>             at com.facebook.presto.operator.D
> river.processInternal(Driver.java:343)
>             at com.facebook.presto.operator.D
> river.lambda$processFor$6(Driver.java:241)
>             at com.facebook.presto.operator.Driver$$Lambda$765/
> 442308692.get(Unknown Source)
>             at com.facebook.presto.operator.D
> river.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.ThreadPoo
> lExecutor.runWorker(ThreadPoolExecutor.java:1142)
>             at java.util.concurrent.ThreadPoo
> lExecutor$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
>



-- 
Best Regards,
Wenlei Xie

Email: wenlei.xie at gmail.com