APM Java Agent creating Deadlock in Web logic

Lakshmi_Narayan · March 25, 2019, 11:50am

Kibana version: 6.6.0

Elasticsearch version: 6.6.0

APM Server version: 6.6.0

APM Agent language and version: elastic-apm-agent-1.3.0.jar

Fresh install or upgraded from other version? Freash

Is there anything special in your setup? For example, are you using the Logstash or Kafka outputs? Are you using a load balancer in front of the APM Servers? Have you changed index pattern, generated custom templates, changed agent configuration etc.

No

Description of the problem including expected versus actual behavior. Please include screenshots (if relevant):

Steps to reproduce:

Weblogic create a dead lock

weblogic.utils.classloaders.ChangeAwareClassLoader.loadClass(ChangeAwareClassLoader.java:68)

    weblogic.utils.classloaders.ChangeAwareClassLoader.loadClass(ChangeAwareClassLoader.java:53)

    java.lang.Class.forName0(Native Method)

    java.lang.Class.forName(Class.java:348)

    co.elastic.apm.agent.bci.bytebuddy.CustomElementMatchers.canLoadClass(CustomElementMatchers.java:84)

    co.elastic.apm.agent.bci.bytebuddy.CustomElementMatchers.access$000(CustomElementMatchers.java:34)

    co.elastic.apm.agent.bci.bytebuddy.CustomElementMatchers$1.matches(CustomElementMatchers.java:73)

    co.elastic.apm.agent.bci.bytebuddy.CustomElementMatchers$1.matches(CustomElementMatchers.java:60)

    co.elastic.apm.agent.bci.ElasticApmAgent$4.matches(ElasticApmAgent.java:171)

Eyal_Koren · March 25, 2019, 2:37pm

Where is this thread snapshot coming from? Can you get the other thread with which this deadlock occurs as well? Does it happen every time you start your WebLogic? How can you say it is a deadlock?

We are not testing with WebLogic, so I can't reproduce at the moment. Maybe if you set agent debug level to DEBUG and provide more info with the entire log I can see some more to at least offer a workaround, if not find the root cause.

Thanks!

Lakshmi_Narayan · March 26, 2019, 10:13am

hi, @Eyal_Koren thanks for your response. Please find the attached thread dump that shows both the thread that is in deadlock.

both locked at the same point

- locked **&lt;0x00000004c3d14f28&gt;** (a weblogic.utils.classloaders.ChangeAwareClassLoader)

First tread

[ACTIVE] ExecuteThread: '31' for queue: 'weblogic.kernel.Default (self-tuning)' - priority:5 - threadId:0x00007fe929af5000 - nativeId:0x7dcd - nativeId (decimal):32205 - state:BLOCKED
stackTrace:
java.lang.Thread.State: BLOCKED (on object monitor)
at weblogic.utils.classloaders.ChangeAwareClassLoader.loadClass(ChangeAwareClassLoader.java:81)
- waiting to lock <0x00000004c3d14f28> (a weblogic.utils.classloaders.ChangeAwareClassLoader)
- locked <0x00000007a990f4f0> (a java.lang.Object)
at weblogic.utils.classloaders.ChangeAwareClassLoader.loadClass(ChangeAwareClassLoader.java:53)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:348)
at co.elastic.apm.agent.bci.bytebuddy.CustomElementMatchers.canLoadClass(CustomElementMatchers.java:84)
at co.elastic.apm.agent.bci.bytebuddy.CustomElementMatchers.access$000(CustomElementMatchers.java:34)
at co.elastic.apm.agent.bci.bytebuddy.CustomElementMatchers$1.matches(CustomElementMatchers.java:73)
at co.elastic.apm.agent.bci.bytebuddy.CustomElementMatchers$1.matches(CustomElementMatchers.java:60)
at co.elastic.apm.agent.bci.ElasticApmAgent$4.matches(ElasticApmAgent.java:171)
at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$Transformation$Simple.matches(AgentBuilder.java:9901)
at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$Transformation$Simple.resolve(AgentBuilder.java:9914)
at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$Transformation$Compound.resolve(AgentBuilder.java:10170)
at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.resolve(AgentBuilder.java:10502)
at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.doTransform(AgentBuilder.java:10469)
at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:10432)
at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.access$1500(AgentBuilder.java:10198)

second thread

[ACTIVE] ExecuteThread: '16' for queue: 'weblogic.kernel.Default (self-tuning)' - priority:5 - threadId:0x00007fe929c92000 - nativeId:0x7dbe - nativeId (decimal):32190 - state:BLOCKED
stackTrace:
java.lang.Thread.State: BLOCKED (on object monitor)
at weblogic.utils.classloaders.ChangeAwareClassLoader.loadClass(ChangeAwareClassLoader.java:68)
- waiting to lock <0x00000007a990f4f0> (a java.lang.Object)
at weblogic.utils.classloaders.ChangeAwareClassLoader.loadClass(ChangeAwareClassLoader.java:53)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:348)
at co.elastic.apm.agent.bci.bytebuddy.CustomElementMatchers.canLoadClass(CustomElementMatchers.java:84)
at co.elastic.apm.agent.bci.bytebuddy.CustomElementMatchers.access$000(CustomElementMatchers.java:34)
at co.elastic.apm.agent.bci.bytebuddy.CustomElementMatchers$1.matches(CustomElementMatchers.java:73)
at co.elastic.apm.agent.bci.bytebuddy.CustomElementMatchers$1.matches(CustomElementMatchers.java:60)
at co.elastic.apm.agent.bci.ElasticApmAgent$4.matches(ElasticApmAgent.java:171)
at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$Transformation$Simple.matches(AgentBuilder.java:9901)
at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$Transformation$Simple.resolve(AgentBuilder.java:9914)
at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$Transformation$Compound.resolve(AgentBuilder.java:10170)
at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.resolve(AgentBuilder.java:10502)
at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.doTransform(AgentBuilder.java:10469)
at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:10432)
at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.access$1500(AgentBuilder.java:10198)
at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$LegacyVmDispatcher.run(AgentBuilder.java:10807)
at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer$LegacyVmDispatcher.run(AgentBuilder.java:10754)
at java.security.AccessController.doPrivileged(Native Method)
at co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer.transform(AgentBuilder.java:10355)
at sun.instrument.TransformerManager.transform(TransformerManager.java:188)
at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java:428)
at java.lang.ClassLoader.defineClass1(Native Method)
at java.lang.ClassLoader.defineClass(ClassLoader.java:763)
at sun.reflect.GeneratedMethodAccessor377.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.cglib.core.ReflectUtils.defineClass(ReflectUtils.java:523)
at org.springframework.cglib.core.AbstractClassGenerator.generate(AbstractClassGenerator.java:359)
- locked <0x00000004c3d14f28> (a weblogic.utils.classloaders.ChangeAwareClassLoader)

Lakshmi_Narayan · March 26, 2019, 10:15am

[LN] We have not enabled the APM logs, we have just done can provide if it re-happen

Eyal_Koren · March 26, 2019, 10:49am

Thanks for uploading the thread dump.
It looks like a bug in WebLogic's class loading mechanism- it seems to allow concurrent class loading but not doing it completely thread-safe. See if you can find something about that documented and fixed.

In any case, I suggest you upgrade to a newer agent version, as a recent PR should considerably reduce the chances for such a deadlock.

1.4.0 is available for quite some time, but today/tomorrow we will release 1.5.0 so maybe wait for that

felixbarny · April 3, 2019, 3:31pm

1.5.0 has now been released. Could you try out if it works for you now?

system · April 24, 2019, 11:31am

This topic was automatically closed 20 days after the last reply. New replies are no longer allowed.