Requests hang indefinitely waiting for a connection from the connection pool
Issue #8
new
When there is an exception happening while com.sun.jersey.api.client.WebResource#get is called, the pooled connection is dead and blocked.
I got a java.lang.NoClassDefFoundError: org/springframework/util/ReflectionUtils$FieldFilter exception during deserialization of Issue (which I will report separately).
This happened a couple of times and then the tests just hung indefinitely waiting for a connection from the connection pool to issue the next request.
When running the tests from the IDE, one directly sees the stacktrace for the first tests that were executed already. But when running the tests through atlas-integration-test there is no stacktrace shown and the tests just hang indefinitely which is very confusing and can require quite some time to find the cause.
The exception that happened here and made the connections dead and the pool permanently exhausted was
java.lang.NoClassDefFoundError: org/springframework/util/ReflectionUtils$FieldFilter
at java.lang.Class.getDeclaredMethods0(Native Method)
at java.lang.Class.privateGetDeclaredMethods(Class.java:2701)
at java.lang.Class.getDeclaredMethods(Class.java:1975)
at org.codehaus.jackson.map.introspect.AnnotatedClass._addMemberMethods(AnnotatedClass.java:620)
at org.codehaus.jackson.map.introspect.AnnotatedClass.resolveMemberMethods(AnnotatedClass.java:408)
at org.codehaus.jackson.map.introspect.BasicClassIntrospector.classWithCreators(BasicClassIntrospector.java:185)
at org.codehaus.jackson.map.introspect.BasicClassIntrospector.collectProperties(BasicClassIntrospector.java:157)
at org.codehaus.jackson.map.introspect.BasicClassIntrospector.forDeserialization(BasicClassIntrospector.java:108)
at org.codehaus.jackson.map.introspect.BasicClassIntrospector.forDeserialization(BasicClassIntrospector.java:16)
at org.codehaus.jackson.map.DeserializationConfig.introspect(DeserializationConfig.java:868)
at org.codehaus.jackson.map.deser.BeanDeserializerFactory.createBeanDeserializer(BeanDeserializerFactory.java:587)
at org.codehaus.jackson.map.deser.StdDeserializerProvider._createDeserializer(StdDeserializerProvider.java:401)
at org.codehaus.jackson.map.deser.StdDeserializerProvider._createAndCache2(StdDeserializerProvider.java:310)
at org.codehaus.jackson.map.deser.StdDeserializerProvider._createAndCacheValueDeserializer(StdDeserializerProvider.java:290)
at org.codehaus.jackson.map.deser.StdDeserializerProvider.findValueDeserializer(StdDeserializerProvider.java:159)
at org.codehaus.jackson.map.deser.std.StdDeserializer.findDeserializer(StdDeserializer.java:620)
at org.codehaus.jackson.map.deser.BeanDeserializer.resolve(BeanDeserializer.java:379)
at org.codehaus.jackson.map.deser.StdDeserializerProvider._resolveDeserializer(StdDeserializerProvider.java:407)
at org.codehaus.jackson.map.deser.StdDeserializerProvider._createAndCache2(StdDeserializerProvider.java:352)
at org.codehaus.jackson.map.deser.StdDeserializerProvider._createAndCacheValueDeserializer(StdDeserializerProvider.java:290)
at org.codehaus.jackson.map.deser.StdDeserializerProvider.findValueDeserializer(StdDeserializerProvider.java:159)
at org.codehaus.jackson.map.deser.StdDeserializerProvider.findTypedValueDeserializer(StdDeserializerProvider.java:180)
at org.codehaus.jackson.map.ObjectMapper._findRootDeserializer(ObjectMapper.java:2829)
at org.codehaus.jackson.map.ObjectMapper._readValue(ObjectMapper.java:2699)
at org.codehaus.jackson.map.ObjectMapper.readValue(ObjectMapper.java:1315)
at org.codehaus.jackson.jaxrs.JacksonJsonProvider.readFrom(JacksonJsonProvider.java:419)
at com.sun.jersey.api.client.ClientResponse.getEntity(ClientResponse.java:634)
at com.sun.jersey.api.client.ClientResponse.getEntity(ClientResponse.java:586)
at com.sun.jersey.api.client.WebResource.handle(WebResource.java:686)
at com.sun.jersey.api.client.WebResource.get(WebResource.java:193)
at com.atlassian.jira.testkit.client.restclient.IssueClient.get(IssueClient.java:60)
at com.atlassian.jira.testkit.client.IssuesControl.getIssue(IssuesControl.java:283)
at it.de.empic.tools.jira.WorklogHandlerEventListenerTestkitTest.verifyTimeTracking(WorklogHandlerEventListenerTestkitTest.java:488)
at it.de.empic.tools.jira.WorklogHandlerEventListenerTestkitTest.testAdjustingRemainingEstimateOnSubTask(WorklogHandlerEventListenerTestkitTest.java:264)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:61)
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:68)
at com.intellij.rt.junit.IdeaTestRunner$Repeater.startRunnerWithArgs(IdeaTestRunner.java:33)
at com.intellij.rt.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:230)
at com.intellij.rt.junit.JUnitStarter.main(JUnitStarter.java:58)
Caused by: java.lang.ClassNotFoundException: org.springframework.util.ReflectionUtils$FieldFilter
at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:335)
at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
... 62 more
And here the thread dump of the thread that waited for the next connection from the pool that never arrives:
"main@1" prio=5 tid=0x1 nid=NA waiting
java.lang.Thread.State: WAITING
at java.lang.Object.wait(Object.java:-1)
at org.apache.commons.httpclient.MultiThreadedHttpConnectionManager.doGetConnection(MultiThreadedHttpConnectionManager.java:518)
at org.apache.commons.httpclient.MultiThreadedHttpConnectionManager.getConnectionWithTimeout(MultiThreadedHttpConnectionManager.java:416)
at org.apache.commons.httpclient.HttpMethodDirector.executeMethod(HttpMethodDirector.java:153)
at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:397)
at com.sun.jersey.client.apache.DefaultApacheHttpMethodExecutor.executeMethod(DefaultApacheHttpMethodExecutor.java:210)
at com.sun.jersey.client.apache.ApacheHttpClientHandler.handle(ApacheHttpClientHandler.java:175)
at com.sun.jersey.api.client.Client.handle(Client.java:652)
at com.atlassian.jira.testkit.client.BackdoorControl$BackdoorLoggingFilter.handle(BackdoorControl.java:158)
at com.atlassian.jira.testkit.client.BackdoorControl$JsonMediaTypeFilter.handle(BackdoorControl.java:184)
at com.sun.jersey.api.client.WebResource.handle(WebResource.java:694)
at com.sun.jersey.api.client.WebResource.get(WebResource.java:198)
at com.atlassian.jira.testkit.client.IssueTypeControl.getIssueTypesForProject(IssueTypeControl.java:61)
at com.atlassian.jira.testkit.client.IssuesControl$$Lambda$1.367967231.apply(Unknown Source:-1)
at java.util.Optional.map(Optional.java:215)
at com.atlassian.jira.testkit.client.IssuesControl.getBestGuessIssueType(IssuesControl.java:153)
at com.atlassian.jira.testkit.client.IssuesControl.createIssue(IssuesControl.java:99)
at it.de.empic.tools.jira.WorklogHandlerEventListenerTestkitTest.setUp(WorklogHandlerEventListenerTestkitTest.java:91)
at sun.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-1)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
at org.junit.internal.runners.statements.RunBefores.invokeMethod(RunBefores.java:33)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:61)
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365)
at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273)
at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238)
at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159)
at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
There should probably at least be some timeout set like http.connection-manager.timeout that would cause the test to fail in a timely manner instead of hanging indefinitely.
It would probably be even better to somehow make sure that an exception cannot exhaust the pool but connection being released after an exception during deserialization.