Details
-
Bug
-
Status: Closed
-
Major
-
Resolution: Fixed
-
None
Description
At least three distributed unit test runs have recently hung in this test.
https://concourse.apachegeode-ci.info/teams/main/pipelines/apache-develop-main/jobs/DistributedTestOpenJDK11/builds/1158
https://concourse.apachegeode-ci.info/teams/main/pipelines/apache-develop-main/jobs/DistributedTestOpenJDK11/builds/1164
and
https://concourse.apachegeode-ci.info/teams/main/pipelines/apache-develop-main/jobs/DistributedTestOpenJDK11/builds/1173
Here are some threads that might be of interest in the latest hang:
java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(java.base@11.0.4/Native Method) at java.net.SocketInputStream.socketRead(java.base@11.0.4/SocketInputStream.java:115) at java.net.SocketInputStream.read(java.base@11.0.4/SocketInputStream.java:168) at java.net.SocketInputStream.read(java.base@11.0.4/SocketInputStream.java:140) at java.io.BufferedInputStream.fill(java.base@11.0.4/BufferedInputStream.java:252) at java.io.BufferedInputStream.read(java.base@11.0.4/BufferedInputStream.java:271) - locked <0x00000000e3c4e9b8> (a java.io.BufferedInputStream) at java.io.DataInputStream.readByte(java.base@11.0.4/DataInputStream.java:270) at sun.rmi.transport.StreamRemoteCall.executeCall(java.rmi@11.0.4/StreamRemoteCall.java:222) at sun.rmi.server.UnicastRef.invoke(java.rmi@11.0.4/UnicastRef.java:161) at java.rmi.server.RemoteObjectInvocationHandler.invokeRemoteMethod(java.rmi@11.0.4/RemoteObjectInvocationHandler.java:209) at java.rmi.server.RemoteObjectInvocationHandler.invoke(java.rmi@11.0.4/RemoteObjectInvocationHandler.java:161) at com.sun.proxy.$Proxy55.executeMethodOnObject(Unknown Source) at org.apache.geode.test.dunit.VM.executeMethodOnObject(VM.java:576) at org.apache.geode.test.dunit.VM.invoke(VM.java:431) at org.apache.geode.internal.cache.backup.IncrementalBackupDistributedTest.testIncompleteInBaseline(IncrementalBackupDistributedTest.java:327) "RMI TCP Connection(4)-172.17.0.9" #40 daemon prio=5 os_prio=0 cpu=1139.47ms elapsed=4212.37s tid=0x00007f2f94004800 nid=0x1f7 waiting on condition [0x00007f301d826000] java.lang.Thread.State: TIMED_WAITING (parking) at jdk.internal.misc.Unsafe.park(java.base@11.0.4/Native Method) - parking to wait for <0x00000000ecf14698> (a java.util.concurrent.CountDownLatch$Sync) at java.util.concurrent.locks.LockSupport.parkNanos(java.base@11.0.4/LockSupport.java:234) at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(java.base@11.0.4/AbstractQueuedSynchronizer.java:1079) at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(java.base@11.0.4/AbstractQueuedSynchronizer.java:1369) at java.util.concurrent.CountDownLatch.await(java.base@11.0.4/CountDownLatch.java:278) at org.apache.geode.internal.util.concurrent.StoppableCountDownLatch.awaitWithCheck(StoppableCountDownLatch.java:120) at org.apache.geode.internal.util.concurrent.StoppableCountDownLatch.await(StoppableCountDownLatch.java:93) at org.apache.geode.distributed.internal.ReplyProcessor21.basicWait(ReplyProcessor21.java:692) at org.apache.geode.distributed.internal.ReplyProcessor21.waitForReplies(ReplyProcessor21.java:639) at org.apache.geode.distributed.internal.ReplyProcessor21.waitForReplies(ReplyProcessor21.java:620) at org.apache.geode.distributed.internal.ReplyProcessor21.waitForReplies(ReplyProcessor21.java:534) at org.apache.geode.internal.cache.backup.BackupStep.send(BackupStep.java:66) at org.apache.geode.internal.cache.backup.BackupOperation.performBackupSteps(BackupOperation.java:121) at org.apache.geode.internal.cache.backup.BackupOperation.performBackupUnderLock(BackupOperation.java:92) at org.apache.geode.internal.cache.backup.BackupOperation.performBackup(BackupOperation.java:77) at org.apache.geode.internal.cache.backup.BackupOperation.backupAllMembers(BackupOperation.java:71) at org.apache.geode.internal.cache.backup.IncrementalBackupDistributedTest.performBackup(IncrementalBackupDistributedTest.java:565) at org.apache.geode.internal.cache.backup.IncrementalBackupDistributedTest.performBackup(IncrementalBackupDistributedTest.java:560) at org.apache.geode.internal.cache.backup.IncrementalBackupDistributedTest.lambda$testIncompleteInBaseline$515fd116$1(IncrementalBackupDistributedTest.java:327) at org.apache.geode.internal.cache.backup.IncrementalBackupDistributedTest$$Lambda$418/0x0000000840c20c40.call(Unknown Source) "BackupServiceThread1" #276 daemon prio=10 os_prio=0 cpu=0.33ms elapsed=4152.24s tid=0x00007f377021b000 nid=0x50c waiting on condition [0x00007f38391d6000] java.lang.Thread.State: WAITING (parking) at jdk.internal.misc.Unsafe.park(java.base@11.0.4/Native Method) - parking to wait for <0x00000000e3ce6438> (a java.util.concurrent.CountDownLatch$Sync) at java.util.concurrent.locks.LockSupport.park(java.base@11.0.4/LockSupport.java:194) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.4/AbstractQueuedSynchronizer.java:885) at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(java.base@11.0.4/AbstractQueuedSynchronizer.java:1039) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(java.base@11.0.4/AbstractQueuedSynchronizer.java:1345) at java.util.concurrent.CountDownLatch.await(java.base@11.0.4/CountDownLatch.java:232) at org.apache.geode.internal.cache.backup.BackupTask.backup(BackupTask.java:72) at org.apache.geode.internal.cache.backup.BackupService.lambda$prepareBackup$0(BackupService.java:62) at org.apache.geode.internal.cache.backup.BackupService$$Lambda$406/0x0000000840c48040.call(Unknown Source) at java.util.concurrent.FutureTask.run(java.base@11.0.4/FutureTask.java:264) at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.4/ThreadPoolExecutor.java:1128) at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.4/ThreadPoolExecutor.java:628) at java.lang.Thread.run(java.base@11.0.4/Thread.java:834) "BackupServiceThread1" #266 daemon prio=5 os_prio=0 cpu=0.43ms elapsed=4156.14s tid=0x00007f2fac631800 nid=0x50e waiting on condition [0x00007f2f455c7000] java.lang.Thread.State: WAITING (parking) at jdk.internal.misc.Unsafe.park(java.base@11.0.4/Native Method) - parking to wait for <0x00000000ecf518b8> (a java.util.concurrent.CountDownLatch$Sync) at java.util.concurrent.locks.LockSupport.park(java.base@11.0.4/LockSupport.java:194) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.4/AbstractQueuedSynchronizer.java:885) at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(java.base@11.0.4/AbstractQueuedSynchronizer.java:1039) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(java.base@11.0.4/AbstractQueuedSynchronizer.java:1345) at java.util.concurrent.CountDownLatch.await(java.base@11.0.4/CountDownLatch.java:232) at org.apache.geode.internal.cache.backup.BackupTask.backup(BackupTask.java:72) at org.apache.geode.internal.cache.backup.BackupService.lambda$prepareBackup$0(BackupService.java:62) at org.apache.geode.internal.cache.backup.BackupService$$Lambda$390/0x0000000840be0c40.call(Unknown Source) at java.util.concurrent.FutureTask.run(java.base@11.0.4/FutureTask.java:264) at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.4/ThreadPoolExecutor.java:1128) at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.4/ThreadPoolExecutor.java:628) at java.lang.Thread.run(java.base@11.0.4/Thread.java:834) Locked ownable synchronizers: - <0x00000000ece9fc10> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) - <0x00000000eceb37b0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync) - <0x00000000ecf51990> (a java.util.concurrent.ThreadPoolExecutor$Worker) "Pooled Message Processor 3" #86 daemon prio=10 os_prio=0 cpu=41.38ms elapsed=4176.70s tid=0x00007fcfb403f800 nid=0x307 waiting on condition [0x00007fd0348d4000] java.lang.Thread.State: WAITING (parking) at jdk.internal.misc.Unsafe.park(java.base@11.0.4/Native Method) - parking to wait for <0x00000000ecf68520> (a java.util.concurrent.CountDownLatch$Sync) at java.util.concurrent.locks.LockSupport.park(java.base@11.0.4/LockSupport.java:194) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.4/AbstractQueuedSynchronizer.java:885) at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(java.base@11.0.4/AbstractQueuedSynchronizer.java:1039) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(java.base@11.0.4/AbstractQueuedSynchronizer.java:1345) at java.util.concurrent.CountDownLatch.await(java.base@11.0.4/CountDownLatch.java:232) at org.apache.geode.internal.cache.backup.BackupTask.getPreparedDiskStores(BackupTask.java:60) at org.apache.geode.internal.cache.backup.BackupService.prepareBackup(BackupService.java:63) at org.apache.geode.internal.cache.backup.PrepareBackup.run(PrepareBackup.java:41) at org.apache.geode.internal.cache.backup.PrepareBackupRequest.createResponse(PrepareBackupRequest.java:66) at org.apache.geode.internal.admin.remote.CliLegacyMessage.process(CliLegacyMessage.java:37) at org.apache.geode.distributed.internal.DistributionMessage.scheduleAction(DistributionMessage.java:372) at org.apache.geode.distributed.internal.DistributionMessage$1.run(DistributionMessage.java:436) at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.4/ThreadPoolExecutor.java:1128) at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.4/ThreadPoolExecutor.java:628) at org.apache.geode.distributed.internal.ClusterOperationExecutors.runUntilShutdown(ClusterOperationExecutors.java:475) at org.apache.geode.distributed.internal.ClusterOperationExecutors.doProcessingThread(ClusterOperationExecutors.java:406) at org.apache.geode.distributed.internal.ClusterOperationExecutors$$Lambda$174/0x0000000840a39840.invoke(Unknown Source) at org.apache.geode.internal.logging.LoggingThreadFactory.lambda$newThread$0(LoggingThreadFactory.java:119) at org.apache.geode.internal.logging.LoggingThreadFactory$$Lambda$175/0x0000000840a39c40.run(Unknown Source) at java.lang.Thread.run(java.base@11.0.4/Thread.java:834)
Test output shows these as the last log entries written to logs & captured by gradle:
[vm0] [info 2019/10/15 22:40:23.697 GMT <Pooled Waiting Message Processor 1> tid=0xd0] Configured redundancy of 1 copies has been restored to /IncrementalBackupDistributedTest_testIncompleteInBaseline_region-2 [info 2019/10/15 22:40:23.698 GMT <Pooled Waiting Message Processor 1> tid=0xf1] Configured redundancy of 1 copies has been restored to /IncrementalBackupDistributedTest_testIncompleteInBaseline_region-2 [vm1] [info 2019/10/15 22:40:26.230 GMT <RMI TCP Connection(4)-172.17.0.9> tid=0x28] Received method: org.apache.geode.internal.cache.backup.IncrementalBackupDistributedTest$$Lambda$417/0x0000000840c20840.call with 0 args on object: org.apache.geode.internal.cache.backup.IncrementalBackupDistributedTest$$Lambda$417/0x0000000840c20840@2aba62dc [vm1] [info 2019/10/15 22:40:26.230 GMT <RMI TCP Connection(4)-172.17.0.9> tid=0x28] Received method: org.apache.geode.internal.cache.backup.IncrementalBackupDistributedTest$$Lambda$417/0x0000000840c20840.call with 0 args on object: org.apache.geode.internal.cache.backup.IncrementalBackupDistributedTest$$Lambda$417/0x0000000840c20840@2aba62dc [vm1] [info 2019/10/15 22:40:26.240 GMT <RMI TCP Connection(4)-172.17.0.9> tid=0x28] Received method: org.apache.geode.internal.cache.backup.IncrementalBackupDistributedTest$$Lambda$418/0x0000000840c20c40.call with 0 args on object: org.apache.geode.internal.cache.backup.IncrementalBackupDistributedTest$$Lambda$418/0x0000000840c20c40@6eaf6978
Attachments
Issue Links
- is duplicated by
-
GEODE-7411 IncrementalBackupDistributedTest.testMissingMemberInBaseline hangs in CI
- Resolved
-
GEODE-7293 testMissingMemberInBaseline hangs intermittently
- Closed
- links to