Bug 7011 - Race condition in statistics collection related transaction chain handling

[openflowplugin.git] / openflowplugin-impl / src / main / java / org / opendaylight / openflowplugin / impl / statistics / StatisticsManagerImpl.java

diff --git a/openflowplugin-impl/src/main/java/org/opendaylight/openflowplugin/impl/statistics/StatisticsManagerImpl.java b/openflowplugin-impl/src/main/java/org/opendaylight/openflowplugin/impl/statistics/StatisticsManagerImpl.java
index 8ebd6cd614085425a630792bfe8fc0686d476361..f0bcbdcce43c73509569ac126d932591d1be5ea0 100644 (file)
--- a/openflowplugin-impl/src/main/java/org/opendaylight/openflowplugin/impl/statistics/StatisticsManagerImpl.java
+++ b/openflowplugin-impl/src/main/java/org/opendaylight/openflowplugin/impl/statistics/StatisticsManagerImpl.java
@@ -56,7 +56,7 @@ public class StatisticsManagerImpl implements StatisticsManager, StatisticsManag
     private static final Logger LOG = LoggerFactory.getLogger(StatisticsManagerImpl.class);
 
     private static final long DEFAULT_STATS_TIMEOUT_SEC = 50L;
-    private final ConvertorExecutor convertorExecutor;
+    private final ConvertorExecutor converterExecutor;
 
     private DeviceInitializationPhaseHandler deviceInitPhaseHandler;
     private DeviceTerminationPhaseHandler deviceTerminPhaseHandler;
@@ -69,7 +69,7 @@ public class StatisticsManagerImpl implements StatisticsManager, StatisticsManag
 
     private StatisticsWorkMode workMode = StatisticsWorkMode.COLLECTALL;
     private final Semaphore workModeGuard = new Semaphore(1, true);
-    private boolean isStatisticsPollingEnabled;
+    private boolean isStatisticsPollingOff;
     private BindingAwareBroker.RpcRegistration<StatisticsManagerControlService> controlServiceRegistration;
 
     private final HashedWheelTimer hashedWheelTimer;
@@ -80,22 +80,33 @@ public class StatisticsManagerImpl implements StatisticsManager, StatisticsManag
     }
 
     public StatisticsManagerImpl(final RpcProviderRegistry rpcProviderRegistry,
-                                 final boolean isStatisticsPollingEnabled,
+                                 final boolean isStatisticsPollingOff,
                                  final HashedWheelTimer hashedWheelTimer,
                                  final ConvertorExecutor convertorExecutor) {
         Preconditions.checkArgument(rpcProviderRegistry != null);
-       this.convertorExecutor = convertorExecutor;
-        this.controlServiceRegistration = Preconditions.checkNotNull(rpcProviderRegistry.addRpcImplementation(
-                StatisticsManagerControlService.class, this));
-        this.isStatisticsPollingEnabled = isStatisticsPollingEnabled;
+           this.converterExecutor = convertorExecutor;
+        this.controlServiceRegistration = Preconditions.checkNotNull(
+                rpcProviderRegistry.addRpcImplementation(StatisticsManagerControlService.class, this)
+        );
+        this.isStatisticsPollingOff = isStatisticsPollingOff;
         this.hashedWheelTimer = hashedWheelTimer;
     }
 
     @Override
-    public void onDeviceContextLevelUp(final DeviceInfo deviceInfo, final LifecycleService lifecycleService) throws Exception {
-
-        final StatisticsContext statisticsContext = new StatisticsContextImpl(deviceInfo, isStatisticsPollingEnabled, lifecycleService, convertorExecutor, this);
-        Verify.verify(contexts.putIfAbsent(deviceInfo, statisticsContext) == null, "StatisticsCtx still not closed for Node {}", deviceInfo.getLOGValue());
+    public void onDeviceContextLevelUp(final DeviceInfo deviceInfo,
+                                       final LifecycleService lifecycleService) throws Exception {
+
+        final StatisticsContext statisticsContext =
+                new StatisticsContextImpl(
+                        deviceInfo,
+                        isStatisticsPollingOff,
+                        lifecycleService,
+                        converterExecutor,
+                        this);
+        Verify.verify(
+                contexts.putIfAbsent(deviceInfo, statisticsContext) == null,
+                "StatisticsCtx still not closed for Node {}", deviceInfo.getLOGValue()
+        );
         lifecycleService.setStatContext(statisticsContext);
         deviceInitPhaseHandler.onDeviceContextLevelUp(deviceInfo, lifecycleService);
     }
@@ -107,11 +118,15 @@ public class StatisticsManagerImpl implements StatisticsManager, StatisticsManag
                         final DeviceInfo deviceInfo) {
 
         if (!statisticsContext.isSchedulingEnabled()) {
-            LOG.debug("Disabled statistics scheduling for device: {}", deviceInfo.getNodeId().getValue());
+            if (LOG.isDebugEnabled()) {
+                LOG.debug("Disabled statistics scheduling for device: {}", deviceInfo.getNodeId().getValue());
+            }
             return;
         }
 
-        LOG.debug("POLLING ALL STATISTICS for device: {}", deviceInfo.getNodeId());
+        if (LOG.isDebugEnabled()) {
+            LOG.debug("POLLING ALL STATISTICS for device: {}", deviceInfo.getNodeId());
+        }
         timeCounter.markStart();
         final ListenableFuture<Boolean> deviceStatisticsCollectionFuture = statisticsContext.gatherDynamicData();
         Futures.addCallback(deviceStatisticsCollectionFuture, new FutureCallback<Boolean>() {
@@ -125,12 +140,14 @@ public class StatisticsManagerImpl implements StatisticsManager, StatisticsManag
             @Override
             public void onFailure(@Nonnull final Throwable throwable) {
                 timeCounter.addTimeMark();
-                LOG.warn("Statistics gathering for single node was not successful: {}", throwable.getMessage());
-                LOG.trace("Statistics gathering for single node was not successful.. ", throwable);
+                LOG.warn("Statistics gathering for single node {} was not successful: {}", deviceInfo.getLOGValue(),
+                        throwable.getMessage());
+                if (LOG.isTraceEnabled()) {
+                    LOG.trace("Gathering for node {} failure: ", deviceInfo.getLOGValue(), throwable);
+                }
                 calculateTimerDelay(timeCounter);
-                if (throwable instanceof CancellationException) {
-                    /* This often happens when something wrong with akka or DS, so closing connection will help to restart device **/
-                    contexts.get(deviceInfo).getLifecycleService().closeConnection();
+                if (throwable instanceof IllegalStateException) {
+                    stopScheduling(deviceInfo);
                 } else {
                     scheduleNextPolling(deviceState, deviceInfo, statisticsContext, timeCounter);
                 }
@@ -138,23 +155,25 @@ public class StatisticsManagerImpl implements StatisticsManager, StatisticsManag
         });
 
         final long averageTime = TimeUnit.MILLISECONDS.toSeconds(timeCounter.getAverageTimeBetweenMarks());
-        final long STATS_TIMEOUT_SEC = averageTime > 0 ? 3 * averageTime : DEFAULT_STATS_TIMEOUT_SEC;
+        final long statsTimeoutSec = averageTime > 0 ? 3 * averageTime : DEFAULT_STATS_TIMEOUT_SEC;
         final TimerTask timerTask = timeout -> {
             if (!deviceStatisticsCollectionFuture.isDone()) {
-                LOG.info("Statistics collection for node {} still in progress even after {} secs", deviceInfo.getLOGValue(), STATS_TIMEOUT_SEC);
+                LOG.info("Statistics collection for node {} still in progress even after {} secs", deviceInfo.getLOGValue(), statsTimeoutSec);
                 deviceStatisticsCollectionFuture.cancel(true);
             }
         };
 
-        hashedWheelTimer.newTimeout(timerTask, STATS_TIMEOUT_SEC, TimeUnit.SECONDS);
+        hashedWheelTimer.newTimeout(timerTask, statsTimeoutSec, TimeUnit.SECONDS);
     }
 
     private void scheduleNextPolling(final DeviceState deviceState,
                                      final DeviceInfo deviceInfo,
                                      final StatisticsContext statisticsContext,
                                      final TimeCounter timeCounter) {
-        LOG.debug("SCHEDULING NEXT STATISTICS POLLING for device: {}", deviceInfo.getNodeId());
-        if (!isStatisticsPollingEnabled) {
+        if (LOG.isDebugEnabled()) {
+            LOG.debug("SCHEDULING NEXT STATISTICS POLLING for device: {}", deviceInfo.getNodeId());
+        }
+        if (!isStatisticsPollingOff) {
             final Timeout pollTimeout = hashedWheelTimer.newTimeout(
                     timeout -> pollStatistics(
                             deviceState,
@@ -213,15 +232,15 @@ public class StatisticsManagerImpl implements StatisticsManager, StatisticsManag
         if (workModeGuard.tryAcquire()) {
             final StatisticsWorkMode targetWorkMode = input.getMode();
             if (!workMode.equals(targetWorkMode)) {
-                isStatisticsPollingEnabled = StatisticsWorkMode.FULLYDISABLED.equals(targetWorkMode);
+                isStatisticsPollingOff = StatisticsWorkMode.FULLYDISABLED.equals(targetWorkMode);
                 // iterate through stats-ctx: propagate mode
                 for (Map.Entry<DeviceInfo, StatisticsContext> entry : contexts.entrySet()) {
                     final DeviceInfo deviceInfo = entry.getKey();
                     final StatisticsContext statisticsContext = entry.getValue();
-                    final DeviceContext deviceContext = statisticsContext.getLifecycleService().getDeviceContext();
+                    final DeviceContext deviceContext = statisticsContext.gainDeviceContext();
                     switch (targetWorkMode) {
                         case COLLECTALL:
-                            scheduleNextPolling(deviceContext.getDeviceState(), deviceInfo, statisticsContext, new TimeCounter());
+                            scheduleNextPolling(statisticsContext.gainDeviceState(), deviceInfo, statisticsContext, new TimeCounter());
                             for (final ItemLifeCycleSource lifeCycleSource : deviceContext.getItemLifeCycleSourceRegistry().getLifeCycleSources()) {
                                 lifeCycleSource.setItemLifecycleListener(null);
                             }
@@ -253,8 +272,8 @@ public class StatisticsManagerImpl implements StatisticsManager, StatisticsManag
 
     @Override
     public void startScheduling(final DeviceInfo deviceInfo) {
-        if (isStatisticsPollingEnabled) {
-            LOG.info("Statistics are shut down for device: {}", deviceInfo.getNodeId());
+        if (isStatisticsPollingOff) {
+            LOG.info("Statistics are shutdown for device: {}", deviceInfo.getNodeId());
             return;
         }
 
@@ -273,20 +292,25 @@ public class StatisticsManagerImpl implements StatisticsManager, StatisticsManag
         LOG.info("Scheduling statistics poll for device: {}", deviceInfo.getNodeId());
 
         statisticsContext.setSchedulingEnabled(true);
-        final DeviceState deviceState = contexts.get(deviceInfo).getLifecycleService().getDeviceContext().getDeviceState();
-        scheduleNextPolling(deviceState, deviceInfo, statisticsContext, new TimeCounter());
+        scheduleNextPolling(
+                statisticsContext.gainDeviceState(),
+                deviceInfo,
+                statisticsContext,
+                new TimeCounter()
+        );
     }
 
     @Override
     public void stopScheduling(final DeviceInfo deviceInfo) {
-        LOG.debug("Stopping statistics scheduling for device: {}", deviceInfo.getNodeId());
+        if (LOG.isDebugEnabled()) {
+            LOG.debug("Stopping statistics scheduling for device: {}", deviceInfo.getNodeId());
+        }
         final StatisticsContext statisticsContext = contexts.get(deviceInfo);
 
         if (statisticsContext == null) {
             LOG.warn("Statistics context not found for device: {}", deviceInfo.getNodeId());
             return;
         }
-
         statisticsContext.setSchedulingEnabled(false);
     }
 
@@ -307,4 +331,9 @@ public class StatisticsManagerImpl implements StatisticsManager, StatisticsManag
         this.deviceTerminPhaseHandler = handler;
     }
 
+    @Override
+    public void setIsStatisticsPollingOff(boolean isStatisticsPollingOff){
+        this.isStatisticsPollingOff = isStatisticsPollingOff;
+    }
+
 }