Anthony Dahanne
2014-10-16 23:20:21 UTC
Hello Jersey team /users,
I am encountering in an intermittent OOME with Jersey Client 2.6 (yeah I
know the latest is 2.13, but 2.6 is the latest version working with JDK
1.6) - this issue appears when we try to connect to an HTTP server that is
down (sorry I don't have a reproducible test case yet...)
I know the issue (OOME) is coming from Jersey client, thanks to this heap
dump analysis in Memory Analyser Tool (MAT) :
Loading Image...
zoomed :
Loading Image...
As you can see, the listeners (in Jersey trunk they're now called
shutdownHooks) LinkedBlockingDeque is growing very large (2126 entries,
weighing 330KB each)
So what happened, why did that Deque grow so large ?
A colleague of mine actually took a thread dump just before its VM OOME'd ,
and jersey was busy calling ClientConfig.initRuntime() :
"qtp2059324016-2084" prio=5 tid=0x00007fbd8f83a000 nid=0xad8f runnable
[0x0000000167c32000]
java.lang.Thread.State: RUNNABLE
at java.lang.reflect.Method.getParameterTypes(Method.java:260)
at java.lang.Class.searchMethods(Class.java:2792)
at java.lang.Class.getDeclaredMethod(Class.java:2002)
at
org.jvnet.hk2.internal.Utilities$MemberDescriptor.internalGetMethod(Utilities.java:2909)
at
org.jvnet.hk2.internal.Utilities$MemberDescriptor.access$1800(Utilities.java:2698)
at
org.jvnet.hk2.internal.Utilities$MemberDescriptor$2.run(Utilities.java:2843)
at
org.jvnet.hk2.internal.Utilities$MemberDescriptor$2.run(Utilities.java:2839)
at java.security.AccessController.doPrivileged(Native Method)
at
org.jvnet.hk2.internal.Utilities$MemberDescriptor.getMethod(Utilities.java:2839)
at
org.jvnet.hk2.internal.Utilities$MemberDescriptor.access$900(Utilities.java:2698)
at
org.jvnet.hk2.internal.Utilities$MemberKey.getBackingMethod(Utilities.java:2477)
at
org.jvnet.hk2.internal.Utilities$MemberKey.access$400(Utilities.java:2463)
at org.jvnet.hk2.internal.Utilities.getAllMethods(Utilities.java:1345)
at
org.jvnet.hk2.internal.Utilities.findInitializerMethods(Utilities.java:1424)
at
org.jvnet.hk2.internal.DefaultClassAnalyzer.getInitializerMethods(DefaultClassAnalyzer.java:102)
at org.jvnet.hk2.internal.Utilities.getInitMethods(Utilities.java:243)
at org.jvnet.hk2.internal.ClazzCreator.initialize(ClazzCreator.java:163)
at org.jvnet.hk2.internal.ClazzCreator.initialize(ClazzCreator.java:200)
at
org.jvnet.hk2.internal.SystemDescriptor.internalReify(SystemDescriptor.java:649)
at org.jvnet.hk2.internal.SystemDescriptor.reify(SystemDescriptor.java:604)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.reifyDescriptor(ServiceLocatorImpl.java:405)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.narrow(ServiceLocatorImpl.java:2046)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.access$700(ServiceLocatorImpl.java:116)
at
org.jvnet.hk2.internal.ServiceLocatorImpl$8.compute(ServiceLocatorImpl.java:1207)
at
org.jvnet.hk2.internal.ServiceLocatorImpl$8.compute(ServiceLocatorImpl.java:1202)
at
org.glassfish.hk2.utilities.cache.LRUHybridCache$OriginThreadAwareFuture$1.call(LRUHybridCache.java:115)
at
org.glassfish.hk2.utilities.cache.LRUHybridCache$OriginThreadAwareFuture$1.call(LRUHybridCache.java:111)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
org.glassfish.hk2.utilities.cache.LRUHybridCache$OriginThreadAwareFuture.run(LRUHybridCache.java:173)
at
org.glassfish.hk2.utilities.cache.LRUHybridCache.compute(LRUHybridCache.java:292)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.internalGetAllServiceHandles(ServiceLocatorImpl.java:1280)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.getAllServiceHandles(ServiceLocatorImpl.java:1189)
at
org.jvnet.hk2.internal.ServiceLocatorImpl$7.run(ServiceLocatorImpl.java:1168)
at
org.jvnet.hk2.internal.ServiceLocatorImpl$7.run(ServiceLocatorImpl.java:1164)
at java.security.AccessController.doPrivileged(Native Method)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.protectedGetAllServiceHandles(ServiceLocatorImpl.java:1164)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.reupClassAnalyzers(ServiceLocatorImpl.java:1748)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.reup(ServiceLocatorImpl.java:1820)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.addConfiguration(ServiceLocatorImpl.java:1875)
at
org.jvnet.hk2.internal.DynamicConfigurationImpl.commit(DynamicConfigurationImpl.java:236)
at org.glassfish.jersey.internal.inject.Injections.bind(Injections.java:160)
at
org.glassfish.jersey.internal.inject.Injections._createLocator(Injections.java:148)
at
org.glassfish.jersey.internal.inject.Injections.createLocator(Injections.java:137)
at
org.glassfish.jersey.client.ClientConfig$State.initRuntime(ClientConfig.java:382)
at
org.glassfish.jersey.client.ClientConfig$State.access$000(ClientConfig.java:88)
at
org.glassfish.jersey.client.ClientConfig$State$3.get(ClientConfig.java:120)
at
org.glassfish.jersey.client.ClientConfig$State$3.get(ClientConfig.java:117)
at
org.glassfish.jersey.internal.util.collection.Values$LazyValueImpl.get(Values.java:322)
- locked <0x0000000154774c00> (a java.lang.Object)
at
org.glassfish.jersey.client.ClientConfig.getRuntime(ClientConfig.java:717)
at
org.glassfish.jersey.client.ClientRequest.getConfiguration(ClientRequest.java:281)
at
org.glassfish.jersey.client.JerseyInvocation.validateHttpMethodAndEntity(JerseyInvocation.java:124)
at
org.glassfish.jersey.client.JerseyInvocation.<init>(JerseyInvocation.java:97)
at
org.glassfish.jersey.client.JerseyInvocation.<init>(JerseyInvocation.java:90)
at
org.glassfish.jersey.client.JerseyInvocation$AsyncInvoker.method(JerseyInvocation.java:604)
at
org.glassfish.jersey.client.JerseyInvocation$AsyncInvoker.get(JerseyInvocation.java:465)
at
com.terracotta.management.services.impl.JerseyResourceServiceClientService.sendAsyncRequestsV2(JerseyResourceServiceClientService.java:341)
at
com.terracotta.management.services.impl.JerseyResourceServiceClientService.proxyGet(JerseyResourceServiceClientService.java:315)
at
com.terracotta.management.resource.services.impl.AggregateResourceServiceSupport.doGet(AggregateResourceServiceSupport.java:83)
That seems to indicate that what should be call only once,
ClientConfig$State.initRuntime(ClientConfig.java:382)
, is being called multiple times, and hence adds each time an additional
listener to the Deque.
So it seems like the LazyValue is misbehaving by calling several times
initRuntime() when it should call it just once :
https://github.com/jersey/jersey/blob/master/core-client/src/main/java/org/glassfish/jersey/client/ClientConfig.java#L118
Do you guys think like me ? Have you ever experienced such an issue with
JerseyClient ?
Thanks for reading,
Anthony
I am encountering in an intermittent OOME with Jersey Client 2.6 (yeah I
know the latest is 2.13, but 2.6 is the latest version working with JDK
1.6) - this issue appears when we try to connect to an HTTP server that is
down (sorry I don't have a reproducible test case yet...)
I know the issue (OOME) is coming from Jersey client, thanks to this heap
dump analysis in Memory Analyser Tool (MAT) :
Loading Image...
zoomed :
Loading Image...
As you can see, the listeners (in Jersey trunk they're now called
shutdownHooks) LinkedBlockingDeque is growing very large (2126 entries,
weighing 330KB each)
So what happened, why did that Deque grow so large ?
A colleague of mine actually took a thread dump just before its VM OOME'd ,
and jersey was busy calling ClientConfig.initRuntime() :
"qtp2059324016-2084" prio=5 tid=0x00007fbd8f83a000 nid=0xad8f runnable
[0x0000000167c32000]
java.lang.Thread.State: RUNNABLE
at java.lang.reflect.Method.getParameterTypes(Method.java:260)
at java.lang.Class.searchMethods(Class.java:2792)
at java.lang.Class.getDeclaredMethod(Class.java:2002)
at
org.jvnet.hk2.internal.Utilities$MemberDescriptor.internalGetMethod(Utilities.java:2909)
at
org.jvnet.hk2.internal.Utilities$MemberDescriptor.access$1800(Utilities.java:2698)
at
org.jvnet.hk2.internal.Utilities$MemberDescriptor$2.run(Utilities.java:2843)
at
org.jvnet.hk2.internal.Utilities$MemberDescriptor$2.run(Utilities.java:2839)
at java.security.AccessController.doPrivileged(Native Method)
at
org.jvnet.hk2.internal.Utilities$MemberDescriptor.getMethod(Utilities.java:2839)
at
org.jvnet.hk2.internal.Utilities$MemberDescriptor.access$900(Utilities.java:2698)
at
org.jvnet.hk2.internal.Utilities$MemberKey.getBackingMethod(Utilities.java:2477)
at
org.jvnet.hk2.internal.Utilities$MemberKey.access$400(Utilities.java:2463)
at org.jvnet.hk2.internal.Utilities.getAllMethods(Utilities.java:1345)
at
org.jvnet.hk2.internal.Utilities.findInitializerMethods(Utilities.java:1424)
at
org.jvnet.hk2.internal.DefaultClassAnalyzer.getInitializerMethods(DefaultClassAnalyzer.java:102)
at org.jvnet.hk2.internal.Utilities.getInitMethods(Utilities.java:243)
at org.jvnet.hk2.internal.ClazzCreator.initialize(ClazzCreator.java:163)
at org.jvnet.hk2.internal.ClazzCreator.initialize(ClazzCreator.java:200)
at
org.jvnet.hk2.internal.SystemDescriptor.internalReify(SystemDescriptor.java:649)
at org.jvnet.hk2.internal.SystemDescriptor.reify(SystemDescriptor.java:604)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.reifyDescriptor(ServiceLocatorImpl.java:405)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.narrow(ServiceLocatorImpl.java:2046)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.access$700(ServiceLocatorImpl.java:116)
at
org.jvnet.hk2.internal.ServiceLocatorImpl$8.compute(ServiceLocatorImpl.java:1207)
at
org.jvnet.hk2.internal.ServiceLocatorImpl$8.compute(ServiceLocatorImpl.java:1202)
at
org.glassfish.hk2.utilities.cache.LRUHybridCache$OriginThreadAwareFuture$1.call(LRUHybridCache.java:115)
at
org.glassfish.hk2.utilities.cache.LRUHybridCache$OriginThreadAwareFuture$1.call(LRUHybridCache.java:111)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
org.glassfish.hk2.utilities.cache.LRUHybridCache$OriginThreadAwareFuture.run(LRUHybridCache.java:173)
at
org.glassfish.hk2.utilities.cache.LRUHybridCache.compute(LRUHybridCache.java:292)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.internalGetAllServiceHandles(ServiceLocatorImpl.java:1280)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.getAllServiceHandles(ServiceLocatorImpl.java:1189)
at
org.jvnet.hk2.internal.ServiceLocatorImpl$7.run(ServiceLocatorImpl.java:1168)
at
org.jvnet.hk2.internal.ServiceLocatorImpl$7.run(ServiceLocatorImpl.java:1164)
at java.security.AccessController.doPrivileged(Native Method)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.protectedGetAllServiceHandles(ServiceLocatorImpl.java:1164)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.reupClassAnalyzers(ServiceLocatorImpl.java:1748)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.reup(ServiceLocatorImpl.java:1820)
at
org.jvnet.hk2.internal.ServiceLocatorImpl.addConfiguration(ServiceLocatorImpl.java:1875)
at
org.jvnet.hk2.internal.DynamicConfigurationImpl.commit(DynamicConfigurationImpl.java:236)
at org.glassfish.jersey.internal.inject.Injections.bind(Injections.java:160)
at
org.glassfish.jersey.internal.inject.Injections._createLocator(Injections.java:148)
at
org.glassfish.jersey.internal.inject.Injections.createLocator(Injections.java:137)
at
org.glassfish.jersey.client.ClientConfig$State.initRuntime(ClientConfig.java:382)
at
org.glassfish.jersey.client.ClientConfig$State.access$000(ClientConfig.java:88)
at
org.glassfish.jersey.client.ClientConfig$State$3.get(ClientConfig.java:120)
at
org.glassfish.jersey.client.ClientConfig$State$3.get(ClientConfig.java:117)
at
org.glassfish.jersey.internal.util.collection.Values$LazyValueImpl.get(Values.java:322)
- locked <0x0000000154774c00> (a java.lang.Object)
at
org.glassfish.jersey.client.ClientConfig.getRuntime(ClientConfig.java:717)
at
org.glassfish.jersey.client.ClientRequest.getConfiguration(ClientRequest.java:281)
at
org.glassfish.jersey.client.JerseyInvocation.validateHttpMethodAndEntity(JerseyInvocation.java:124)
at
org.glassfish.jersey.client.JerseyInvocation.<init>(JerseyInvocation.java:97)
at
org.glassfish.jersey.client.JerseyInvocation.<init>(JerseyInvocation.java:90)
at
org.glassfish.jersey.client.JerseyInvocation$AsyncInvoker.method(JerseyInvocation.java:604)
at
org.glassfish.jersey.client.JerseyInvocation$AsyncInvoker.get(JerseyInvocation.java:465)
at
com.terracotta.management.services.impl.JerseyResourceServiceClientService.sendAsyncRequestsV2(JerseyResourceServiceClientService.java:341)
at
com.terracotta.management.services.impl.JerseyResourceServiceClientService.proxyGet(JerseyResourceServiceClientService.java:315)
at
com.terracotta.management.resource.services.impl.AggregateResourceServiceSupport.doGet(AggregateResourceServiceSupport.java:83)
That seems to indicate that what should be call only once,
ClientConfig$State.initRuntime(ClientConfig.java:382)
, is being called multiple times, and hence adds each time an additional
listener to the Deque.
So it seems like the LazyValue is misbehaving by calling several times
initRuntime() when it should call it just once :
https://github.com/jersey/jersey/blob/master/core-client/src/main/java/org/glassfish/jersey/client/ClientConfig.java#L118
Do you guys think like me ? Have you ever experienced such an issue with
JerseyClient ?
Thanks for reading,
Anthony