Uploaded image for project: 'Infinispan'
  1. Infinispan
  2. ISPN-373

Deadlock between lock and put under heavy concurrency

XMLWordPrintable

      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)

              mircea.markus Mircea Markus (Inactive)
              nigel1_jira Nigel Slack-Smith (Inactive)
              Votes:
              2 Vote for this issue
              Watchers:
              4 Start watching this issue

                Created:
                Updated:
                Resolved: