[infinispan-issues] [JBoss JIRA] (ISPN-6098) LockManagerTest.testMultipleCounterStripped random failures

Tue Jan 26 03:40:00 EST 2016

Dan Berindei created ISPN-6098:
----------------------------------

             Summary: LockManagerTest.testMultipleCounterStripped random failures
                 Key: ISPN-6098
                 URL: https://issues.jboss.org/browse/ISPN-6098
             Project: Infinispan
          Issue Type: Bug
          Components: Test Suite - Core
    Affects Versions: 8.1.0.Final
            Reporter: Dan Berindei
             Fix For: 8.2.0.Beta1

Doesn't appear to fail in CI, but I did get a couple failures running the test on my machine:

{noformat}
17:42:29,998 ERROR (testng-LockManagerTest:) [UnitTestTestNGListener] Test testMultipleCounterStripped(org.infinispan.lock.LockManagerTest) failed.
java.util.concurrent.ExecutionException: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 60 seconds for key key-6 and requestor Thread[pool-1127-thread-4,5,main]. Lock is held by null
	at java.util.concurrent.FutureTask.report(FutureTask.java:122) ~[?:1.8.0_60]
	at java.util.concurrent.FutureTask.get(FutureTask.java:192) ~[?:1.8.0_60]
	at org.infinispan.lock.LockManagerTest.doMultipleCounterTest(LockManagerTest.java:193) ~[test-classes/:?]
	at org.infinispan.lock.LockManagerTest.testMultipleCounterStripped(LockManagerTest.java:67) ~[test-classes/:?]
Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 60 seconds for key key-6 and requestor Thread[pool-1127-thread-4,5,main]. Lock is held by null
	at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.lock(DefaultLockManager.java:236) ~[classes/:?]
	at org.infinispan.util.concurrent.locks.impl.DefaultLockManager$CompositeLockPromise.lock(DefaultLockManager.java:305) ~[classes/:?]
	at org.infinispan.lock.LockManagerTest.lambda$doMultipleCounterTest$483(LockManagerTest.java:163) ~[test-classes/:?]
	... 4 more
{noformat}

In another run, I got a deadlock that I think is related in {{InfinispanLockTest}}:

{noformat}
"testng-InfinispanLockTest" #19 prio=5 os_prio=0 tid=0x00007ff7f0eeb800 nid=0x4f5d waiting on condition [0x00007ff770da5000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x0000000084202448> (a java.util.concurrent.FutureTask)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:429)
	at java.util.concurrent.FutureTask.get(FutureTask.java:191)
	at org.infinispan.lock.InfinispanLockTest.testSingleCounter(InfinispanLockTest.java:262)
	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:497)
	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:84)
	at org.testng.internal.Invoker.invokeMethod(Invoker.java:714)
	at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:901)
	at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1231)
	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127)
	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111)
	at org.testng.TestRunner.privateRun(TestRunner.java:767)
	at org.testng.TestRunner.run(TestRunner.java:617)
	at org.testng.SuiteRunner.runTest(SuiteRunner.java:348)
	at org.testng.SuiteRunner.access$000(SuiteRunner.java:38)
	at org.testng.SuiteRunner$SuiteWorker.run(SuiteRunner.java:382)
	at org.testng.internal.thread.ThreadUtil$2.call(ThreadUtil.java:64)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)
   Locked ownable synchronizers:	- <0x0000000082875cc0> (a java.util.concurrent.ThreadPoolExecutor$Worker)

"pool-1011-thread-7" #9840 prio=5 os_prio=0 tid=0x00007ff7380da000 nid=0x75f7 waiting on condition [0x00007ff698409000]
   java.lang.Thread.State: TIMED_WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000000842020d8> (a java.util.concurrent.CompletableFuture$Signaller)
	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	at java.util.concurrent.CompletableFuture$Signaller.block(CompletableFuture.java:1695)
	at java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3323)
	at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1775)
	at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
	at org.infinispan.util.concurrent.CompletableFutures.await(CompletableFutures.java:74)
	at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.lock(InfinispanLock.java:319)
	at org.infinispan.lock.InfinispanLockTest.lambda$testSingleCounter$509(InfinispanLockTest.java:243)
	at org.infinispan.lock.InfinispanLockTest$$Lambda$516/1905052434.call(Unknown Source)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)
   Locked ownable synchronizers:	- <0x00000000842021f8> (a java.util.concurrent.ThreadPoolExecutor$Worker)

"pool-1011-thread-6" #9839 prio=5 os_prio=0 tid=0x00007ff738130800 nid=0x75f6 waiting on condition [0x00007ff699c21000]
   java.lang.Thread.State: TIMED_WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000000842023a0> (a java.util.concurrent.CompletableFuture$Signaller)
	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	at java.util.concurrent.CompletableFuture$Signaller.block(CompletableFuture.java:1695)
	at java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3323)
	at java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1775)
	at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
	at org.infinispan.util.concurrent.CompletableFutures.await(CompletableFutures.java:74)
	at org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.lock(InfinispanLock.java:319)
	at org.infinispan.lock.InfinispanLockTest.lambda$testSingleCounter$509(InfinispanLockTest.java:243)
	at org.infinispan.lock.InfinispanLockTest$$Lambda$516/1905052434.call(Unknown Source)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)
   Locked ownable synchronizers:	- <0x0000000084202468> (a java.util.concurrent.ThreadPoolExecutor$Worker)
{noformat}

I also suggest using {{AbstractInfinispanTest.fork()}} instead of an explicit {{ExecutorService}} in both tests, because without the test name in the thread name it's impossible to filter the test logs.

--
This message was sent by Atlassian JIRA
(v6.4.11#64026)