Description
Test run timed out in CI: https://concourse.apachegeode-ci.info/teams/main/pipelines/apache-develop-main/jobs/UpgradeTestOpenJDK11/builds/128#A
Test is stuck trying to roll the server:
"Test worker" #27 prio=5 os_prio=0 cpu=4769.09ms elapsed=2897.08s tid=0x00007f9ad4ac6800 nid=0x19 runnable [0x00007f9aa1d42000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(java.base@11.0.7/Native Method) at java.net.SocketInputStream.socketRead(java.base@11.0.7/SocketInputStream.java:115) at java.net.SocketInputStream.read(java.base@11.0.7/SocketInputStream.java:168) at java.net.SocketInputStream.read(java.base@11.0.7/SocketInputStream.java:140) at java.io.BufferedInputStream.fill(java.base@11.0.7/BufferedInputStream.java:252) at java.io.BufferedInputStream.read(java.base@11.0.7/BufferedInputStream.java:271) - locked <0x00000000fa010c38> (a java.io.BufferedInputStream) at java.io.DataInputStream.readByte(java.base@11.0.7/DataInputStream.java:270) at sun.rmi.transport.StreamRemoteCall.executeCall(java.rmi@11.0.7/StreamRemoteCall.java:240) at sun.rmi.server.UnicastRef.invoke(java.rmi@11.0.7/UnicastRef.java:164) at java.rmi.server.RemoteObjectInvocationHandler.invokeRemoteMethod(java.rmi@11.0.7/RemoteObjectInvocationHandler.java:217) at java.rmi.server.RemoteObjectInvocationHandler.invoke(java.rmi@11.0.7/RemoteObjectInvocationHandler.java:162) at com.sun.proxy.$Proxy56.executeMethodOnObject(Unknown Source) at org.apache.geode.test.dunit.VM.executeMethodOnObject(VM.java:607) at org.apache.geode.test.dunit.VM.invoke(VM.java:437) at org.apache.geode.cache.lucene.LuceneSearchWithRollingUpgradeTestBase.rollServerToCurrent(LuceneSearchWithRollingUpgradeTestBase.java:344) at org.apache.geode.cache.lucene.LuceneSearchWithRollingUpgradeTestBase.rollServerToCurrentCreateLuceneIndexAndCreateRegion(LuceneSearchWithRollingUpgradeTestBase.java:356) at org.apache.geode.cache.lucene.RollingUpgradeQueryReturnsCorrectResultAfterTwoLocatorsWithTwoServersAreRolled.luceneQueryReturnsCorrectResultAfterTwoLocatorsWithTwoServersAreRolled(RollingUpgradeQueryReturnsCorrectResultAfterTwoLocatorsWithTwoServersAreRolled.java:86) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.7/Native Method) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.7/NativeMethodAccessorImpl.java:62) at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.7/DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(java.base@11.0.7/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.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27) at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55) 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.junit.runners.Suite.runChild(Suite.java:128) at org.junit.runners.Suite.runChild(Suite.java:27) 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.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) 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:62) at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:51) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.7/Native Method) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.7/NativeMethodAccessorImpl.java:62) at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.7/DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(java.base@11.0.7/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.7/Native Method) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.7/NativeMethodAccessorImpl.java:62) at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.7/DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(java.base@11.0.7/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.7/ThreadPoolExecutor.java:1128) at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.7/ThreadPoolExecutor.java:628) at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:55) at java.lang.Thread.run(java.base@11.0.7/Thread.java:834)
The rolled server cache close is hung waiting for replies:
"RMI TCP Connection(2)-172.17.0.16" #35 daemon prio=5 os_prio=0 cpu=4555.53ms elapsed=2810.44s tid=0x00007f1218241800 nid=0x276 waiting on condition [0x00007f1284da3000] java.lang.Thread.State: TIMED_WAITING (parking) at jdk.internal.misc.Unsafe.park(java.base@11.0.7/Native Method) - parking to wait for <0x00000000ed54bc08> (a java.util.concurrent.CountDownLatch$Sync) at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.7/LockSupport.java:234) at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(java.base@11.0.7/AbstractQueuedSynchronizer.java:1079) at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(java.base@11.0.7/AbstractQueuedSynchronizer.java:1369) at java.util.concurrent.CountDownLatch.await(java.base@11.0.7/CountDownLatch.java:278) at org.apache.geode.internal.util.concurrent.StoppableCountDownLatch.await(StoppableCountDownLatch.java:64) at org.apache.geode.distributed.internal.ReplyProcessor21.basicWait(ReplyProcessor21.java:718) at org.apache.geode.distributed.internal.ReplyProcessor21.waitForReplies(ReplyProcessor21.java:644) at org.apache.geode.distributed.internal.ReplyProcessor21.waitForReplies(ReplyProcessor21.java:624) at org.apache.geode.distributed.internal.ReplyProcessor21.waitForReplies(ReplyProcessor21.java:519) at org.apache.geode.internal.cache.GemFireCacheImpl.close(GemFireCacheImpl.java:2314) - locked <0x00000000ed54bd78> (a java.lang.Class for org.apache.geode.internal.cache.GemFireCacheImpl) at org.apache.geode.internal.cache.GemFireCacheImpl.close(GemFireCacheImpl.java:1937) at org.apache.geode.internal.cache.GemFireCacheImpl.close(GemFireCacheImpl.java:1927) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.7/Native Method) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.7/NativeMethodAccessorImpl.java:62) at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.7/DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(java.base@11.0.7/Method.java:566) at org.apache.geode.cache.lucene.LuceneSearchWithRollingUpgradeTestBase.closeCache(LuceneSearchWithRollingUpgradeTestBase.java:755) at org.apache.geode.cache.lucene.LuceneSearchWithRollingUpgradeTestBase$12.run2(LuceneSearchWithRollingUpgradeTestBase.java:568) at org.apache.geode.cache30.CacheSerializableRunnable.run(CacheSerializableRunnable.java:55) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.7/Native Method) at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.7/NativeMethodAccessorImpl.java:62) at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.7/DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(java.base@11.0.7/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:78) at jdk.internal.reflect.GeneratedMethodAccessor7.invoke(Unknown Source) at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.7/DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(java.base@11.0.7/Method.java:566) at sun.rmi.server.UnicastServerRef.dispatch(java.rmi@11.0.7/UnicastServerRef.java:359) at sun.rmi.transport.Transport$1.run(java.rmi@11.0.7/Transport.java:200) at sun.rmi.transport.Transport$1.run(java.rmi@11.0.7/Transport.java:197) at java.security.AccessController.doPrivileged(java.base@11.0.7/Native Method) at sun.rmi.transport.Transport.serviceCall(java.rmi@11.0.7/Transport.java:196) at sun.rmi.transport.tcp.TCPTransport.handleMessages(java.rmi@11.0.7/TCPTransport.java:562) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(java.rmi@11.0.7/TCPTransport.java:796) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(java.rmi@11.0.7/TCPTransport.java:677) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$$Lambda$133/0x0000000840199c40.run(java.rmi@11.0.7/Unknown Source) at java.security.AccessController.doPrivileged(java.base@11.0.7/Native Method) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(java.rmi@11.0.7/TCPTransport.java:676) at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.7/ThreadPoolExecutor.java:1128) at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.7/ThreadPoolExecutor.java:628) at java.lang.Thread.run(java.base@11.0.7/Thread.java:834)
Artifacts are in:
http://files.apachegeode-ci.info/builds/apache-develop-main/1.14.0-SNAPSHOT.0009/test-results/upgradeTest/1588808320/