Discussion:
OOME with Jersey Client 2.6
Anthony Dahanne
2014-10-16 23:20:21 UTC
Permalink
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
Anthony Dahanne
2014-10-19 02:28:28 UTC
Permalink
OK, I finally found out what was wrong.
And it was in my code, not in Jersey client code.
After each un successful code (for example the server is down), I used to
set a property to the client :

client.property(*VALID_CLIENT_MARKER_KEY*, *null*);

but doing this, I inadvertently changed the state object, and when the
state of the ClientConfig is changed, initRuntime() needs to be called, and
a new listener gets attached to the client. (this lead to my OOME)

So, be careful when setting properties to the client, it may have a bigger
impact than what you initially thought...

ANthony
Post by Anthony Dahanne
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
http://i.imgur.com/RFyhVOR.png?1
http://i.imgur.com/xj6xauM.png?1
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
"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
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
Loading...