BUG 3340 : Improve logging 86/21486/1
authorMoiz Raja <moraja@cisco.com>
Thu, 28 May 2015 02:22:40 +0000 (19:22 -0700)
committerTom Pantelis <tpanteli@brocade.com>
Sat, 30 May 2015 19:18:23 +0000 (19:18 +0000)
- In SimpleShardDataTreeCohort we log the contents of the tree at debug level. This
  makes it impossible to turn on debug for the package org.opendaylight.cluster.datastore
- At some point we seem to have lost the feature to include the chain number in the transaction
 identifier. I added that back in.

Change-Id: Ifd6cd4c9f5c49790dfb045d2800b5a8beef19b37
Signed-off-by: Moiz Raja <moraja@cisco.com>
(cherry picked from commit afa53553bd476c625ae137e14c7484ff510fbcc4)

opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/SimpleShardDataTreeCohort.java
opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/TransactionChainProxy.java
opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/TransactionContextFactory.java
opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/identifiers/ChainedTransactionIdentifier.java
opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/identifiers/TransactionChainIdentifier.java [new file with mode: 0644]
opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/identifiers/TransactionIdentifier.java
opendaylight/md-sal/sal-distributed-datastore/src/test/java/org/opendaylight/controller/cluster/datastore/DebugThreePhaseCommitCohortTest.java
opendaylight/md-sal/sal-distributed-datastore/src/test/java/org/opendaylight/controller/cluster/datastore/TransactionChainProxyTest.java
opendaylight/md-sal/sal-distributed-datastore/src/test/java/org/opendaylight/controller/cluster/datastore/identifiers/ChainedTransactionIdentifierTest.java [new file with mode: 0644]
opendaylight/md-sal/sal-distributed-datastore/src/test/java/org/opendaylight/controller/cluster/datastore/identifiers/TransactionChainIdentifierTest.java [new file with mode: 0644]

index bfbfb138a1791ea8dc577e095b0dd38fa5164d14..2b6b39684a271976be496cd366eda3ef0797b7c9 100644 (file)
@@ -38,7 +38,7 @@ final class SimpleShardDataTreeCohort extends ShardDataTreeCohort {
     public ListenableFuture<Boolean> canCommit() {
         try {
             dataTree.getDataTree().validate(dataTreeModification());
-            LOG.debug("Transaction {} validated", transaction);
+            LOG.trace("Transaction {} validated", transaction);
             return TRUE_FUTURE;
         } catch (Exception e) {
             return Futures.immediateFailedFuture(e);
@@ -53,7 +53,7 @@ final class SimpleShardDataTreeCohort extends ShardDataTreeCohort {
              * FIXME: this is the place where we should be interacting with persistence, specifically by invoking
              *        persist on the candidate (which gives us a Future).
              */
-            LOG.debug("Transaction {} prepared candidate {}", transaction, candidate);
+            LOG.trace("Transaction {} prepared candidate {}", transaction, candidate);
             return VOID_FUTURE;
         } catch (Exception e) {
             LOG.debug("Transaction {} failed to prepare", transaction, e);
@@ -84,7 +84,7 @@ final class SimpleShardDataTreeCohort extends ShardDataTreeCohort {
             return Futures.immediateFailedFuture(e);
         }
 
-        LOG.debug("Transaction {} committed, proceeding to notify", transaction);
+        LOG.trace("Transaction {} committed, proceeding to notify", transaction);
         dataTree.notifyListeners(candidate);
         return VOID_FUTURE;
     }
index ff6471caa0637ebfc21b7fc6947909a02c63bbe4..0946b402fd9bb02b3129d48d5f5236ea605510a5 100644 (file)
@@ -13,6 +13,7 @@ import com.google.common.base.Preconditions;
 import java.util.Collection;
 import java.util.concurrent.atomic.AtomicInteger;
 import java.util.concurrent.atomic.AtomicReferenceFieldUpdater;
+import org.opendaylight.controller.cluster.datastore.identifiers.TransactionChainIdentifier;
 import org.opendaylight.controller.cluster.datastore.identifiers.TransactionIdentifier;
 import org.opendaylight.controller.cluster.datastore.messages.CloseTransactionChain;
 import org.opendaylight.controller.cluster.datastore.messages.PrimaryShardInfo;
@@ -115,18 +116,19 @@ final class TransactionChainProxy extends AbstractTransactionContextFactory<Loca
     private static final AtomicReferenceFieldUpdater<TransactionChainProxy, State> STATE_UPDATER =
             AtomicReferenceFieldUpdater.newUpdater(TransactionChainProxy.class, State.class, "currentState");
 
-    private final String transactionChainId;
+    private final TransactionChainIdentifier transactionChainId;
     private final TransactionContextFactory parent;
     private volatile State currentState = IDLE_STATE;
 
     TransactionChainProxy(final TransactionContextFactory parent) {
         super(parent.getActorContext());
-        transactionChainId = parent.getActorContext().getCurrentMemberName() + "-txn-chain-" + CHAIN_COUNTER.incrementAndGet();
+
+        transactionChainId = new TransactionChainIdentifier(parent.getActorContext().getCurrentMemberName(), CHAIN_COUNTER.incrementAndGet());
         this.parent = parent;
     }
 
     public String getTransactionChainId() {
-        return transactionChainId;
+        return transactionChainId.toString();
     }
 
     @Override
@@ -152,7 +154,7 @@ final class TransactionChainProxy extends AbstractTransactionContextFactory<Loca
         currentState = CLOSED_STATE;
 
         // Send a close transaction chain request to each and every shard
-        getActorContext().broadcast(new CloseTransactionChain(transactionChainId).toSerializable());
+        getActorContext().broadcast(new CloseTransactionChain(transactionChainId.toString()).toSerializable());
     }
 
     private TransactionProxy allocateWriteTransaction(final TransactionType type) {
@@ -187,7 +189,15 @@ final class TransactionChainProxy extends AbstractTransactionContextFactory<Loca
             return parent.findPrimaryShard(shardName);
         }
 
-        LOG.debug("Waiting for ready futures for on chain {}", getTransactionChainId());
+        final String previousTransactionId;
+
+        if(localState instanceof Pending){
+            previousTransactionId = ((Pending) localState).getIdentifier().toString();
+            LOG.debug("Waiting for ready futures with pending Tx {}", previousTransactionId);
+        } else {
+            previousTransactionId = "";
+            LOG.debug("Waiting for ready futures on chain {}", getTransactionChainId());
+        }
 
         // Add a callback for completion of the combined Futures.
         final Promise<PrimaryShardInfo> returnPromise = akka.dispatch.Futures.promise();
@@ -197,10 +207,11 @@ final class TransactionChainProxy extends AbstractTransactionContextFactory<Loca
             public void onComplete(final Throwable failure, final Object notUsed) {
                 if (failure != null) {
                     // A Ready Future failed so fail the returned Promise.
+                    LOG.error("Ready future failed for Tx {}", previousTransactionId);
                     returnPromise.failure(failure);
                 } else {
-                    LOG.debug("Previous Tx readied - proceeding to FindPrimaryShard on chain {}",
-                            getTransactionChainId());
+                    LOG.debug("Previous Tx {} readied - proceeding to FindPrimaryShard",
+                            previousTransactionId);
 
                     // Send the FindPrimaryShard message and use the resulting Future to complete the
                     // returned Promise.
@@ -246,6 +257,6 @@ final class TransactionChainProxy extends AbstractTransactionContextFactory<Loca
 
     @Override
     protected TransactionIdentifier nextIdentifier() {
-        return TransactionIdentifier.create(getMemberName(), TX_COUNTER.getAndIncrement(), transactionChainId);
+        return transactionChainId.newTransactionIdentifier();
     }
 }
index 49f2ea85ff3221c4357b9ef20344bffa9a27f6ec..2b5144aa5ee432e48308f6d9a1968bacc4418817 100644 (file)
@@ -36,7 +36,7 @@ final class TransactionContextFactory extends AbstractTransactionContextFactory<
 
     @Override
     protected TransactionIdentifier nextIdentifier() {
-        return TransactionIdentifier.create(getMemberName(), TX_COUNTER.getAndIncrement(), null);
+        return TransactionIdentifier.create(getMemberName(), TX_COUNTER.getAndIncrement());
     }
 
     @Override
index 1aec854785f05be6fe5a07a4aafac6fc1e855f99..78f68f6204fdb9a946fa37ac47b37729b528a469 100644 (file)
@@ -8,20 +8,38 @@
 package org.opendaylight.controller.cluster.datastore.identifiers;
 
 import com.google.common.base.Preconditions;
+import com.google.common.base.Supplier;
+import com.google.common.base.Suppliers;
 
 /**
  * A TransactionIdentifier which is tied to a backend transaction chain.
  */
 public class ChainedTransactionIdentifier extends TransactionIdentifier {
     private final String chainId;
+    private Supplier<String> stringRepresentation;
 
-    public ChainedTransactionIdentifier(final String memberName, final long counter, final String chainId) {
-        super(memberName, counter);
-        this.chainId = Preconditions.checkNotNull(chainId);
+    public ChainedTransactionIdentifier(final TransactionChainIdentifier chainId, final long txnCounter) {
+        super(chainId.getMemberName(), txnCounter);
+        Preconditions.checkNotNull(chainId);
+        this.chainId = chainId.toString();
+        stringRepresentation = Suppliers.memoize(new Supplier<String>() {
+            @Override
+            public String get() {
+                return new StringBuilder(chainId.toString().length() + TX_SEPARATOR.length() + 10).
+                        append(chainId).append(TX_SEPARATOR).append(getCounter()).toString();
+            }
+        });
     }
 
+
     @Override
     public String getChainId() {
         return chainId;
     }
+
+    @Override
+    public String toString() {
+        return stringRepresentation.get();
+    }
+
 }
diff --git a/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/identifiers/TransactionChainIdentifier.java b/opendaylight/md-sal/sal-distributed-datastore/src/main/java/org/opendaylight/controller/cluster/datastore/identifiers/TransactionChainIdentifier.java
new file mode 100644 (file)
index 0000000..4b1c096
--- /dev/null
@@ -0,0 +1,47 @@
+/*
+ * Copyright (c) 2015 Cisco Systems, Inc. and others.  All rights reserved.
+ *
+ * This program and the accompanying materials are made available under the
+ * terms of the Eclipse Public License v1.0 which accompanies this distribution,
+ * and is available at http://www.eclipse.org/legal/epl-v10.html
+ */
+
+package org.opendaylight.controller.cluster.datastore.identifiers;
+
+import com.google.common.base.Supplier;
+import com.google.common.base.Suppliers;
+import java.util.concurrent.atomic.AtomicLong;
+
+public class TransactionChainIdentifier {
+
+    protected static final String CHAIN_SEPARATOR = "-chn-";
+
+    private final AtomicLong txnCounter = new AtomicLong();
+    private final Supplier<String> stringRepresentation;
+    private final String memberName;
+
+    public TransactionChainIdentifier(final String memberName, final long counter) {
+        this.memberName = memberName;
+        stringRepresentation = Suppliers.memoize(new Supplier<String>() {
+            @Override
+            public String get() {
+                final StringBuilder sb = new StringBuilder();
+                sb.append(memberName).append(CHAIN_SEPARATOR);
+                sb.append(counter);
+                return sb.toString();
+            }
+        });
+    }
+    @Override
+    public String toString() {
+        return stringRepresentation.get();
+    }
+
+    public TransactionIdentifier newTransactionIdentifier(){
+        return new ChainedTransactionIdentifier(this, txnCounter.incrementAndGet());
+    }
+
+    public String getMemberName() {
+        return memberName;
+    }
+}
index 6742b5c7db259998da37767facea6482c06725dd..5a365f28a3e45abcc794b6de1f8349125cd9a2ee 100644 (file)
@@ -9,10 +9,17 @@
 package org.opendaylight.controller.cluster.datastore.identifiers;
 
 import com.google.common.base.Preconditions;
-import com.google.common.base.Strings;
 
 public class TransactionIdentifier {
-    private static final String TX_SEPARATOR = "-txn-";
+    protected static final String TX_SEPARATOR = "-txn-";
+
+    protected String getMemberName() {
+        return memberName;
+    }
+
+    protected long getCounter() {
+        return counter;
+    }
 
     private final String memberName;
     private final long counter;
@@ -27,12 +34,8 @@ public class TransactionIdentifier {
         return "";
     }
 
-    public static TransactionIdentifier create(String memberName, long counter, String chainId) {
-        if (Strings.isNullOrEmpty(chainId)) {
-            return new TransactionIdentifier(memberName, counter);
-        } else {
-            return new ChainedTransactionIdentifier(memberName, counter, chainId);
-        }
+    public static TransactionIdentifier create(String memberName, long counter) {
+        return new TransactionIdentifier(memberName, counter);
     }
 
     @Override
@@ -72,4 +75,5 @@ public class TransactionIdentifier {
 
         return stringRepresentation;
     }
+
 }
index 4427ee89bfedf22b8aab9b29809a7030bc580325..630e153b2ab32eae17e7ee5c71943928fa458ecf 100644 (file)
@@ -47,7 +47,7 @@ public class DebugThreePhaseCommitCohortTest {
         List<Future<Object>> expCohortFutures = new ArrayList<>();
         doReturn(expCohortFutures).when(mockDelegate).getCohortFutures();
 
-        TransactionIdentifier transactionId = TransactionIdentifier.create("1", 1, "");
+        TransactionIdentifier transactionId = TransactionIdentifier.create("1", 1);
         Throwable debugContext = new RuntimeException("mock");
         DebugThreePhaseCommitCohort cohort = new DebugThreePhaseCommitCohort(transactionId , mockDelegate , debugContext );
 
index 11ca195311cdb9014ee956c0d6ab54532b1639cc..4ea81f44e3c6f5b2e6cc5c97ba1b4010ede956a9 100644 (file)
@@ -203,8 +203,7 @@ public class TransactionChainProxyTest extends AbstractTransactionProxyTest {
 
         verifyOneBatchedModification(txActorRef1, new WriteModification(TestModel.TEST_PATH, writeNode1), true);
 
-        String tx2MemberName = "tx2MemberName";
-        doReturn(tx2MemberName).when(mockActorContext).getCurrentMemberName();
+        String tx2MemberName = "mock-member";
         ActorRef shardActorRef2 = setupActorContextWithoutInitialCreateTransaction(getSystem());
         ActorRef txActorRef2 = setupActorContextWithInitialCreateTransaction(getSystem(), READ_WRITE,
                 DataStoreVersions.CURRENT_VERSION, tx2MemberName, shardActorRef2);
diff --git a/opendaylight/md-sal/sal-distributed-datastore/src/test/java/org/opendaylight/controller/cluster/datastore/identifiers/ChainedTransactionIdentifierTest.java b/opendaylight/md-sal/sal-distributed-datastore/src/test/java/org/opendaylight/controller/cluster/datastore/identifiers/ChainedTransactionIdentifierTest.java
new file mode 100644 (file)
index 0000000..ba3130b
--- /dev/null
@@ -0,0 +1,23 @@
+package org.opendaylight.controller.cluster.datastore.identifiers;
+
+import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertTrue;
+import org.junit.Test;
+
+public class ChainedTransactionIdentifierTest {
+
+    @Test
+    public void testToString(){
+        TransactionChainIdentifier chainId = new TransactionChainIdentifier("member-1", 99);
+        ChainedTransactionIdentifier chainedTransactionIdentifier = new ChainedTransactionIdentifier(chainId, 100);
+
+        String txnId = chainedTransactionIdentifier.toString();
+
+        assertTrue(txnId.contains("member-1"));
+        assertTrue(txnId.contains("100"));
+        assertTrue(txnId.contains("99"));
+
+        assertEquals("member-1-chn-99-txn-100", txnId);
+    }
+
+}
\ No newline at end of file
diff --git a/opendaylight/md-sal/sal-distributed-datastore/src/test/java/org/opendaylight/controller/cluster/datastore/identifiers/TransactionChainIdentifierTest.java b/opendaylight/md-sal/sal-distributed-datastore/src/test/java/org/opendaylight/controller/cluster/datastore/identifiers/TransactionChainIdentifierTest.java
new file mode 100644 (file)
index 0000000..c91fe2b
--- /dev/null
@@ -0,0 +1,29 @@
+package org.opendaylight.controller.cluster.datastore.identifiers;
+
+import static org.junit.Assert.assertEquals;
+import org.junit.Test;
+
+public class TransactionChainIdentifierTest {
+    @Test
+    public void testToString(){
+        TransactionChainIdentifier transactionChainIdentifier = new TransactionChainIdentifier("member-1", 99);
+
+        String id = transactionChainIdentifier.toString();
+
+        assertEquals("member-1-chn-99", id);
+    }
+
+    @Test
+    public void testNewTransactionIdentifier(){
+        TransactionChainIdentifier transactionChainIdentifier = new TransactionChainIdentifier("member-1", 99);
+
+        TransactionIdentifier txId1 = transactionChainIdentifier.newTransactionIdentifier();
+
+        assertEquals("member-1-chn-99-txn-1", txId1.toString());
+
+        TransactionIdentifier txId2 = transactionChainIdentifier.newTransactionIdentifier();
+
+        assertEquals("member-1-chn-99-txn-2", txId2.toString());
+    }
+
+}
\ No newline at end of file