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

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, 4.1.0.Final Environment: Mac OS-X 10.6, 2.8Ghz Core 2, 8GB RAM Reporter: Nigel Slack-Smith Assignee: Mircea Markus Fix For: 4.2.0.BETA1, 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)