[infinispan-issues] [JBoss JIRA] Commented: (ISPN-373) Deadlock between lock and put under heavy concurrency
Vladimir Blagojevic (JIRA)
jira-events at lists.jboss.org
Tue Sep 7 08:30:52 EDT 2010
[ https://jira.jboss.org/browse/ISPN-373?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12549404#action_12549404 ]
Vladimir Blagojevic commented on ISPN-373:
------------------------------------------
Not actual cheats as much as sloppiness. First of all I was not using transactional cache manager. Second, we were invoking executor shutdown right away from the main thread which in turn interrupts executor threads leading to non deterministic results. And yes, I kept it at 100K iterations because I am getting OOM at 1M. Have a look now. Looking forward to your comments.
> 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