Remove excessive (trace) logging in FRS 72/45972/7
authorAndrej Leitner <andrej.leitner@pantheon.tech>
Wed, 21 Sep 2016 12:34:38 +0000 (14:34 +0200)
committerAndrej Leitner <andrej.leitner@pantheon.tech>
Thu, 22 Sep 2016 12:21:57 +0000 (14:21 +0200)
 - removed not so necessary logging + some updates
 - added some finals
 - simplify statements

Change-Id: I0db57a38a45efd6bb8334a9f05cdba991bff556d
Signed-off-by: Andrej Leitner <andrej.leitner@pantheon.tech>
12 files changed:
applications/forwardingrules-manager/src/main/java/org/opendaylight/openflowplugin/applications/frm/impl/DeviceMastershipManager.java
applications/forwardingrules-sync/src/main/java/org/opendaylight/openflowplugin/applications/frsync/impl/AbstractFrmSyncListener.java
applications/forwardingrules-sync/src/main/java/org/opendaylight/openflowplugin/applications/frsync/impl/SimplifiedConfigListener.java
applications/forwardingrules-sync/src/main/java/org/opendaylight/openflowplugin/applications/frsync/impl/SimplifiedOperationalListener.java
applications/forwardingrules-sync/src/main/java/org/opendaylight/openflowplugin/applications/frsync/impl/SyncReactorClusterDecorator.java
applications/forwardingrules-sync/src/main/java/org/opendaylight/openflowplugin/applications/frsync/impl/SyncReactorFutureDecorator.java
applications/forwardingrules-sync/src/main/java/org/opendaylight/openflowplugin/applications/frsync/impl/SyncReactorFutureZipDecorator.java
applications/forwardingrules-sync/src/main/java/org/opendaylight/openflowplugin/applications/frsync/impl/SyncReactorGuardDecorator.java
applications/forwardingrules-sync/src/main/java/org/opendaylight/openflowplugin/applications/frsync/impl/SyncReactorImpl.java
applications/forwardingrules-sync/src/main/java/org/opendaylight/openflowplugin/applications/frsync/impl/SyncReactorRetryDecorator.java
applications/forwardingrules-sync/src/main/java/org/opendaylight/openflowplugin/applications/frsync/impl/clustering/DeviceMastershipManager.java
applications/forwardingrules-sync/src/main/java/org/opendaylight/openflowplugin/applications/frsync/impl/strategy/SyncPlanPushStrategyFlatBatchImpl.java

index 2627cf6344dc99d9d353e44761387337ee19a10f..dd7c2721c7093830836384ac065dfaa54a05c881 100644 (file)
@@ -28,9 +28,9 @@ public class DeviceMastershipManager {
     }
 
     public void onDeviceConnected(final NodeId nodeId) {
+        LOG.debug("FRM service registered for: {}", nodeId.getValue());
         final DeviceMastership mastership = new DeviceMastership(nodeId, clusterSingletonService);
         deviceMasterships.put(nodeId, mastership);
-        LOG.debug("FRM service registered for: {}", nodeId.getValue());
     }
 
     public void onDeviceDisconnected(final NodeId nodeId) {
@@ -49,5 +49,4 @@ public class DeviceMastershipManager {
     ConcurrentHashMap<NodeId, DeviceMastership> getDeviceMasterships() {
         return deviceMasterships;
     }
-
 }
index 744b531e1f61317cc3f6cd3aed2de2e053cec919..e3dbc99c425be8969279cf175b99d989bdb9ed8a 100644 (file)
@@ -32,29 +32,29 @@ public abstract class AbstractFrmSyncListener<T extends DataObject> implements N
     public void onDataTreeChanged(@Nonnull final Collection<DataTreeModification<T>> modifications) {
         for (DataTreeModification<T> modification : modifications) {
             final NodeId nodeId = PathUtil.digNodeId(modification.getRootPath().getRootIdentifier());
-
+            if (LOG.isTraceEnabled()) {
+                LOG.trace("DataTreeModification of {} in {} datastore", nodeId.getValue(), dsType());
+            }
             try {
                 final Optional<ListenableFuture<Boolean>> optFuture = processNodeModification(modification);
                 if (optFuture.isPresent()) {
                     final ListenableFuture<Boolean> future = optFuture.get();
                     final Boolean ret = future.get(15000, TimeUnit.MILLISECONDS);
-                    LOG.debug("syncup return in {} listener for: {} [{}] thread:{}", dsType(), nodeId.getValue(), ret, threadName());
+                    if (LOG.isTraceEnabled()) {
+                        LOG.trace("syncup return [{}] for {} from {} listener", ret, nodeId.getValue(), dsType());
+                    }
                 }
             } catch (InterruptedException e) {
-                LOG.warn("permit for forwarding rules sync not acquired: {}", nodeId.getValue());
+                LOG.warn("Permit for forwarding rules sync not acquired: {}", nodeId.getValue());
             } catch (Exception e) {
-                LOG.error("error processing inventory node modification: {}", nodeId.getValue(), e);
+                LOG.error("Error processing inventory node modification: {}, {}", nodeId.getValue(), e);
             }
         }
     }
 
     protected abstract Optional<ListenableFuture<Boolean>> processNodeModification(
-            DataTreeModification<T> modification) throws InterruptedException;
+            final DataTreeModification<T> modification) throws InterruptedException;
 
     protected abstract LogicalDatastoreType dsType();
 
-    private static String threadName() {
-        final Thread currentThread = Thread.currentThread();
-        return currentThread.getName();
-    }
 }
index 0d2e64b1c27f6b54328a791acec75d77b5dd36fe..abc686e144d256dc097cdd54d8dad81a331f850a 100644 (file)
@@ -43,8 +43,7 @@ public class SimplifiedConfigListener extends AbstractFrmSyncListener<FlowCapabl
     }
 
     @Override
-    public void onDataTreeChanged(Collection<DataTreeModification<FlowCapableNode>> modifications) {
-        LOG.trace("Config changes: {}", modifications.size());
+    public void onDataTreeChanged(final Collection<DataTreeModification<FlowCapableNode>> modifications) {
         super.onDataTreeChanged(modifications);
     }
 
@@ -54,7 +53,7 @@ public class SimplifiedConfigListener extends AbstractFrmSyncListener<FlowCapabl
      * @throws InterruptedException from syncup
      */
     protected Optional<ListenableFuture<Boolean>> processNodeModification(
-            DataTreeModification<FlowCapableNode> modification) throws InterruptedException {
+            final DataTreeModification<FlowCapableNode> modification) throws InterruptedException {
         final InstanceIdentifier<FlowCapableNode> nodePath = modification.getRootPath().getRootIdentifier();
         final NodeId nodeId = PathUtil.digNodeId(nodePath);
 
@@ -62,7 +61,7 @@ public class SimplifiedConfigListener extends AbstractFrmSyncListener<FlowCapabl
 
         final Optional<FlowCapableNode> operationalNode = operationalDao.loadByNodeId(nodeId);
         if (!operationalNode.isPresent()) {
-            LOG.info("Skip syncup, {} operational is not present", nodeId.getValue());
+            LOG.debug("Skip syncup, {} operational is not present", nodeId.getValue());
             return Optional.absent();
         }
 
@@ -89,9 +88,7 @@ public class SimplifiedConfigListener extends AbstractFrmSyncListener<FlowCapabl
     private ListenableFuture<Boolean> onNodeAdded(final InstanceIdentifier<FlowCapableNode> nodePath,
                                                   final FlowCapableNode dataAfter,
                                                   final FlowCapableNode operationalNode) throws InterruptedException {
-        NodeId nodeId = PathUtil.digNodeId(nodePath);
-        LOG.trace("onNodeAdded {}", nodeId.getValue());
-        LOG.debug("Reconciliation {}: {}", dsType(), nodeId.getValue());
+        LOG.debug("Reconciliation {}: {}", dsType(), PathUtil.digNodeId(nodePath).getValue());
         final SyncupEntry syncupEntry = new SyncupEntry(dataAfter, dsType(), operationalNode, LogicalDatastoreType.OPERATIONAL);
         return reactor.syncup(nodePath, syncupEntry);
     }
@@ -106,8 +103,6 @@ public class SimplifiedConfigListener extends AbstractFrmSyncListener<FlowCapabl
     private ListenableFuture<Boolean> onNodeUpdated(final InstanceIdentifier<FlowCapableNode> nodePath,
                                                     final FlowCapableNode dataBefore,
                                                     final FlowCapableNode dataAfter) throws InterruptedException {
-        NodeId nodeId = PathUtil.digNodeId(nodePath);
-        LOG.trace("onNodeUpdated {}", nodeId.getValue());
         final SyncupEntry syncupEntry = new SyncupEntry(dataAfter, dsType(), dataBefore, dsType());
         return reactor.syncup(nodePath, syncupEntry);
     }
@@ -118,8 +113,6 @@ public class SimplifiedConfigListener extends AbstractFrmSyncListener<FlowCapabl
      */
     private ListenableFuture<Boolean> onNodeDeleted(final InstanceIdentifier<FlowCapableNode> nodePath,
                                                     final FlowCapableNode dataBefore) throws InterruptedException {
-        NodeId nodeId = PathUtil.digNodeId(nodePath);
-        LOG.trace("onNodeDeleted {}", nodeId.getValue());
         final SyncupEntry syncupEntry = new SyncupEntry(null, dsType(), dataBefore, dsType());
         return reactor.syncup(nodePath, syncupEntry);
     }
@@ -128,5 +121,4 @@ public class SimplifiedConfigListener extends AbstractFrmSyncListener<FlowCapabl
     public LogicalDatastoreType dsType() {
         return LogicalDatastoreType.CONFIGURATION;
     }
-
 }
index c5aaf8def34d70a4d11c88d2b0f3ee3e46154ca9..9e9d103ce02203a582de2e2ad2c828757d93c8f6 100644 (file)
@@ -65,8 +65,7 @@ public class SimplifiedOperationalListener extends AbstractFrmSyncListener<Node>
     }
 
     @Override
-    public void onDataTreeChanged(Collection<DataTreeModification<Node>> modifications) {
-        LOG.trace("Operational changes: {}", modifications.size());
+    public void onDataTreeChanged(final Collection<DataTreeModification<Node>> modifications) {
         super.onDataTreeChanged(modifications);
     }
 
@@ -76,7 +75,7 @@ public class SimplifiedOperationalListener extends AbstractFrmSyncListener<Node>
      * @throws InterruptedException from syncup
      */
     protected Optional<ListenableFuture<Boolean>> processNodeModification(
-            DataTreeModification<Node> modification) throws InterruptedException {
+            final DataTreeModification<Node> modification) throws InterruptedException {
         final NodeId nodeId = ModificationUtil.nodeId(modification);
         updateCache(modification);
 
@@ -96,7 +95,7 @@ public class SimplifiedOperationalListener extends AbstractFrmSyncListener<Node>
      * Unregister for device mastership.
      * @param modification Datastore modification
      */
-    private void updateCache(DataTreeModification<Node> modification) {
+    private void updateCache(final DataTreeModification<Node> modification) {
         NodeId nodeId = ModificationUtil.nodeId(modification);
         if (isDelete(modification) || isDeleteLogical(modification)) {
             operationalSnapshot.updateCache(nodeId, Optional.absent());
@@ -106,62 +105,43 @@ public class SimplifiedOperationalListener extends AbstractFrmSyncListener<Node>
         operationalSnapshot.updateCache(nodeId, Optional.fromNullable(ModificationUtil.flowCapableNodeAfter(modification)));
     }
 
-    private Optional<ListenableFuture<Boolean>> skipModification(DataTreeModification<Node> modification) {
-        LOG.trace("Skipping operational modification: {}, before {}, after {}",
-                ModificationUtil.nodeIdValue(modification),
-                modification.getRootNode().getDataBefore() == null ? "null" : "nonnull",
-                modification.getRootNode().getDataAfter() == null ? "null" : "nonnull");
+    private Optional<ListenableFuture<Boolean>> skipModification(final DataTreeModification<Node> modification) {
+        if (LOG.isTraceEnabled()) {
+            LOG.trace("Skipping operational modification: {}, before {}, after {}",
+                    ModificationUtil.nodeIdValue(modification),
+                    modification.getRootNode().getDataBefore() == null ? "null" : "nonnull",
+                    modification.getRootNode().getDataAfter() == null ? "null" : "nonnull");
+        }
         return Optional.absent();
     }
 
     /**
      * ModificationType.DELETE.
      */
-    private boolean isDelete(DataTreeModification<Node> modification) {
-        if (ModificationType.DELETE == modification.getRootNode().getModificationType()) {
-            LOG.trace("Delete {} (physical)", ModificationUtil.nodeIdValue(modification));
-            return true;
-        }
-
-        return false;
+    private boolean isDelete(final DataTreeModification<Node> modification) {
+        return ModificationType.DELETE == modification.getRootNode().getModificationType();
     }
 
     /**
      * All connectors disappeared from operational store (logical delete).
      */
-    private boolean isDeleteLogical(DataTreeModification<Node> modification) {
+    private boolean isDeleteLogical(final DataTreeModification<Node> modification) {
         final DataObjectModification<Node> rootNode = modification.getRootNode();
-        if (!safeConnectorsEmpty(rootNode.getDataBefore()) && safeConnectorsEmpty(rootNode.getDataAfter())) {
-            LOG.trace("Delete {} (logical)", ModificationUtil.nodeIdValue(modification));
-            return true;
-        }
+        return !safeConnectorsEmpty(rootNode.getDataBefore()) && safeConnectorsEmpty(rootNode.getDataAfter());
 
-        return false;
     }
 
-    private boolean isAdd(DataTreeModification<Node> modification) {
+    private boolean isAdd(final DataTreeModification<Node> modification) {
         final DataObjectModification<Node> rootNode = modification.getRootNode();
-        final Node dataAfter = rootNode.getDataAfter();
-        final Node dataBefore = rootNode.getDataBefore();
-
-        final boolean nodeAppearedInOperational = dataBefore == null && dataAfter != null;
-        if (nodeAppearedInOperational) {
-            LOG.trace("Add {} (physical)", ModificationUtil.nodeIdValue(modification));
-        }
-        return nodeAppearedInOperational;
+        return rootNode.getDataBefore() == null && rootNode.getDataAfter() != null;
     }
 
     /**
      * All connectors appeared in operational store (logical add).
      */
-    private boolean isAddLogical(DataTreeModification<Node> modification) {
+    private boolean isAddLogical(final DataTreeModification<Node> modification) {
         final DataObjectModification<Node> rootNode = modification.getRootNode();
-        if (safeConnectorsEmpty(rootNode.getDataBefore()) && !safeConnectorsEmpty(rootNode.getDataAfter())) {
-            LOG.trace("Add {} (logical)", ModificationUtil.nodeIdValue(modification));
-            return true;
-        }
-
-        return false;
+        return safeConnectorsEmpty(rootNode.getDataBefore()) && !safeConnectorsEmpty(rootNode.getDataAfter());
     }
 
     /**
@@ -171,7 +151,8 @@ public class SimplifiedOperationalListener extends AbstractFrmSyncListener<Node>
      * @return optional syncup future
      * @throws InterruptedException from syncup
      */
-    private Optional<ListenableFuture<Boolean>> reconciliation(DataTreeModification<Node> modification) throws InterruptedException {
+    private Optional<ListenableFuture<Boolean>> reconciliation(final DataTreeModification<Node> modification)
+            throws InterruptedException {
         final NodeId nodeId = ModificationUtil.nodeId(modification);
         final Optional<FlowCapableNode> nodeConfiguration = configDao.loadByNodeId(nodeId);
 
@@ -191,7 +172,7 @@ public class SimplifiedOperationalListener extends AbstractFrmSyncListener<Node>
         }
     }
 
-    private boolean isConsistentForReconcile(DataTreeModification<Node> modification) {
+    private boolean isConsistentForReconcile(final DataTreeModification<Node> modification) {
         final NodeId nodeId = PathUtil.digNodeId(modification.getRootPath().getRootIdentifier());
         final FlowCapableStatisticsGatheringStatus gatheringStatus = modification.getRootNode().getDataAfter()
                 .getAugmentation(FlowCapableStatisticsGatheringStatus.class);
@@ -222,13 +203,13 @@ public class SimplifiedOperationalListener extends AbstractFrmSyncListener<Node>
                 return true;
             }
         } catch (ParseException e) {
-            LOG.error("Timestamp parsing error {}", e);
+            LOG.warn("Timestamp parsing error {}", e);
         }
         LOG.debug("Fresh operational not present: {}", nodeId.getValue());
         return false;
     }
 
-    private static boolean safeConnectorsEmpty(Node node) {
+    private static boolean safeConnectorsEmpty(final Node node) {
         if (node == null) {
             return true;
         }
@@ -240,5 +221,4 @@ public class SimplifiedOperationalListener extends AbstractFrmSyncListener<Node>
     public LogicalDatastoreType dsType() {
         return LogicalDatastoreType.OPERATIONAL;
     }
-
 }
index e508e277d89584456c6cf3521162934e1cba4623..53f8dfe94231e811a7354b28647de822d2ca6a25 100644 (file)
@@ -38,8 +38,6 @@ public class SyncReactorClusterDecorator implements SyncReactor {
     public ListenableFuture<Boolean> syncup(final InstanceIdentifier<FlowCapableNode> flowcapableNodePath,
                                             final SyncupEntry syncupEntry) throws InterruptedException {
         final NodeId nodeId = PathUtil.digNodeId(flowcapableNodePath);
-        LOG.trace("Syncup cluster decorator: {}", nodeId.getValue());
-
         if (!deviceMastershipManager.isDeviceMastered(nodeId)) {
             LOG.debug("Skip syncup since not master for: {}", nodeId.getValue());
             return Futures.immediateFuture(Boolean.TRUE);
index ba3a1d8c59e9d858a8c85b78f70b047ecb9c3226..c279e9f9cb5e6c830cde696a65ea8a8ed7cb5a35 100644 (file)
@@ -39,18 +39,13 @@ public class SyncReactorFutureDecorator implements SyncReactor {
     public ListenableFuture<Boolean> syncup(final InstanceIdentifier<FlowCapableNode> flowcapableNodePath,
                                             final SyncupEntry syncupEntry) throws InterruptedException {
         final NodeId nodeId = PathUtil.digNodeId(flowcapableNodePath);
-        LOG.trace("syncup future decorator: {}", nodeId.getValue());
-
         return executorService.submit(() -> {
             final String oldThreadName = updateThreadName(nodeId);
-
             try {
-                final Boolean ret = doSyncupInFuture(flowcapableNodePath, syncupEntry)
-                        .get(10000, TimeUnit.MILLISECONDS);
-                LOG.trace("syncup return in future decorator: {} [{}]", nodeId.getValue(), ret);
-                return true;
+                final Boolean ret = doSyncupInFuture(flowcapableNodePath, syncupEntry).get(10000, TimeUnit.MILLISECONDS);
+                return ret;
             } catch (TimeoutException e) {
-                LOG.error("doSyncupInFuture timeout occured {}", nodeId.getValue(), e);
+                LOG.warn("doSyncupInFuture timeout occured {}", nodeId.getValue(), e);
                 return false;
             } finally {
                 updateThreadName(oldThreadName);
@@ -60,38 +55,27 @@ public class SyncReactorFutureDecorator implements SyncReactor {
 
     protected ListenableFuture<Boolean> doSyncupInFuture(final InstanceIdentifier<FlowCapableNode> flowcapableNodePath,
                                                          final SyncupEntry syncupEntry) throws InterruptedException {
-        final NodeId nodeId = PathUtil.digNodeId(flowcapableNodePath);
-        LOG.trace("doSyncupInFuture future decorator: {}", nodeId.getValue());
-
         return delegate.syncup(flowcapableNodePath, syncupEntry);
     }
 
-    private String updateThreadName(NodeId nodeId) {
+    private String updateThreadName(final NodeId nodeId) {
         final Thread currentThread = Thread.currentThread();
         final String oldName = currentThread.getName();
-        try {
-            if (oldName.startsWith(SyncReactorFutureDecorator.FRM_RPC_CLIENT_PREFIX)) {
-                currentThread.setName(oldName + "@" + nodeId.getValue());
-            } else {
-                LOG.warn("try to update foreign thread name {} {}", nodeId, oldName);
-            }
-        } catch (Exception e) {
-            LOG.error("failed updating threadName {}", nodeId, e);
+        if (oldName.startsWith(SyncReactorFutureDecorator.FRM_RPC_CLIENT_PREFIX)) {
+            currentThread.setName(oldName + "@" + nodeId.getValue());
+        } else {
+            LOG.warn("Try to update foreign thread name {} {}", nodeId, oldName);
         }
         return oldName;
     }
 
-    private void updateThreadName(String name) {
+    private void updateThreadName(final String name) {
         final Thread currentThread = Thread.currentThread();
         final String oldName = currentThread.getName();
-        try {
-            if (oldName.startsWith(SyncReactorFutureDecorator.FRM_RPC_CLIENT_PREFIX)) {
-                currentThread.setName(name);
-            } else {
-                LOG.warn("try to update foreign thread name {} {}", oldName, name);
-            }
-        } catch (Exception e) {
-            LOG.error("failed updating threadName {}", name, e);
+        if (oldName.startsWith(SyncReactorFutureDecorator.FRM_RPC_CLIENT_PREFIX)) {
+            currentThread.setName(name);
+        } else {
+            LOG.warn("Try to update foreign thread name {} {}", oldName, name);
         }
     }
 }
index 060a04964c02aff5ba2f9a5ca79604e9bc67c87c..d06697a896abafa95f181742cd4bceffe0ed6871 100644 (file)
@@ -16,10 +16,8 @@ import java.util.Map;
 import java.util.concurrent.Semaphore;
 import javax.annotation.concurrent.GuardedBy;
 import org.opendaylight.openflowplugin.applications.frsync.SyncReactor;
-import org.opendaylight.openflowplugin.applications.frsync.util.PathUtil;
 import org.opendaylight.openflowplugin.applications.frsync.util.SyncupEntry;
 import org.opendaylight.yang.gen.v1.urn.opendaylight.flow.inventory.rev130819.FlowCapableNode;
-import org.opendaylight.yang.gen.v1.urn.opendaylight.inventory.rev130819.NodeId;
 import org.opendaylight.yangtools.yang.binding.InstanceIdentifier;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
@@ -41,12 +39,8 @@ public class SyncReactorFutureZipDecorator extends SyncReactorFutureDecorator {
 
     public ListenableFuture<Boolean> syncup(final InstanceIdentifier<FlowCapableNode> flowcapableNodePath,
                                             final SyncupEntry syncupEntry) throws InterruptedException {
-        final NodeId nodeId = PathUtil.digNodeId(flowcapableNodePath);
-        LOG.trace("syncup zip decorator: {}", nodeId.getValue());
-
         try {
             compressionGuard.acquire();
-
             final boolean newFutureNecessary = updateCompressionState(flowcapableNodePath, syncupEntry);
             if (newFutureNecessary) {
                 super.syncup(flowcapableNodePath, syncupEntry);
@@ -59,9 +53,6 @@ public class SyncReactorFutureZipDecorator extends SyncReactorFutureDecorator {
 
     protected ListenableFuture<Boolean> doSyncupInFuture(final InstanceIdentifier<FlowCapableNode> flowcapableNodePath,
                                                          final SyncupEntry syncupEntry) throws InterruptedException {
-        final NodeId nodeId = PathUtil.digNodeId(flowcapableNodePath);
-        LOG.trace("doSyncupInFuture zip decorator: {}", nodeId.getValue());
-
         final SyncupEntry lastCompressionState = removeLastCompressionState(flowcapableNodePath);
         if (lastCompressionState == null) {
             return Futures.immediateFuture(true);
@@ -86,25 +77,24 @@ public class SyncReactorFutureZipDecorator extends SyncReactorFutureDecorator {
         return previousEntry == null;
     }
 
-    private void updateOptimizedConfigDelta(InstanceIdentifier<FlowCapableNode> flowcapableNodePath, SyncupEntry actual,
-                                            SyncupEntry previous) {
-        compressionQueue.put(flowcapableNodePath, new SyncupEntry(actual.getAfter(), actual.getDsTypeAfter(),
-                                                                  previous.getBefore(), previous.getDsTypeBefore()));
+    private void updateOptimizedConfigDelta(final InstanceIdentifier<FlowCapableNode> flowcapableNodePath,
+                                            final SyncupEntry actual,
+                                            final SyncupEntry previous) {
+        final SyncupEntry updatedEntry = new SyncupEntry(actual.getAfter(), actual.getDsTypeAfter(),
+                                                         previous.getBefore(), previous.getDsTypeBefore());
+        compressionQueue.put(flowcapableNodePath, updatedEntry);
     }
 
-    private SyncupEntry removeLastCompressionState(
-            final InstanceIdentifier<FlowCapableNode> flowcapableNodePath) {
+    private SyncupEntry removeLastCompressionState(final InstanceIdentifier<FlowCapableNode> flowcapableNodePath) {
         try {
             try {
                 compressionGuard.acquire();
             } catch (InterruptedException e) {
                 return null;
             }
-
             return compressionQueue.remove(flowcapableNodePath);
         } finally {
             compressionGuard.release();
         }
     }
-
 }
\ No newline at end of file
index 3f1b2716a3f743ccadfa1cad969f5c295d906205..defe9a0051a2d0d789a2120027fdbfe587b81c77 100644 (file)
@@ -44,8 +44,6 @@ public class SyncReactorGuardDecorator implements SyncReactor {
     public ListenableFuture<Boolean> syncup(final InstanceIdentifier<FlowCapableNode> flowcapableNodePath,
                                             final SyncupEntry syncupEntry) throws InterruptedException {
         final NodeId nodeId = PathUtil.digNodeId(flowcapableNodePath);
-        LOG.trace("syncup guard decorator: {}", nodeId.getValue());
-
         final long stampBeforeGuard = System.nanoTime();
         final Semaphore guard = summonGuardAndAcquire(flowcapableNodePath);
         if (guard == null) {
@@ -55,14 +53,14 @@ public class SyncReactorGuardDecorator implements SyncReactor {
 
         try {
             if (LOG.isDebugEnabled()) {
-                LOG.debug("syncup start {} waiting:{} guard:{} thread:{}", nodeId.getValue(),
+                LOG.debug("syncup start {} waiting:{} guard:{} thread:{}",
+                        nodeId.getValue(),
                         formatNanos(stampAfterGuard - stampBeforeGuard),
-                        guard, threadName());
+                        guard,
+                        threadName());
             }
 
-            final ListenableFuture<Boolean> endResult =
-                    delegate.syncup(flowcapableNodePath, syncupEntry);
-
+            final ListenableFuture<Boolean> endResult = delegate.syncup(flowcapableNodePath, syncupEntry);
             Futures.addCallback(endResult, createSyncupCallback(guard, stampBeforeGuard, stampAfterGuard, nodeId));
             return endResult;
         } catch (InterruptedException e) {
@@ -89,14 +87,14 @@ public class SyncReactorGuardDecorator implements SyncReactor {
             @Override
             public void onFailure(final Throwable t) {
                 final long stampFinished = System.nanoTime();
-                LOG.error("syncup failed {} took:{} rpc:{} wait:{} guard:{} permits thread:{}", nodeId.getValue(),
+                LOG.warn("syncup failed {} took:{} rpc:{} wait:{} guard:{} permits thread:{}", nodeId.getValue(),
                         formatNanos(stampFinished - stampBeforeGuard), formatNanos(stampFinished - stampAfterGuard),
                         formatNanos(stampAfterGuard - stampBeforeGuard), guard.availablePermits(), threadName());
                 releaseGuardForNodeId(guard);
             }};
     }
 
-    private static String formatNanos(long nanos) {
+    private static String formatNanos(final long nanos) {
         return "'" + TimeUnit.NANOSECONDS.toMillis(nanos) + " ms'";
     }
 
@@ -112,10 +110,12 @@ public class SyncReactorGuardDecorator implements SyncReactor {
         try {
             guard.acquire();
         } catch (InterruptedException e) {
-            LOG.error("syncup summon {} failed {}", nodeId.getValue(), e);
+            LOG.warn("syncup summon {} failed {}", nodeId.getValue(), e);
             return null;
         }
-        LOG.trace("syncup summon {} guard:{} thread:{}", nodeId.getValue(), guard, threadName());
+        if (LOG.isTraceEnabled()) {
+            LOG.trace("syncup summon {} guard:{} thread:{}", nodeId.getValue(), guard, threadName());
+        }
         return guard;
     }
 
@@ -126,7 +126,9 @@ public class SyncReactorGuardDecorator implements SyncReactor {
     private static void releaseGuardForNodeId(final Semaphore guard) {
         if (guard != null) {
             guard.release();
-            LOG.trace("syncup release guard:{} thread:{}", guard, threadName());
+            if (LOG.isTraceEnabled()) {
+                LOG.trace("syncup release guard:{} thread:{}", guard, threadName());
+            }
         }
     }
 
@@ -134,5 +136,4 @@ public class SyncReactorGuardDecorator implements SyncReactor {
         final Thread currentThread = Thread.currentThread();
         return currentThread.getName();
     }
-
 }
index 7f1be0b3fde15bdd1aa2ad52c279c7437e9b9efa..d66c30f7deabb50390a3a31ee7dd24d77b6e926c 100644 (file)
@@ -14,6 +14,7 @@ import com.google.common.base.Preconditions;
 import com.google.common.util.concurrent.Futures;
 import com.google.common.util.concurrent.ListenableFuture;
 import java.util.ArrayList;
+import java.util.Arrays;
 import java.util.Collections;
 import java.util.List;
 import java.util.Map;
@@ -23,7 +24,6 @@ import org.opendaylight.openflowplugin.applications.frsync.SyncReactor;
 import org.opendaylight.openflowplugin.applications.frsync.impl.strategy.SynchronizationDiffInput;
 import org.opendaylight.openflowplugin.applications.frsync.util.CrudCounts;
 import org.opendaylight.openflowplugin.applications.frsync.util.FlowCapableNodeLookups;
-import org.opendaylight.openflowplugin.applications.frsync.util.FxChainUtil;
 import org.opendaylight.openflowplugin.applications.frsync.util.ItemSyncBox;
 import org.opendaylight.openflowplugin.applications.frsync.util.PathUtil;
 import org.opendaylight.openflowplugin.applications.frsync.util.ReconcileUtil;
@@ -61,11 +61,6 @@ public class SyncReactorImpl implements SyncReactor {
         final NodeId nodeId = PathUtil.digNodeId(nodeIdent);
         FlowCapableNode configTree = syncupEntry.getAfter();
         FlowCapableNode operationalTree = syncupEntry.getBefore();
-
-        LOG.trace("syncup reactor {} cfg:{} oper:{}",
-                nodeId.getValue(),
-                configTree == null ? "is null" : "non null",
-                operationalTree == null ? "is null" : "non null");
         final SyncCrudCounters counters = new SyncCrudCounters();
 
         /**
@@ -76,7 +71,6 @@ public class SyncReactorImpl implements SyncReactor {
          *  - recommended order follows:
          * reconciliation strategy - phase 1: - add/update missing objects in following order:
          *  - table features - groups (reordered) - meters - flows
-         *
          * reconciliation strategy - phase 2: - remove redundant objects in following order:
          *  - flows - meters - groups (reordered)
          **/
@@ -98,9 +92,6 @@ public class SyncReactorImpl implements SyncReactor {
         final ListenableFuture<RpcResult<Void>> resultVehicle = syncPlanPushStrategy.executeSyncStrategy(
                 bootstrapResultFuture, input, counters);
 
-        // log final result
-        Futures.addCallback(resultVehicle, FxChainUtil.logResultCallback(nodeId, "final result"));
-
         return Futures.transform(resultVehicle, new Function<RpcResult<Void>, Boolean>() {
             @Override
             public Boolean apply(RpcResult<Void> input) {
@@ -111,14 +102,15 @@ public class SyncReactorImpl implements SyncReactor {
                     final CrudCounts flowCrudCounts = counters.getFlowCrudCounts();
                     final CrudCounts meterCrudCounts = counters.getMeterCrudCounts();
                     final CrudCounts groupCrudCounts = counters.getGroupCrudCounts();
-                    LOG.debug("syncup outcome[{}] (added/updated/removed): flow={}/{}/{}, group={}/{}/{}, meter={}/{}/{}, took={} ms",
+                    LOG.debug("syncup outcome[{}] (added/updated/removed): flow={}/{}/{}, group={}/{}/{}, " +
+                                    "meter={}/{}/{}, took={} ms, errors={}",
                             nodeId.getValue(),
                             flowCrudCounts.getAdded(), flowCrudCounts.getUpdated(), flowCrudCounts.getRemoved(),
                             groupCrudCounts.getAdded(), groupCrudCounts.getUpdated(), groupCrudCounts.getRemoved(),
                             meterCrudCounts.getAdded(), meterCrudCounts.getUpdated(), meterCrudCounts.getRemoved(),
-                            TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - counters.getStartNano()));
+                            TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - counters.getStartNano()),
+                            Arrays.toString(input.getErrors().toArray()));
                 }
-                LOG.trace("syncup errors: {}", input.getErrors());
                 return input.isSuccessful();
             }});
     }
@@ -202,5 +194,4 @@ public class SyncReactorImpl implements SyncReactor {
 
         return ReconcileUtil.resolveAndDivideGroupDiffs(nodeId, groupConfiguredMap, pendingGroups, false);
     }
-
 }
index 9ab76dfe19847b074e9949f694039d78b808005f..95194980ca37e2af97f8a5b84155ebbc50a6ccf9 100644 (file)
@@ -40,8 +40,6 @@ public class SyncReactorRetryDecorator implements SyncReactor {
                                             final SyncupEntry syncupEntry) throws InterruptedException {
 
         final NodeId nodeId = PathUtil.digNodeId(flowcapableNodePath);
-        LOG.trace("syncup retry decorator: {}", nodeId.getValue());
-
         if (syncupEntry.isOptimizedConfigDelta() && reconciliationRegistry.isRegistered(nodeId)) {
             LOG.debug("Config change ignored because {} is in reconcile.", nodeId.getValue());
             return Futures.immediateFuture(Boolean.FALSE);
@@ -52,7 +50,6 @@ public class SyncReactorRetryDecorator implements SyncReactor {
         return Futures.transform(syncupResult, new Function<Boolean, Boolean>() {
             @Override
             public Boolean apply(Boolean result) {
-                LOG.trace("syncup return in retry decorator: {} [{}]", nodeId.getValue(), result);
                 if (result) {
                     reconciliationRegistry.unregisterIfRegistered(nodeId);
                     return true;
index 4e7cef661308f39bacb08348ad765581fe074a4f..2b9e7ebf42d15416f611d52846230335e4f6d610 100644 (file)
@@ -32,9 +32,9 @@ public class DeviceMastershipManager {
     }
 
     public void onDeviceConnected(final NodeId nodeId) {
+        LOG.debug("FRS service registered for: {}", nodeId.getValue());
         final DeviceMastership mastership = new DeviceMastership(nodeId, reconciliationRegistry, clusterSingletonService);
         deviceMasterships.put(nodeId, mastership);
-        LOG.debug("FRS service registered for: {}", nodeId.getValue());
     }
 
     public void onDeviceDisconnected(final NodeId nodeId) {
@@ -53,5 +53,4 @@ public class DeviceMastershipManager {
     ConcurrentHashMap<NodeId, DeviceMastership> getDeviceMasterships() {
         return deviceMasterships;
     }
-
 }
index 68e0803723c532b7e7a9a6de1f9fe51cc3225165..527e8fd49154b7a9d49e610f93cd37e4d5093a99 100644 (file)
@@ -24,7 +24,6 @@ import java.util.Map;
 import java.util.concurrent.Future;
 import javax.annotation.Nullable;
 import org.opendaylight.openflowplugin.applications.frsync.SyncPlanPushStrategy;
-import org.opendaylight.openflowplugin.applications.frsync.util.FxChainUtil;
 import org.opendaylight.openflowplugin.applications.frsync.util.ItemSyncBox;
 import org.opendaylight.openflowplugin.applications.frsync.util.PathUtil;
 import org.opendaylight.openflowplugin.applications.frsync.util.ReconcileUtil;
@@ -73,7 +72,6 @@ import org.opendaylight.yang.gen.v1.urn.opendaylight.flat.batch.service.rev16032
 import org.opendaylight.yang.gen.v1.urn.opendaylight.flat.batch.service.rev160321.process.flat.batch.input.batch.batch.choice.flat.batch.update.meter._case.FlatBatchUpdateMeter;
 import org.opendaylight.yang.gen.v1.urn.opendaylight.flat.batch.service.rev160321.process.flat.batch.input.batch.batch.choice.flat.batch.update.meter._case.FlatBatchUpdateMeterBuilder;
 import org.opendaylight.yang.gen.v1.urn.opendaylight.flat.batch.service.rev160321.process.flat.batch.output.BatchFailure;
-import org.opendaylight.yang.gen.v1.urn.opendaylight.flow.inventory.rev130819.FlowCapableNode;
 import org.opendaylight.yang.gen.v1.urn.opendaylight.flow.inventory.rev130819.meters.Meter;
 import org.opendaylight.yang.gen.v1.urn.opendaylight.flow.inventory.rev130819.tables.TableKey;
 import org.opendaylight.yang.gen.v1.urn.opendaylight.flow.inventory.rev130819.tables.table.Flow;
@@ -82,11 +80,9 @@ import org.opendaylight.yang.gen.v1.urn.opendaylight.flows.service.rev160314.bat
 import org.opendaylight.yang.gen.v1.urn.opendaylight.group.types.rev131018.groups.Group;
 import org.opendaylight.yang.gen.v1.urn.opendaylight.groups.service.rev160315.batch.group.input.update.grouping.OriginalBatchedGroupBuilder;
 import org.opendaylight.yang.gen.v1.urn.opendaylight.groups.service.rev160315.batch.group.input.update.grouping.UpdatedBatchedGroupBuilder;
-import org.opendaylight.yang.gen.v1.urn.opendaylight.inventory.rev130819.NodeId;
 import org.opendaylight.yang.gen.v1.urn.opendaylight.inventory.rev130819.NodeRef;
 import org.opendaylight.yang.gen.v1.urn.opendaylight.meters.service.rev160316.batch.meter.input.update.grouping.OriginalBatchedMeterBuilder;
 import org.opendaylight.yang.gen.v1.urn.opendaylight.meters.service.rev160316.batch.meter.input.update.grouping.UpdatedBatchedMeterBuilder;
-import org.opendaylight.yangtools.yang.binding.InstanceIdentifier;
 import org.opendaylight.yangtools.yang.common.RpcResult;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
@@ -105,9 +101,6 @@ public class SyncPlanPushStrategyFlatBatchImpl implements SyncPlanPushStrategy {
     public ListenableFuture<RpcResult<Void>> executeSyncStrategy(ListenableFuture<RpcResult<Void>> resultVehicle,
                                                                  final SynchronizationDiffInput diffInput,
                                                                  final SyncCrudCounters counters) {
-        final InstanceIdentifier<FlowCapableNode> nodeIdent = diffInput.getNodeIdent();
-        final NodeId nodeId = PathUtil.digNodeId(nodeIdent);
-
         // prepare default (full) counts
         counters.getGroupCrudCounts().setAdded(ReconcileUtil.countTotalPushed(diffInput.getGroupsToAddOrUpdate()));
         counters.getGroupCrudCounts().setUpdated(ReconcileUtil.countTotalUpdated(diffInput.getGroupsToAddOrUpdate()));
@@ -150,19 +143,15 @@ public class SyncPlanPushStrategyFlatBatchImpl implements SyncPlanPushStrategy {
 
                 final Future<RpcResult<ProcessFlatBatchOutput>> rpcResultFuture = flatBatchService.processFlatBatch(flatBatchInput);
 
-                final int failureIndexLimit = batchOrder;
-
                 if (LOG.isDebugEnabled()) {
                     Futures.addCallback(JdkFutureAdapters.listenInPoolThread(rpcResultFuture),
-                            createCounterCallback(batchBag, failureIndexLimit, counters));
+                            createCounterCallback(batchBag, batchOrder, counters));
                 }
 
                 return Futures.transform(JdkFutureAdapters.listenInPoolThread(rpcResultFuture),
                         ReconcileUtil.<ProcessFlatBatchOutput>createRpcResultToVoidFunction("flat-batch"));
             }
         });
-
-        Futures.addCallback(resultVehicle, FxChainUtil.logResultCallback(nodeId, "flat-batch"));
         return resultVehicle;
     }