commit 03b831821a4bce8e34599176d0ed329f3751dc8d
author Jordan Halterman <jordan@onlab.us> Tue May 09 12:11:22 2017 -0700
committer Jordan Halterman <jordan@onlab.us> Wed May 10 19:10:01 2017 +0000
tree a7c55a2282c841c19e43227ca0d4ef309ead60bf
parent b2243071f2b4e6e496b6dbbc00b87abd81a7ea87

[ONOS-6425] Improve logging for transactions

Change-Id: I74ff83a96aa76782a724d9db3e1a9557a02bacf5

core/store/primitives/src/main/java/org/onosproject/store/primitives/impl/Transaction.java

diff --git a/core/store/primitives/src/main/java/org/onosproject/store/primitives/impl/Transaction.java b/core/store/primitives/src/main/java/org/onosproject/store/primitives/impl/Transaction.java
index 8ad8cb8..0e2e45d 100644
--- a/core/store/primitives/src/main/java/org/onosproject/store/primitives/impl/Transaction.java
+++ b/core/store/primitives/src/main/java/org/onosproject/store/primitives/impl/Transaction.java
@@ -25,6 +25,8 @@
 import org.onosproject.store.service.Version;
 import org.onosproject.store.service.TransactionContext;
 import org.onosproject.store.service.TransactionException;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 import static com.google.common.base.MoreObjects.toStringHelper;
 import static com.google.common.base.Preconditions.checkState;
@@ -105,6 +107,7 @@
     private static final String TX_INACTIVE_ERROR = "transaction is not active";
     private static final String TX_UNPREPARED_ERROR = "transaction has not been prepared";
 
+    protected final Logger log = LoggerFactory.getLogger(getClass());
     protected final TransactionId transactionId;
     protected final Transactional<T> transactionalObject;
     private final AtomicBoolean open = new AtomicBoolean();
@@ -191,9 +194,11 @@
      * @return a completable future to be completed once the transaction has been started
      */
     public CompletableFuture<Version> begin() {
+        log.debug("Beginning transaction {} for {}", transactionId, transactionalObject);
         open();
         return transactionalObject.begin(transactionId).thenApply(lock -> {
             this.lock = lock;
+            log.trace("Transaction lock acquired: {}", lock);
             return lock;
         });
     }
@@ -212,6 +217,7 @@
     public CompletableFuture<Boolean> prepare(List<T> updates) {
         checkOpen();
         checkActive();
+        log.debug("Preparing transaction {} for {}", transactionId, transactionalObject);
         Version lock = this.lock;
         checkState(lock != null, TX_INACTIVE_ERROR);
         setState(State.PREPARING);
@@ -234,6 +240,7 @@
     public CompletableFuture<Boolean> prepareAndCommit(List<T> updates) {
         checkOpen();
         checkActive();
+        log.debug("Preparing and committing transaction {} for {}", transactionId, transactionalObject);
         Version lock = this.lock;
         checkState(lock != null, TX_INACTIVE_ERROR);
         setState(State.PREPARING);
@@ -255,6 +262,7 @@
     public CompletableFuture<Void> commit() {
         checkOpen();
         checkPrepared();
+        log.debug("Committing transaction {} for {}", transactionId, transactionalObject);
         setState(State.COMMITTING);
         return transactionalObject.commit(transactionId).thenRun(() -> {
             setState(State.COMMITTED);
@@ -271,6 +279,7 @@
     public CompletableFuture<Void> rollback() {
         checkOpen();
         checkPrepared();
+        log.debug("Rolling back transaction {} for {}", transactionId, transactionalObject);
         setState(State.ROLLING_BACK);
         return transactionalObject.rollback(transactionId).thenRun(() -> {
             setState(State.ROLLED_BACK);