Merge "Bug 6110: Fixed bugs in statistics manager due to race condition." into stable...
[openflowplugin.git] / openflowplugin-impl / src / main / java / org / opendaylight / openflowplugin / impl / statistics / StatisticsManagerImpl.java
index 048957a5bb78e0933ddf64d5b84f3752402eb603..06dc64de2688f7183a14cf35543128e70912402d 100644 (file)
@@ -15,20 +15,33 @@ import com.google.common.collect.Iterators;
 import com.google.common.util.concurrent.FutureCallback;
 import com.google.common.util.concurrent.Futures;
 import com.google.common.util.concurrent.ListenableFuture;
+import io.netty.util.HashedWheelTimer;
 import io.netty.util.Timeout;
 import io.netty.util.TimerTask;
+import java.util.Iterator;
+import java.util.Map;
+import java.util.Optional;
+import java.util.concurrent.CancellationException;
+import java.util.concurrent.ConcurrentHashMap;
+import java.util.concurrent.ConcurrentMap;
+import java.util.concurrent.Future;
+import java.util.concurrent.Semaphore;
+import java.util.concurrent.TimeUnit;
+import javax.annotation.Nonnull;
 import org.opendaylight.controller.sal.binding.api.BindingAwareBroker;
 import org.opendaylight.controller.sal.binding.api.RpcProviderRegistry;
+import org.opendaylight.openflowplugin.api.ConnectionException;
 import org.opendaylight.openflowplugin.api.openflow.OFPContext;
 import org.opendaylight.openflowplugin.api.openflow.device.DeviceContext;
 import org.opendaylight.openflowplugin.api.openflow.device.DeviceInfo;
 import org.opendaylight.openflowplugin.api.openflow.device.DeviceState;
 import org.opendaylight.openflowplugin.api.openflow.device.handlers.DeviceInitializationPhaseHandler;
 import org.opendaylight.openflowplugin.api.openflow.device.handlers.DeviceTerminationPhaseHandler;
-import org.opendaylight.openflowplugin.api.openflow.lifecycle.LifecycleConductor;
+import org.opendaylight.openflowplugin.api.openflow.lifecycle.LifecycleService;
 import org.opendaylight.openflowplugin.api.openflow.rpc.ItemLifeCycleSource;
 import org.opendaylight.openflowplugin.api.openflow.statistics.StatisticsContext;
 import org.opendaylight.openflowplugin.api.openflow.statistics.StatisticsManager;
+import org.opendaylight.openflowplugin.openflow.md.core.sal.convertor.ConvertorExecutor;
 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.openflowplugin.sm.control.rev150812.ChangeStatisticsWorkModeInput;
 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.openflowplugin.sm.control.rev150812.GetStatisticsWorkModeOutput;
 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.openflowplugin.sm.control.rev150812.GetStatisticsWorkModeOutputBuilder;
@@ -40,64 +53,72 @@ import org.opendaylight.yangtools.yang.common.RpcResultBuilder;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
-import javax.annotation.CheckForNull;
-import javax.annotation.Nonnull;
-import java.util.Iterator;
-import java.util.Map;
-import java.util.Optional;
-import java.util.concurrent.CancellationException;
-import java.util.concurrent.ConcurrentHashMap;
-import java.util.concurrent.ConcurrentMap;
-import java.util.concurrent.Future;
-import java.util.concurrent.Semaphore;
-import java.util.concurrent.TimeUnit;
-
 public class StatisticsManagerImpl implements StatisticsManager, StatisticsManagerControlService {
 
     private static final Logger LOG = LoggerFactory.getLogger(StatisticsManagerImpl.class);
 
     private static final long DEFAULT_STATS_TIMEOUT_SEC = 50L;
+    private final ConvertorExecutor converterExecutor;
 
     private DeviceInitializationPhaseHandler deviceInitPhaseHandler;
-    private DeviceTerminationPhaseHandler deviceTerminPhaseHandler;
+    private DeviceTerminationPhaseHandler deviceTerminationPhaseHandler;
 
     private final ConcurrentMap<DeviceInfo, StatisticsContext> contexts = new ConcurrentHashMap<>();
 
-    private static final long basicTimerDelay = 3000;
-    private static long currentTimerDelay = basicTimerDelay;
-    private static final long maximumTimerDelay = 900000; //wait max 15 minutes for next statistics
+    private static long basicTimerDelay;
+    private static long currentTimerDelay;
+    private static long maximumTimerDelay; //wait time for next statistics
 
     private StatisticsWorkMode workMode = StatisticsWorkMode.COLLECTALL;
     private final Semaphore workModeGuard = new Semaphore(1, true);
-    private boolean shuttingDownStatisticsPolling;
+    private boolean isStatisticsPollingOn;
     private BindingAwareBroker.RpcRegistration<StatisticsManagerControlService> controlServiceRegistration;
 
-    private final LifecycleConductor conductor;
+    private final HashedWheelTimer hashedWheelTimer;
 
     @Override
     public void setDeviceInitializationPhaseHandler(final DeviceInitializationPhaseHandler handler) {
         deviceInitPhaseHandler = handler;
     }
 
-    public StatisticsManagerImpl(@CheckForNull final RpcProviderRegistry rpcProviderRegistry,
-                                 final boolean shuttingDownStatisticsPolling,
-                                 final LifecycleConductor lifecycleConductor) {
+    public StatisticsManagerImpl(final RpcProviderRegistry rpcProviderRegistry,
+                                 final boolean isStatisticsPollingOn,
+                                 final HashedWheelTimer hashedWheelTimer,
+                                 final ConvertorExecutor convertorExecutor,
+                                 final long basicTimerDelay,
+                                 final long maximumTimerDelay) {
         Preconditions.checkArgument(rpcProviderRegistry != null);
-        this.controlServiceRegistration = Preconditions.checkNotNull(rpcProviderRegistry.addRpcImplementation(
-                StatisticsManagerControlService.class, this));
-        this.shuttingDownStatisticsPolling = shuttingDownStatisticsPolling;
-        this.conductor = lifecycleConductor;
+           this.converterExecutor = convertorExecutor;
+        this.controlServiceRegistration = Preconditions.checkNotNull(
+                rpcProviderRegistry.addRpcImplementation(StatisticsManagerControlService.class, this)
+        );
+        this.isStatisticsPollingOn = isStatisticsPollingOn;
+        this.basicTimerDelay = basicTimerDelay;
+        this.currentTimerDelay = basicTimerDelay;
+        this.maximumTimerDelay = maximumTimerDelay;
+        this.hashedWheelTimer = hashedWheelTimer;
     }
 
     @Override
-    public void onDeviceContextLevelUp(final DeviceInfo deviceInfo) throws Exception {
-
-        final DeviceContext deviceContext = Preconditions.checkNotNull(conductor.getDeviceContext(deviceInfo));
-
-        final StatisticsContext statisticsContext = new StatisticsContextImpl(deviceInfo, shuttingDownStatisticsPolling, conductor);
-        Verify.verify(contexts.putIfAbsent(deviceInfo, statisticsContext) == null, "StatisticsCtx still not closed for Node {}", deviceInfo.getNodeId());
-
-        deviceInitPhaseHandler.onDeviceContextLevelUp(deviceInfo);
+    public void onDeviceContextLevelUp(final DeviceInfo deviceInfo,
+                                       final LifecycleService lifecycleService) throws Exception {
+
+        final StatisticsContext statisticsContext =
+                new StatisticsContextImpl(
+                        deviceInfo,
+                        isStatisticsPollingOn,
+                        lifecycleService,
+                        converterExecutor,
+                        this);
+
+        Verify.verify(
+                contexts.putIfAbsent(deviceInfo, statisticsContext) == null,
+                "StatisticsCtx still not closed for Node {}", deviceInfo.getLOGValue()
+        );
+
+        lifecycleService.setStatContext(statisticsContext);
+        lifecycleService.registerDeviceRemovedHandler(this);
+        deviceInitPhaseHandler.onDeviceContextLevelUp(deviceInfo, lifecycleService);
     }
 
     @VisibleForTesting
@@ -107,22 +128,16 @@ public class StatisticsManagerImpl implements StatisticsManager, StatisticsManag
                         final DeviceInfo deviceInfo) {
 
         if (!statisticsContext.isSchedulingEnabled()) {
-            LOG.debug("Disabling statistics scheduling for device: {}", deviceInfo.getNodeId());
-            return;
-        }
-        
-        if (!deviceState.isValid()) {
-            LOG.debug("Session is not valid for device: {}", deviceInfo.getNodeId());
+            if (LOG.isDebugEnabled()) {
+                LOG.debug("Disabled statistics scheduling for device: {}", deviceInfo.getNodeId().getValue());
+            }
             return;
         }
 
-        if (!deviceState.isStatisticsPollingEnabled()) {
-            LOG.debug("Statistics polling is currently disabled for device: {}", deviceInfo.getNodeId());
-            scheduleNextPolling(deviceState, deviceInfo, statisticsContext, timeCounter);
-            return;
+        if (LOG.isDebugEnabled()) {
+            LOG.debug("POLLING ALL STATISTICS for device: {}", deviceInfo.getNodeId());
         }
 
-        LOG.debug("POLLING ALL STATISTICS for device: {}", deviceInfo.getNodeId());
         timeCounter.markStart();
         final ListenableFuture<Boolean> deviceStatisticsCollectionFuture = statisticsContext.gatherDynamicData();
         Futures.addCallback(deviceStatisticsCollectionFuture, new FutureCallback<Boolean>() {
@@ -136,37 +151,57 @@ 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 **/
-                    conductor.closeConnection(deviceInfo);
+                if (throwable instanceof ConnectionException) {
+                    // ConnectionException is raised by StatisticsContextImpl class when the connections
+                    // move to RIP state. In this particular case, there is no need to reschedule
+                    // because this statistics manager should be closed soon
+                    LOG.warn("Node {} is no more connected, stopping the statistics collection",
+                            deviceInfo.getLOGValue(),throwable);
+                    stopScheduling(deviceInfo);
                 } else {
+                    if (!(throwable instanceof CancellationException)) {
+                        LOG.warn("Unexpected error occurred during statistics collection for node {}, rescheduling " +
+                                "statistics collections", deviceInfo.getLOGValue(),throwable);
+                    }
                     scheduleNextPolling(deviceState, deviceInfo, statisticsContext, timeCounter);
                 }
             }
         });
 
         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.getNodeId(), STATS_TIMEOUT_SEC);
+                LOG.info("Statistics collection for node {} still in progress even after {} secs", deviceInfo.getLOGValue(), statsTimeoutSec);
                 deviceStatisticsCollectionFuture.cancel(true);
             }
         };
 
-        conductor.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 (!shuttingDownStatisticsPolling) {
-            final Timeout pollTimeout = conductor.newTimeout(timeout -> pollStatistics(deviceState, statisticsContext, timeCounter, deviceInfo), currentTimerDelay, TimeUnit.MILLISECONDS);
+        if (LOG.isDebugEnabled()) {
+            LOG.debug("SCHEDULING NEXT STATISTICS POLLING for device: {}", deviceInfo.getNodeId());
+        }
+        if (isStatisticsPollingOn) {
+            final Timeout pollTimeout = hashedWheelTimer.newTimeout(
+                    timeout -> pollStatistics(
+                            deviceState,
+                            statisticsContext,
+                            timeCounter,
+                            deviceInfo),
+                    currentTimerDelay,
+                    TimeUnit.MILLISECONDS);
             statisticsContext.setPollTimeout(pollTimeout);
         }
     }
@@ -195,12 +230,8 @@ public class StatisticsManagerImpl implements StatisticsManager, StatisticsManag
 
     @Override
     public void onDeviceContextLevelDown(final DeviceInfo deviceInfo) {
-        final StatisticsContext statisticsContext = contexts.remove(deviceInfo);
-        if (null != statisticsContext) {
-            LOG.trace("Removing device context from stack. No more statistics gathering for device: {}", deviceInfo.getNodeId());
-            statisticsContext.close();
-        }
-        deviceTerminPhaseHandler.onDeviceContextLevelDown(deviceInfo);
+        Optional.ofNullable(contexts.get(deviceInfo)).ifPresent(OFPContext::close);
+        deviceTerminationPhaseHandler.onDeviceContextLevelDown(deviceInfo);
     }
 
     @Override
@@ -217,23 +248,26 @@ public class StatisticsManagerImpl implements StatisticsManager, StatisticsManag
         if (workModeGuard.tryAcquire()) {
             final StatisticsWorkMode targetWorkMode = input.getMode();
             if (!workMode.equals(targetWorkMode)) {
-                shuttingDownStatisticsPolling = StatisticsWorkMode.FULLYDISABLED.equals(targetWorkMode);
+                isStatisticsPollingOn = !(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.gainDeviceContext();
                     switch (targetWorkMode) {
                         case COLLECTALL:
-                            scheduleNextPolling(conductor.getDeviceContext(entry.getKey()).getDeviceState(), entry.getKey(), entry.getValue(), new TimeCounter());
-                            for (final ItemLifeCycleSource lifeCycleSource : conductor.getDeviceContext(entry.getKey()).getItemLifeCycleSourceRegistry().getLifeCycleSources()) {
+                            scheduleNextPolling(statisticsContext.gainDeviceState(), deviceInfo, statisticsContext, new TimeCounter());
+                            for (final ItemLifeCycleSource lifeCycleSource : deviceContext.getItemLifeCycleSourceRegistry().getLifeCycleSources()) {
                                 lifeCycleSource.setItemLifecycleListener(null);
                             }
                             break;
                         case FULLYDISABLED:
-                            final Optional<Timeout> pollTimeout = entry.getValue().getPollTimeout();
+                            final Optional<Timeout> pollTimeout = statisticsContext.getPollTimeout();
                             if (pollTimeout.isPresent()) {
                                 pollTimeout.get().cancel();
                             }
-                            for (final ItemLifeCycleSource lifeCycleSource : conductor.getDeviceContext(entry.getKey()).getItemLifeCycleSourceRegistry().getLifeCycleSources()) {
-                                lifeCycleSource.setItemLifecycleListener(entry.getValue().getItemLifeCycleListener());
+                            for (final ItemLifeCycleSource lifeCycleSource : deviceContext.getItemLifeCycleSourceRegistry().getLifeCycleSources()) {
+                                lifeCycleSource.setItemLifecycleListener(statisticsContext.getItemLifeCycleListener());
                             }
                             break;
                         default:
@@ -254,8 +288,8 @@ public class StatisticsManagerImpl implements StatisticsManager, StatisticsManag
 
     @Override
     public void startScheduling(final DeviceInfo deviceInfo) {
-        if (shuttingDownStatisticsPolling) {
-            LOG.info("Statistics are shut down for device: {}", deviceInfo.getNodeId());
+        if (!isStatisticsPollingOn) {
+            LOG.info("Statistics are shutdown for device: {}", deviceInfo.getNodeId());
             return;
         }
 
@@ -274,12 +308,20 @@ public class StatisticsManagerImpl implements StatisticsManager, StatisticsManag
         LOG.info("Scheduling statistics poll for device: {}", deviceInfo.getNodeId());
 
         statisticsContext.setSchedulingEnabled(true);
-        scheduleNextPolling(conductor.getDeviceContext(deviceInfo).getDeviceState(), 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) {
@@ -296,6 +338,7 @@ public class StatisticsManagerImpl implements StatisticsManager, StatisticsManag
             controlServiceRegistration.close();
             controlServiceRegistration = null;
         }
+
         for (final Iterator<StatisticsContext> iterator = Iterators.consumingIterator(contexts.values().iterator());
                 iterator.hasNext();) {
             iterator.next().close();
@@ -304,11 +347,26 @@ public class StatisticsManagerImpl implements StatisticsManager, StatisticsManag
 
     @Override
     public void setDeviceTerminationPhaseHandler(final DeviceTerminationPhaseHandler handler) {
-        this.deviceTerminPhaseHandler = handler;
+        this.deviceTerminationPhaseHandler = handler;
+    }
+
+    @Override
+    public void setIsStatisticsPollingOn(boolean isStatisticsPollingOn){
+        this.isStatisticsPollingOn = isStatisticsPollingOn;
+    }
+
+    public void onDeviceRemoved(DeviceInfo deviceInfo) {
+        contexts.remove(deviceInfo);
+        LOG.debug("Statistics context removed for node {}", deviceInfo.getLOGValue());
+    }
+
+    @Override
+    public void setBasicTimerDelay(final long basicTimerDelay) {
+        this.basicTimerDelay = basicTimerDelay;
     }
 
     @Override
-    public <T extends OFPContext> T gainContext(DeviceInfo deviceInfo) {
-        return (T) contexts.get(deviceInfo);
+    public void setMaximumTimerDelay(final long maximumTimerDelay) {
+        this.maximumTimerDelay = maximumTimerDelay;
     }
 }