[GEODE-4948] CI Failure: org.apache.geode.distributed.internal.DlockAndTxlockRegressionTest testDLockProtectsAgainstTransactionConflict

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 1.6.0
• Fix Version/s: 1.6.0
• Component/s: distributed lock service
• Assignee: Unassigned
• Reporter: Udo Kohlmeyer
• Created: 27/Mar/18 17:35
• Updated: 02/Apr/18 16:53
• Resolved: 02/Apr/18 16:52

Description

Started @ 2018-03-24 05:00:58.670 +0000
Ended @ 2018-03-24 05:03:18.615 +0000
Started @ 2018-03-24 05:03:42.413 +0000
2018-03-24 05:31:23.431 +0000 org.apache.geode.distributed.internal.DlockAndTxlockRegressionTest testDLockProtectsAgainstTransactionConflict
Ended @ 2018-03-24 07:22:12.143 +0000
Started @ 2018-03-24 04:12:27.592 +0000
Ended @ 2018-03-24 05:00:51.346 +0000
Started @ 2018-03-24 04:10:29.782 +0000
Ended @ 2018-03-24 04:11:58.704 +000

From the Stack dumps it seems to be waiting for the DLock:

"Pooled Waiting Message Processor 0" #123 daemon prio=5 os_prio=0 tid=0x00007f1534032800 nid=0x294 in Object.wait() [0x00007f15cd5e0000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:502)
        at org.apache.geode.internal.cache.locks.TXLessorDepartureHandler.waitForInProcessDepartures(TXLessorDepartureHandler.java:46)
        - locked <0x00000000e0675468> (a java.lang.Object)
        at org.apache.geode.distributed.internal.locks.DLockGrantor.handleLockBatch(DLockGrantor.java:489)
        - locked <0x00000000e07118b8> (a java.util.HashMap)
        at org.apache.geode.distributed.internal.locks.DLockGrantor.handleLockRequest(DLockGrantor.java:749)
        at org.apache.geode.distributed.internal.locks.DLockRequestProcessor$DLockRequestMessage.basicProcess(DLockRequestProcessor.java:695)
        at org.apache.geode.distributed.internal.locks.DLockRequestProcessor$DLockRequestMessage$1.run(DLockRequestProcessor.java:597)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at org.apache.geode.distributed.internal.ClusterDistributionManager.runUntilShutdown(ClusterDistributionManager.java:1118)
        at org.apache.geode.distributed.internal.ClusterDistributionManager.access$000(ClusterDistributionManager.java:109)
        at org.apache.geode.distributed.internal.ClusterDistributionManager$6$1.run(ClusterDistributionManager.java:863)
        at java.lang.Thread.run(Thread.java:748)

is causing the Processor 1 to wait

"Pooled Waiting Message Processor 1" #172 daemon prio=5 os_prio=0 tid=0x00007f153404a000 nid=0x2e1 waiting for monitor entry [0x00007f1527bfa000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at org.apache.geode.distributed.internal.locks.DLockGrantor.releaseLockBatch(DLockGrantor.java:662)
        - waiting to lock <0x00000000e07118b8> (a java.util.HashMap)
        at org.apache.geode.internal.cache.locks.TXOriginatorRecoveryProcessor.sendMessage(TXOriginatorRecoveryProcessor.java:91)
        at org.apache.geode.internal.cache.locks.TXLessorDepartureHandler$1.run(TXLessorDepartureHandler.java:97)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at org.apache.geode.distributed.internal.ClusterDistributionManager.runUntilShutdown(ClusterDistributionManager.java:1118)
        at org.apache.geode.distributed.internal.ClusterDistributionManager.access$000(ClusterDistributionManager.java:109)
        at org.apache.geode.distributed.internal.ClusterDistributionManager$6$1.run(ClusterDistributionManager.java:863)
        at java.lang.Thread.run(Thread.java:748)