Move OperationLimiter.acquire() warnings to callers

We have two distinct call sites from where we are acquiring permits,
where failure to acquire has different root cause:
RemoteTransactionContext's failure to acquire indicates a slow leader,
while TransactionContextWrapper indicates a failure to discover a leader
in time.

Modify acquire() to report success and log failures to acquire from
the two call sites, with different messages so it is immediately clear
what is going on.

Change-Id: Ie828984c6a984690224494af1a9fdd0e4f257fab
Signed-off-by: Robert Varga <robert.varga@pantheon.tech>
(cherry picked from commit 6a0fab98dc4d16a52922c6594f99a97d4050e800)

diff --git a/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/AbstractTransactionContextFactory.java b/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/AbstractTransactionContextFactory.java
index 69c69bb84b395dc5d89db35f74cdd44343987c95..70a014f2a46f30907190bc768b38d2ab968f51e6 100644 (file)
--- a/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/AbstractTransactionContextFactory.java
+++ b/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/AbstractTransactionContextFactory.java
@@ -116,7 +116,7 @@ abstract class AbstractTransactionContextFactory<F extends LocalTransactionFacto
     final TransactionContextWrapper newTransactionContextWrapper(final TransactionProxy parent,
             final String shardName) {
         final TransactionContextWrapper transactionContextWrapper =
-                new TransactionContextWrapper(parent.getIdentifier(), actorContext);
+                new TransactionContextWrapper(parent.getIdentifier(), actorContext, shardName);
 
         Future<PrimaryShardInfo> findPrimaryFuture = findPrimaryShard(shardName, parent.getIdentifier());
         if (findPrimaryFuture.isCompleted()) {

diff --git a/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/OperationLimiter.java b/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/OperationLimiter.java
index ea93f1f5ad501d01e80f6e4a62853cf3eeed35d5..e1fee6d62b485393f3f98f9c3f9ffcfe64f34db9 100644 (file)
--- a/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/OperationLimiter.java
+++ b/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/OperationLimiter.java
@@ -45,8 +45,6 @@ public class OperationLimiter  {
             if (semaphore.tryAcquire(acquirePermits, acquireTimeout, TimeUnit.NANOSECONDS)) {
                 return true;
             }
-
-            LOG.warn("Failed to acquire operation permit for transaction {}", identifier);
         } catch (InterruptedException e) {
             if (LOG.isDebugEnabled()) {
                 LOG.debug("Interrupted when trying to acquire operation permit for transaction {}", identifier, e);
@@ -66,7 +64,8 @@ public class OperationLimiter  {
         this.semaphore.release(permits);
     }
 
-    public TransactionIdentifier getIdentifier() {
+    @VisibleForTesting
+    TransactionIdentifier getIdentifier() {
         return identifier;
     }
 

diff --git a/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/RemoteTransactionContext.java b/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/RemoteTransactionContext.java
index 7c45c542bd1422887c5c96cd9f53ce3ce81e9268..941c86116cb7926ebd13a6b55b79b32484bdd54e 100644 (file)
--- a/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/RemoteTransactionContext.java
+++ b/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/RemoteTransactionContext.java
@@ -245,7 +245,16 @@ public class RemoteTransactionContext extends AbstractTransactionContext {
      * @return True if a permit was successfully acquired, false otherwise
      */
     private boolean acquireOperation() {
-        return isOperationHandOffComplete() && limiter.acquire();
+        if (isOperationHandOffComplete()) {
+            if (limiter.acquire()) {
+                return true;
+            }
+
+            LOG.warn("Failed to acquire execute operation permit for transaction {} on actor {}", getIdentifier(),
+                actor);
+        }
+
+        return false;
     }
 
     @Override

diff --git a/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/TransactionContextWrapper.java b/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/TransactionContextWrapper.java
index 3fb129f3817f75b7388a335458e4b67b4c8aca09..a126ce95971bae232c2da0b1f9fb9aa3c550cfe6 100644 (file)
--- a/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/TransactionContextWrapper.java
+++ b/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/TransactionContextWrapper.java
@@ -38,8 +38,8 @@ class TransactionContextWrapper {
      */
     @GuardedBy("queuedTxOperations")
     private final List<TransactionOperation> queuedTxOperations = Lists.newArrayList();
-
     private final TransactionIdentifier identifier;
+    private final String shardName;
 
     /**
      * The resulting TransactionContext.
@@ -48,12 +48,14 @@ class TransactionContextWrapper {
 
     private final OperationLimiter limiter;
 
-    TransactionContextWrapper(final TransactionIdentifier identifier, final ActorContext actorContext) {
+    TransactionContextWrapper(final TransactionIdentifier identifier, final ActorContext actorContext,
+            final String shardName) {
         this.identifier = Preconditions.checkNotNull(identifier);
         this.limiter = new OperationLimiter(identifier,
                 // 1 extra permit for the ready operation
                 actorContext.getDatastoreContext().getShardBatchedModificationCount() + 1,
                 TimeUnit.MILLISECONDS.toSeconds(actorContext.getDatastoreContext().getOperationTimeoutInMillis()));
+        this.shardName = Preconditions.checkNotNull(shardName);
     }
 
     TransactionContext getTransactionContext() {
@@ -71,7 +73,7 @@ class TransactionContextWrapper {
         final boolean invokeOperation;
         synchronized (queuedTxOperations) {
             if (transactionContext == null) {
-                LOG.debug("Tx {} Queuing TransactionOperation", getIdentifier());
+                LOG.debug("Tx {} Queuing TransactionOperation", identifier);
 
                 queuedTxOperations.add(operation);
                 invokeOperation = false;
@@ -83,7 +85,10 @@ class TransactionContextWrapper {
         if (invokeOperation) {
             operation.invoke(transactionContext);
         } else {
-            limiter.acquire();
+            if (!limiter.acquire()) {
+                LOG.warn("Failed to acquire enqueue operation permit for transaction {} on shard {}", identifier,
+                    shardName);
+            }
         }
     }
 

diff --git a/opendaylight/md-sal/sal-distributed-datastore/src/test/java/org/opendaylight/controller/cluster/datastore/TransactionContextWrapperTest.java b/opendaylight/md-sal/sal-distributed-datastore/src/test/java/org/opendaylight/controller/cluster/datastore/TransactionContextWrapperTest.java
index 058968c33992d27dc10e88cc0c76229dedd5d128..888a9e6f9306b0cefdf2f984f65ff8187c4e66a8 100644 (file)
--- a/opendaylight/md-sal/sal-distributed-datastore/src/test/java/org/opendaylight/controller/cluster/datastore/TransactionContextWrapperTest.java
+++ b/opendaylight/md-sal/sal-distributed-datastore/src/test/java/org/opendaylight/controller/cluster/datastore/TransactionContextWrapperTest.java
@@ -32,7 +32,7 @@ public class TransactionContextWrapperTest {
         MockitoAnnotations.initMocks(this);
         doReturn(DatastoreContext.newBuilder().build()).when(actorContext).getDatastoreContext();
         transactionContextWrapper = new TransactionContextWrapper(MockIdentifiers.transactionIdentifier(
-            TransactionContextWrapperTest.class, "mock"), actorContext);
+            TransactionContextWrapperTest.class, "mock"), actorContext, "mock");
     }
 
     @Test