Log more information about acquiring and releasing the state transfer…

… lock to aid debugging.
infinispan · Oct 21, 2011 · 1855a28 · 1855a28
1 parent 3ccf4f8
commit 1855a28
Showing 1 changed file with 11 additions and 4 deletions.
diff --git a/core/src/main/java/org/infinispan/statetransfer/StateTransferLockImpl.java b/core/src/main/java/org/infinispan/statetransfer/StateTransferLockImpl.java
@@ -158,10 +158,12 @@ public void waitForStateTransferToEnd(InvocationContext ctx, ReplicableCommand c
    @Override
    public void blockNewTransactions() throws InterruptedException {
       if (!txLock.isWriteLockedByCurrentThread()) {
-         if (trace) log.debug("Blocking new transactions");
+         log.debug("Blocking new transactions");
+         if (trace) log.tracef("Acquiring exclusive state transfer shared lock, shared holders: %d", txLock.getReadLockCount());
          txLockLatch.close();
          // we want to ensure that all the modifications that passed through the tx gate have ended
          txLock.writeLock().lockInterruptibly();
+         log.trace("Acquired state transfer lock in exclusive mode");
          // need to unlock here because the unlock call may arrive on a different thread
          txLock.writeLock().unlock();
       } else {
@@ -171,7 +173,7 @@ public void blockNewTransactions() throws InterruptedException {
 
    @Override
    public void unblockNewTransactions() {
-      if (trace) log.debug("Unblocking new transactions");
+      log.debug("Unblocking new transactions");
       // only for lock commands
       txLockLatch.open();
    }
@@ -190,8 +192,10 @@ private boolean acquireLockForTx(InvocationContext ctx) throws InterruptedExcept
       // hold the read lock to ensure the rehash process waits for the tx to end
       // first try with 0 timeout, in case a rehash is not in progress
       if (txLockLatch.await(0, TimeUnit.MILLISECONDS)) {
-         if (txLock.readLock().tryLock(0, TimeUnit.MILLISECONDS))
+         if (txLock.readLock().tryLock(0, TimeUnit.MILLISECONDS)) {
+            if (trace) log.tracef("Acquired shared state transfer shared lock, remaining holders: %d", txLock.getReadLockCount());
             return true;
+         }
       }
 
       // When the command is being replicated, the caller already holds the tx lock for read on the
@@ -214,8 +218,10 @@ private boolean acquireLockForTx(InvocationContext ctx) throws InterruptedExcept
             return false;
 
          // hold the read lock to ensure the rehash process waits for the tx to end
-         if (txLock.readLock().tryLock(0, TimeUnit.MILLISECONDS))
+         if (txLock.readLock().tryLock(0, TimeUnit.MILLISECONDS)) {
+            if (trace) log.tracef("Acquired shared state transfer shared lock, remaining holders: %d", txLock.getReadLockCount());
             return true;
+         }
 
          // the rehashing thread has acquired the write lock between our latch check and our read lock attempt
          // retry, unless the timeout expired
@@ -230,6 +236,7 @@ private boolean releaseLockForTx() {
       if (holdCount > 1)
          throw new IllegalStateException("Transaction lock should not be acquired more than once by any thread");
       if (holdCount == 1) {
+         if (trace) log.tracef("Releasing shared state transfer shared lock, remaining holders: %d", txLock.getReadLockCount());
          txLock.readLock().unlock();
          return true;
       } else {