[infinispan-issues] [JBoss JIRA] Commented: (ISPN-373) Deadlock between lock and put under heavy concurrency

Nikita Koksharov (JIRA) jira-events at lists.jboss.org
Tue Sep 7 05:40:53 EDT 2010


    [ https://jira.jboss.org/browse/ISPN-373?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12549356#action_12549356 ] 

Nikita Koksharov commented on ISPN-373:
---------------------------------------

I see some cheats in testcase attached by you. First of all, number of iteration is 100.000 instead as 1.000.000. Second, you are just swallow exceptions by rollbacking them... Make some RIGHT changes in your testcase and you will see the bug is not gone.

So let's count exceptions

add this variable
final AtomicInteger counter = new AtomicInteger();

chage this:
               } catch (Exception e) {
                  try {
                     txnMgr.rollback();
                  } catch (Exception ex) {
                  }
               }

to this code:

               } catch (Exception e) {
                   counter.incrementAndGet();
                  try {
                     txnMgr.rollback();
                  } catch (Exception ex) {
                  }
               }

and add following

      executorService.execute(new Runnable() {

        @Override
        public void run() {
            Assert.assertEquals(0, counter);
        }
      });

before 

executorService.shutdown();

> Deadlock between lock and put under heavy concurrency
> -----------------------------------------------------
>
>                 Key: ISPN-373
>                 URL: https://jira.jboss.org/browse/ISPN-373
>             Project: Infinispan
>          Issue Type: Bug
>          Components: Locking and Concurrency
>    Affects Versions: 4.0.0.Final
>         Environment: Mac OS-X 10.6, 2.8Ghz Core 2, 8GB RAM
>            Reporter: Nigel Slack-Smith
>            Assignee: Vladimir Blagojevic
>             Fix For: 4.2.0.CR1, 4.2.0.Final
>
>         Attachments: DeadlockLockingTest.java
>
>
> Concurrent calls to lock and then put seem to be deadlocking. After AdvancedCache.lock is called under a transaction a subsequent call to Cache.put on the same key normally does not attempt to take out a lock, but after a variable number of concurrent calls Cache.put is attempting to take out a lock and then deadlocking with the AdvancedCache.lock call. 
> Here's my test case which hits the deadlock.
> public class DataGridTest {
> 	@Test
> 	public void testCreate() {
> 		CacheManager cacheManager = new DefaultCacheManager();
> 		final String cacheName = "TestCache";
> 		Configuration config = new Configuration();
> 		config.setTransactionManagerLookupClass("org.infinispan.transaction.lookup.DummyTransactionManagerLookup");
> 		cacheManager.defineConfiguration(cacheName, config);
> 		final Cache<Object, Object> cache = cacheManager.getCache(cacheName);
> 		cache.start();
> 		
> 		ExecutorService executorService = Executors.newFixedThreadPool(2);
> 		for (int i = 0; i < 1000000; ++i) {
> 			final String valueStr = "V" + i;
> 			
> 			executorService.execute(new Runnable() {
> 				@Override
> 				public void run() {
> 					TransactionManager txnMgr = cache.getAdvancedCache().getTransactionManager();
> 					
> 					try {
> 						txnMgr.begin();
> 					} catch (Exception e) {
> 						fail(e.getMessage());
> 					}
> 					
> 					cache.getAdvancedCache().lock("K1");
> 					cache.put("K1", valueStr);
> 					
> 					try {
> 						txnMgr.commit();
> 					} catch (Exception e) {
> 						fail(e.getMessage());
> 					}
> 				}
> 			});
> 		}
> 		executorService.shutdown();
> 		try {
> 			if (executorService.awaitTermination(300, TimeUnit.SECONDS) == false) {
> 				fail("Termination timeout");
> 			}
> 		} catch (InterruptedException e) {
> 			fail("Thread interrupted exception: " + e.getMessage());
> 		}
> 	}
> }
> ...and here's the stack trace showing what appears to be a deadlock timeout.
> 2010-03-16 08:35:57,821 1     ERROR [org.infinispan.interceptors.InvocationContextInterceptor] Execution error: 
> org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [10 seconds] on key [K1] for requestor [GlobalTransaction:<null>:114691]! Lock held by [GlobalTransaction:<null>:114690]
> 	at org.infinispan.container.EntryFactoryImpl.acquireLock(EntryFactoryImpl.java:213)
> 	at org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:148)
> 	at org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:106)
> 	at org.infinispan.interceptors.LockingInterceptor.visitPutKeyValueCommand(LockingInterceptor.java:197)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> 	at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
> 	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> 	at org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:183)
> 	at org.infinispan.interceptors.TxInterceptor.visitPutKeyValueCommand(TxInterceptor.java:132)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> 	at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:48)
> 	at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:34)
> 	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
> 	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:269)
> 	at org.infinispan.CacheDelegate.put(CacheDelegate.java:434)
> 	at org.infinispan.CacheDelegate.put(CacheDelegate.java:205)
> 	at com.kasm.core.test.DataGridTest$1.run(DataGridTest.java:47)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> 	at java.lang.Thread.run(Thread.java:637)
> 2010-03-16 08:35:57,821 1     ERROR [org.infinispan.interceptors.InvocationContextInterceptor] Execution error: 
> org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [10 seconds] on key [K1] for requestor [GlobalTransaction:<null>:114692]! Lock held by [GlobalTransaction:<null>:114690]
> 	at org.infinispan.container.EntryFactoryImpl.acquireLock(EntryFactoryImpl.java:213)
> 	at org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:148)
> 	at org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:106)
> 	at org.infinispan.interceptors.LockingInterceptor.visitLockControlCommand(LockingInterceptor.java:146)
> 	at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:82)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> 	at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
> 	at org.infinispan.commands.AbstractVisitor.visitLockControlCommand(AbstractVisitor.java:147)
> 	at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:82)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> 	at org.infinispan.interceptors.TxInterceptor.enlistReadAndInvokeNext(TxInterceptor.java:171)
> 	at org.infinispan.interceptors.TxInterceptor.visitLockControlCommand(TxInterceptor.java:115)
> 	at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:82)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> 	at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:48)
> 	at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:34)
> 	at org.infinispan.commands.AbstractVisitor.visitLockControlCommand(AbstractVisitor.java:147)
> 	at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:82)
> 	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:269)
> 	at org.infinispan.CacheDelegate.lock(CacheDelegate.java:305)
> 	at org.infinispan.CacheDelegate.lock(CacheDelegate.java:298)
> 	at com.kasm.core.test.DataGridTest$1.run(DataGridTest.java:46)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> 	at java.lang.Thread.run(Thread.java:637)
> Exception in thread "pool-2-thread-2" org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [10 seconds] on key [K1] for requestor [GlobalTransaction:<null>:114691]! Lock held by [GlobalTransaction:<null>:114690]
> 	at org.infinispan.container.EntryFactoryImpl.acquireLock(EntryFactoryImpl.java:213)
> 	at org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:148)
> 	at org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:106)
> 	at org.infinispan.interceptors.LockingInterceptor.visitPutKeyValueCommand(LockingInterceptor.java:197)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> 	at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
> 	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> 	at org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:183)
> 	at org.infinispan.interceptors.TxInterceptor.visitPutKeyValueCommand(TxInterceptor.java:132)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> 	at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:48)
> 	at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:34)
> 	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:57)
> 	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:76)
> 	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:269)
> 	at org.infinispan.CacheDelegate.put(CacheDelegate.java:434)
> 	at org.infinispan.CacheDelegate.put(CacheDelegate.java:205)
> 	at com.kasm.core.test.DataGridTest$1.run(DataGridTest.java:47)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> 	at java.lang.Thread.run(Thread.java:637)
> Exception in thread "pool-2-thread-1" org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [10 seconds] on key [K1] for requestor [GlobalTransaction:<null>:114692]! Lock held by [GlobalTransaction:<null>:114690]
> 	at org.infinispan.container.EntryFactoryImpl.acquireLock(EntryFactoryImpl.java:213)
> 	at org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:148)
> 	at org.infinispan.container.EntryFactoryImpl.wrapEntryForWriting(EntryFactoryImpl.java:106)
> 	at org.infinispan.interceptors.LockingInterceptor.visitLockControlCommand(LockingInterceptor.java:146)
> 	at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:82)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> 	at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
> 	at org.infinispan.commands.AbstractVisitor.visitLockControlCommand(AbstractVisitor.java:147)
> 	at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:82)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> 	at org.infinispan.interceptors.TxInterceptor.enlistReadAndInvokeNext(TxInterceptor.java:171)
> 	at org.infinispan.interceptors.TxInterceptor.visitLockControlCommand(TxInterceptor.java:115)
> 	at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:82)
> 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
> 	at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:48)
> 	at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:34)
> 	at org.infinispan.commands.AbstractVisitor.visitLockControlCommand(AbstractVisitor.java:147)
> 	at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:82)
> 	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:269)
> 	at org.infinispan.CacheDelegate.lock(CacheDelegate.java:305)
> 	at org.infinispan.CacheDelegate.lock(CacheDelegate.java:298)
> 	at com.kasm.core.test.DataGridTest$1.run(DataGridTest.java:46)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> 	at java.lang.Thread.run(Thread.java:637)

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

        


More information about the infinispan-issues mailing list