Thanks Kirk - this is GEODE-5676. I'm glad the callstacks are finally working again, that should help us track this down! I'll update that ticket with anything I can figure out from this failure.
-Dan On Wed, Jan 23, 2019 at 10:05 AM Kirk Lund <kl...@apache.org> wrote: > Looks like there's a Test worker thread that keeps running and changing. > Maybe the dunit test is pushing the dunit job over its time limit: > > "Test worker" #27 prio=5 os_prio=0 cpu=1332.79ms elapsed=4871.91s > tid=0x00007f67c4a78800 nid=0x1c runnable [0x00007f675fbf3000] > java.lang.Thread.State: RUNNABLE > at java.net.SocketInputStream.socketRead0(java.base@11.0.1/Native > Method) > at java.net.SocketInputStream.socketRead(java.base@11.0.1 > /SocketInputStream.java:115) > at java.net.SocketInputStream.read(java.base@11.0.1 > /SocketInputStream.java:168) > at java.net.SocketInputStream.read(java.base@11.0.1 > /SocketInputStream.java:140) > at java.io.BufferedInputStream.fill(java.base@11.0.1 > /BufferedInputStream.java:252) > at java.io.BufferedInputStream.read(java.base@11.0.1 > /BufferedInputStream.java:271) > - locked <0x00000000d131b270> (a java.io.BufferedInputStream) > at java.io.DataInputStream.readByte(java.base@11.0.1 > /DataInputStream.java:270) > at sun.rmi.transport.StreamRemoteCall.executeCall(java.rmi@11.0.1 > /StreamRemoteCall.java:222) > at sun.rmi.server.UnicastRef.invoke(java.rmi@11.0.1 > /UnicastRef.java:161) > at > > java.rmi.server.RemoteObjectInvocationHandler.invokeRemoteMethod(java.rmi@11.0.1 > /RemoteObjectInvocationHandler.java:209) > at > java.rmi.server.RemoteObjectInvocationHandler.invoke(java.rmi@11.0.1 > /RemoteObjectInvocationHandler.java:161) > at com.sun.proxy.$Proxy32.executeMethodOnObject(Unknown Source) > at > org.apache.geode.test.dunit.VM.executeMethodOnObject(VM.java:530) > at org.apache.geode.test.dunit.VM.invoke(VM.java:390) > at > > org.apache.geode.test.dunit.rules.ClusterStartupRule.startServerVM(ClusterStartupRule.java:239) > at > > org.apache.geode.test.dunit.rules.ClusterStartupRule.startServerVM(ClusterStartupRule.java:232) > at > > org.apache.geode.test.dunit.rules.ClusterStartupRule.startServerVM(ClusterStartupRule.java:218) > at > > org.apache.geode.management.internal.configuration.ClusterConfigLocatorRestartDUnitTest.serverRestartsAfterOneLocatorDies(ClusterConfigLocatorRestartDUnitTest.java:98) > at > jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.1 > /Native > Method) > at > jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.1 > /NativeMethodAccessorImpl.java:62) > at > jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.1 > /DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(java.base@11.0.1 > /Method.java:566) > at > > org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) > at > > org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) > at > > org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) > at > > org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) > at > > org.apache.geode.test.junit.rules.DescribedExternalResource$1.evaluate(DescribedExternalResource.java:40) > at > org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:48) > at org.junit.rules.RunRules.evaluate(RunRules.java:20) > at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) > at > > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) > at > > org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) > at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) > at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) > at > org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) > at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) > at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) > at org.junit.runners.ParentRunner.run(ParentRunner.java:363) > at > > org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.runTestClass(JUnitTestClassExecutor.java:110) > at > > org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:58) > at > > org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:38) > at > > org.gradle.api.internal.tasks.testing.junit.AbstractJUnitTestClassProcessor.processTestClass(AbstractJUnitTestClassProcessor.java:66) > at > > org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:51) > at > jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.1 > /Native > Method) > at > jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.1 > /NativeMethodAccessorImpl.java:62) > at > jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.1 > /DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(java.base@11.0.1 > /Method.java:566) > at > > org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35) > at > > org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24) > at > > org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32) > at > > org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93) > at com.sun.proxy.$Proxy2.processTestClass(Unknown Source) > at > > org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:118) > at > jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.1 > /Native > Method) > at > jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.1 > /NativeMethodAccessorImpl.java:62) > at > jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.1 > /DelegatingMethodAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(java.base@11.0.1 > /Method.java:566) > at > > org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35) > at > > org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24) > at > > org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:175) > at > > org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:157) > at > > org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:404) > at > > org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:63) > at > > org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:46) > at > java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.1 > /ThreadPoolExecutor.java:1128) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.1 > /ThreadPoolExecutor.java:628) > at > > org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:55) > at java.lang.Thread.run(java.base@11.0.1/Thread.java:834) > > Locked ownable synchronizers: > - <0x00000000d0884428> (a > java.util.concurrent.ThreadPoolExecutor$Worker) > > On Wed, Jan 23, 2019 at 10:02 AM Kirk Lund <kl...@apache.org> wrote: > > > I hit a dunit hang in one of my precheckin runs. > > > > The only test mentioned in callstacks/dunit-hangs.txt is > > ClusterConfigLocatorRestartDUnitTest. > > > > I see some Pooled Message Processor threads that might be hung waiting > for > > the same > > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject on > > OverflowQueueWithDMStat. > > > > ClusterConfigurationLoader and FunctionStreamingResultCollector might be > > involved. > > > > Here's the link if someone working on cluster config wants to download > the > > tgz and look through the callstacks: > > > https://urldefense.proofpoint.com/v2/url?u=https-3A__concourse.apachegeode-2Dci.info_builds_31696&d=DwIBaQ&c=lnl9vOaLMzsy2niBC8-h_K-7QJuNJEsFrzdndhuJ3Sw&r=WLfm1gWdzznUCrPAWyBJYQjifxLutUaeKbwnfk4TP0w&m=UIYwtODvA8Ml35njXgASx8bA_A-KLM_ARzMlP5bEqYs&s=JIjWaAHI0sM_9xzriGwNsHd7_a4oSuPYXmKjsHDpHlc&e= > > > > "RMI TCP Connection(1)-172.17.0.14" #34 daemon prio=5 os_prio=0 > > cpu=1485.20ms elapsed=4864.19s tid=0x00007f6950001800 nid=0x213 waiting > on > > condition [0x00007f696b5f3000] > > java.lang.Thread.State: TIMED_WAITING (parking) > > at jdk.internal.misc.Unsafe.park(java.base@11.0.1/Native Method) > > - parking to wait for <0x00000000ed7bf538> (a > > java.util.concurrent.CountDownLatch$Sync) > > at > > java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.1 > > /LockSupport.java:234) > > at > > > java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(java.base@11.0.1 > > /AbstractQueuedSynchronizer.java:1079) > > at > > > java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(java.base@11.0.1 > > /AbstractQueuedSynchronizer.java:1369) > > at java.util.concurrent.CountDownLatch.await(java.base@11.0.1 > > /CountDownLatch.java:278) > > at > > > org.apache.geode.internal.util.concurrent.StoppableCountDownLatch.await(StoppableCountDownLatch.java:61) > > at > > > org.apache.geode.distributed.internal.ReplyProcessor21.basicWait(ReplyProcessor21.java:714) > > at > > > org.apache.geode.distributed.internal.ReplyProcessor21.waitForRepliesUninterruptibly(ReplyProcessor21.java:785) > > at > > > org.apache.geode.distributed.internal.ReplyProcessor21.waitForRepliesUninterruptibly(ReplyProcessor21.java:762) > > at > > > org.apache.geode.internal.cache.execute.FunctionStreamingResultCollector.getResult(FunctionStreamingResultCollector.java:142) > > at > > > org.apache.geode.internal.cache.ClusterConfigurationLoader.requestConfigurationFromOneLocator(ClusterConfigurationLoader.java:313) > > at > > > org.apache.geode.internal.cache.ClusterConfigurationLoader.requestConfigurationFromLocators(ClusterConfigurationLoader.java:282) > > at > > > org.apache.geode.internal.cache.GemFireCacheImpl.requestSharedConfiguration(GemFireCacheImpl.java:1074) > > at > > > org.apache.geode.internal.cache.GemFireCacheImpl.<init>(GemFireCacheImpl.java:859) > > - locked <0x00000000ed7bf7f8> (a java.lang.Class for > > org.apache.geode.internal.cache.GemFireCacheImpl) > > at > > > org.apache.geode.internal.cache.GemFireCacheImpl.basicCreate(GemFireCacheImpl.java:796) > > - locked <0x00000000ed7bf7f8> (a java.lang.Class for > > org.apache.geode.internal.cache.GemFireCacheImpl) > > at > > > org.apache.geode.internal.cache.GemFireCacheImpl.create(GemFireCacheImpl.java:785) > > at > > org.apache.geode.cache.CacheFactory.create(CacheFactory.java:176) > > - locked <0x00000000ed6005b0> (a java.lang.Class for > > org.apache.geode.cache.CacheFactory) > > at > > org.apache.geode.cache.CacheFactory.create(CacheFactory.java:223) > > - locked <0x00000000ed6005b0> (a java.lang.Class for > > org.apache.geode.cache.CacheFactory) > > at > > > org.apache.geode.test.junit.rules.ServerStarterRule.startServer(ServerStarterRule.java:174) > > at > > > org.apache.geode.test.junit.rules.ServerStarterRule.before(ServerStarterRule.java:80) > > at > > > org.apache.geode.test.dunit.rules.ClusterStartupRule.lambda$startServerVM$729766c4$1(ClusterStartupRule.java:248) > > at > > > org.apache.geode.test.dunit.rules.ClusterStartupRule$$Lambda$131/0x00000008401c0840.call(Unknown > > Source) > > at > > jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.1 > /Native > > Method) > > at > > jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.1 > > /NativeMethodAccessorImpl.java:62) > > at > > jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.1 > > /DelegatingMethodAccessorImpl.java:43) > > at java.lang.reflect.Method.invoke(java.base@11.0.1 > > /Method.java:566) > > at > > > org.apache.geode.test.dunit.internal.MethodInvoker.executeObject(MethodInvoker.java:123) > > at > > > org.apache.geode.test.dunit.internal.RemoteDUnitVM.executeMethodOnObject(RemoteDUnitVM.java:69) > > at > > jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.1 > /Native > > Method) > > at > > jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.1 > > /NativeMethodAccessorImpl.java:62) > > at > > jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.1 > > /DelegatingMethodAccessorImpl.java:43) > > at java.lang.reflect.Method.invoke(java.base@11.0.1 > > /Method.java:566) > > at sun.rmi.server.UnicastServerRef.dispatch(java.rmi@11.0.1 > > /UnicastServerRef.java:359) > > at sun.rmi.transport.Transport$1.run(java.rmi@11.0.1 > > /Transport.java:200) > > at sun.rmi.transport.Transport$1.run(java.rmi@11.0.1 > > /Transport.java:197) > > at java.security.AccessController.doPrivileged(java.base@11.0.1 > /Native > > Method) > > at sun.rmi.transport.Transport.serviceCall(java.rmi@11.0.1 > > /Transport.java:196) > > at > > sun.rmi.transport.tcp.TCPTransport.handleMessages(java.rmi@11.0.1 > > /TCPTransport.java:562) > > at > > sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(java.rmi@11.0.1 > > /TCPTransport.java:796) > > at > > > sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(java.rmi@11.0.1 > > /TCPTransport.java:677) > > at > > > sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$$Lambda$126/0x000000084019f440.run(java.rmi@11.0.1 > /Unknown > > Source) > > at java.security.AccessController.doPrivileged(java.base@11.0.1 > /Native > > Method) > > at > > sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(java.rmi@11.0.1 > > /TCPTransport.java:676) > > at > > java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.1 > > /ThreadPoolExecutor.java:1128) > > at > > java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.1 > > /ThreadPoolExecutor.java:628) > > at java.lang.Thread.run(java.base@11.0.1/Thread.java:834) > > > > Locked ownable synchronizers: > > - <0x00000000ed5c8f60> (a > > java.util.concurrent.ThreadPoolExecutor$Worker) > > > > >
