Merge "Fixed the log level."
[openflowplugin.git] / openflowplugin-impl / src / main / java / org / opendaylight / openflowplugin / impl / statistics / StatisticsManagerImpl.java
1 /*
2  * Copyright (c) 2015 Cisco Systems, Inc. and others.  All rights reserved.
3  *
4  * This program and the accompanying materials are made available under the
5  * terms of the Eclipse Public License v1.0 which accompanies this distribution,
6  * and is available at http://www.eclipse.org/legal/epl-v10.html
7  */
8
9 package org.opendaylight.openflowplugin.impl.statistics;
10
11 import com.google.common.annotations.VisibleForTesting;
12 import com.google.common.base.Preconditions;
13 import com.google.common.base.Verify;
14 import com.google.common.collect.Iterators;
15 import com.google.common.util.concurrent.FutureCallback;
16 import com.google.common.util.concurrent.Futures;
17 import com.google.common.util.concurrent.ListenableFuture;
18 import io.netty.util.Timeout;
19 import io.netty.util.TimerTask;
20 import java.util.Iterator;
21 import java.util.Map;
22 import java.util.Optional;
23 import java.util.concurrent.CancellationException;
24 import java.util.concurrent.ConcurrentHashMap;
25 import java.util.concurrent.ConcurrentMap;
26 import java.util.concurrent.Future;
27 import java.util.concurrent.Semaphore;
28 import java.util.concurrent.TimeUnit;
29 import javax.annotation.CheckForNull;
30 import javax.annotation.Nonnull;
31 import org.opendaylight.controller.sal.binding.api.BindingAwareBroker;
32 import org.opendaylight.controller.sal.binding.api.RpcProviderRegistry;
33 import org.opendaylight.openflowplugin.api.openflow.OFPContext;
34 import org.opendaylight.openflowplugin.api.openflow.device.DeviceContext;
35 import org.opendaylight.openflowplugin.api.openflow.device.DeviceInfo;
36 import org.opendaylight.openflowplugin.api.openflow.device.DeviceState;
37 import org.opendaylight.openflowplugin.api.openflow.device.handlers.DeviceInitializationPhaseHandler;
38 import org.opendaylight.openflowplugin.api.openflow.device.handlers.DeviceTerminationPhaseHandler;
39 import org.opendaylight.openflowplugin.api.openflow.lifecycle.LifecycleConductor;
40 import org.opendaylight.openflowplugin.api.openflow.rpc.ItemLifeCycleSource;
41 import org.opendaylight.openflowplugin.api.openflow.statistics.StatisticsContext;
42 import org.opendaylight.openflowplugin.api.openflow.statistics.StatisticsManager;
43 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.openflowplugin.sm.control.rev150812.ChangeStatisticsWorkModeInput;
44 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.openflowplugin.sm.control.rev150812.GetStatisticsWorkModeOutput;
45 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.openflowplugin.sm.control.rev150812.GetStatisticsWorkModeOutputBuilder;
46 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.openflowplugin.sm.control.rev150812.StatisticsManagerControlService;
47 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.openflowplugin.sm.control.rev150812.StatisticsWorkMode;
48 import org.opendaylight.yangtools.yang.common.RpcError;
49 import org.opendaylight.yangtools.yang.common.RpcResult;
50 import org.opendaylight.yangtools.yang.common.RpcResultBuilder;
51 import org.slf4j.Logger;
52 import org.slf4j.LoggerFactory;
53
54 public class StatisticsManagerImpl implements StatisticsManager, StatisticsManagerControlService {
55
56     private static final Logger LOG = LoggerFactory.getLogger(StatisticsManagerImpl.class);
57
58     private static final long DEFAULT_STATS_TIMEOUT_SEC = 50L;
59
60     private DeviceInitializationPhaseHandler deviceInitPhaseHandler;
61     private DeviceTerminationPhaseHandler deviceTerminPhaseHandler;
62
63     private final ConcurrentMap<DeviceInfo, StatisticsContext> contexts = new ConcurrentHashMap<>();
64
65     private static final long basicTimerDelay = 3000;
66     private static long currentTimerDelay = basicTimerDelay;
67     private static final long maximumTimerDelay = 900000; //wait max 15 minutes for next statistics
68
69     private StatisticsWorkMode workMode = StatisticsWorkMode.COLLECTALL;
70     private final Semaphore workModeGuard = new Semaphore(1, true);
71     private boolean shuttingDownStatisticsPolling;
72     private BindingAwareBroker.RpcRegistration<StatisticsManagerControlService> controlServiceRegistration;
73
74     private final LifecycleConductor conductor;
75
76     @Override
77     public void setDeviceInitializationPhaseHandler(final DeviceInitializationPhaseHandler handler) {
78         deviceInitPhaseHandler = handler;
79     }
80
81     public StatisticsManagerImpl(@CheckForNull final RpcProviderRegistry rpcProviderRegistry,
82                                  final boolean shuttingDownStatisticsPolling,
83                                  final LifecycleConductor lifecycleConductor) {
84         Preconditions.checkArgument(rpcProviderRegistry != null);
85         this.controlServiceRegistration = Preconditions.checkNotNull(rpcProviderRegistry.addRpcImplementation(
86                 StatisticsManagerControlService.class, this));
87         this.shuttingDownStatisticsPolling = shuttingDownStatisticsPolling;
88         this.conductor = lifecycleConductor;
89     }
90
91     @Override
92     public void onDeviceContextLevelUp(final DeviceInfo deviceInfo) throws Exception {
93
94         final DeviceContext deviceContext = Preconditions.checkNotNull(conductor.getDeviceContext(deviceInfo));
95
96         final StatisticsContext statisticsContext = new StatisticsContextImpl(deviceInfo, shuttingDownStatisticsPolling, conductor);
97         Verify.verify(contexts.putIfAbsent(deviceInfo, statisticsContext) == null, "StatisticsCtx still not closed for Node {}", deviceInfo.getNodeId());
98
99         deviceInitPhaseHandler.onDeviceContextLevelUp(deviceInfo);
100     }
101
102     @VisibleForTesting
103     void pollStatistics(final DeviceState deviceState,
104                         final StatisticsContext statisticsContext,
105                         final TimeCounter timeCounter,
106                         final DeviceInfo deviceInfo) {
107
108         if (!statisticsContext.isSchedulingEnabled()) {
109             LOG.debug("Disabling statistics scheduling for device: {}", deviceInfo.getNodeId());
110             return;
111         }
112         
113         if (!deviceState.isValid()) {
114             LOG.debug("Session is not valid for device: {}", deviceInfo.getNodeId());
115             return;
116         }
117
118         if (!deviceState.isStatisticsPollingEnabled()) {
119             LOG.debug("Statistics polling is currently disabled for device: {}", deviceInfo.getNodeId());
120             scheduleNextPolling(deviceState, deviceInfo, statisticsContext, timeCounter);
121             return;
122         }
123
124         LOG.debug("POLLING ALL STATISTICS for device: {}", deviceInfo.getNodeId());
125         timeCounter.markStart();
126         final ListenableFuture<Boolean> deviceStatisticsCollectionFuture = statisticsContext.gatherDynamicData();
127         Futures.addCallback(deviceStatisticsCollectionFuture, new FutureCallback<Boolean>() {
128             @Override
129             public void onSuccess(final Boolean o) {
130                 timeCounter.addTimeMark();
131                 calculateTimerDelay(timeCounter);
132                 scheduleNextPolling(deviceState, deviceInfo, statisticsContext, timeCounter);
133             }
134
135             @Override
136             public void onFailure(@Nonnull final Throwable throwable) {
137                 timeCounter.addTimeMark();
138                 LOG.warn("Statistics gathering for single node was not successful: {}", throwable.getMessage());
139                 LOG.trace("Statistics gathering for single node was not successful.. ", throwable);
140                 calculateTimerDelay(timeCounter);
141                 if (throwable instanceof CancellationException) {
142                     /** This often happens when something wrong with akka or DS, so closing connection will help to restart device **/
143                     conductor.closeConnection(deviceInfo);
144                 } else {
145                     scheduleNextPolling(deviceState, deviceInfo, statisticsContext, timeCounter);
146                 }
147             }
148         });
149
150         final long averageTime = TimeUnit.MILLISECONDS.toSeconds(timeCounter.getAverageTimeBetweenMarks());
151         final long STATS_TIMEOUT_SEC = averageTime > 0 ? 3 * averageTime : DEFAULT_STATS_TIMEOUT_SEC;
152         final TimerTask timerTask = timeout -> {
153             if (!deviceStatisticsCollectionFuture.isDone()) {
154                 LOG.info("Statistics collection for node {} still in progress even after {} secs", deviceInfo.getNodeId(), STATS_TIMEOUT_SEC);
155                 deviceStatisticsCollectionFuture.cancel(true);
156             }
157         };
158
159         conductor.newTimeout(timerTask, STATS_TIMEOUT_SEC, TimeUnit.SECONDS);
160     }
161
162     private void scheduleNextPolling(final DeviceState deviceState,
163                                      final DeviceInfo deviceInfo,
164                                      final StatisticsContext statisticsContext,
165                                      final TimeCounter timeCounter) {
166         LOG.debug("SCHEDULING NEXT STATISTICS POLLING for device: {}", deviceInfo.getNodeId());
167         if (!shuttingDownStatisticsPolling) {
168             final Timeout pollTimeout = conductor.newTimeout(timeout -> pollStatistics(deviceState, statisticsContext, timeCounter, deviceInfo), currentTimerDelay, TimeUnit.MILLISECONDS);
169             statisticsContext.setPollTimeout(pollTimeout);
170         }
171     }
172
173     @VisibleForTesting
174     void calculateTimerDelay(final TimeCounter timeCounter) {
175         final long averageStatisticsGatheringTime = timeCounter.getAverageTimeBetweenMarks();
176         if (averageStatisticsGatheringTime > currentTimerDelay) {
177             currentTimerDelay *= 2;
178             if (currentTimerDelay > maximumTimerDelay) {
179                 currentTimerDelay = maximumTimerDelay;
180             }
181         } else {
182             if (currentTimerDelay > basicTimerDelay) {
183                 currentTimerDelay /= 2;
184             } else {
185                 currentTimerDelay = basicTimerDelay;
186             }
187         }
188     }
189
190     @VisibleForTesting
191     static long getCurrentTimerDelay() {
192         return currentTimerDelay;
193     }
194
195     @Override
196     public void onDeviceContextLevelDown(final DeviceInfo deviceInfo) {
197         final StatisticsContext statisticsContext = contexts.remove(deviceInfo);
198         if (null != statisticsContext) {
199             LOG.trace("Removing device context from stack. No more statistics gathering for device: {}", deviceInfo.getNodeId());
200             statisticsContext.close();
201         }
202         deviceTerminPhaseHandler.onDeviceContextLevelDown(deviceInfo);
203     }
204
205     @Override
206     public Future<RpcResult<GetStatisticsWorkModeOutput>> getStatisticsWorkMode() {
207         final GetStatisticsWorkModeOutputBuilder smModeOutputBld = new GetStatisticsWorkModeOutputBuilder();
208         smModeOutputBld.setMode(workMode);
209         return RpcResultBuilder.success(smModeOutputBld.build()).buildFuture();
210     }
211
212     @Override
213     public Future<RpcResult<Void>> changeStatisticsWorkMode(ChangeStatisticsWorkModeInput input) {
214         final Future<RpcResult<Void>> result;
215         // acquire exclusive access
216         if (workModeGuard.tryAcquire()) {
217             final StatisticsWorkMode targetWorkMode = input.getMode();
218             if (!workMode.equals(targetWorkMode)) {
219                 shuttingDownStatisticsPolling = StatisticsWorkMode.FULLYDISABLED.equals(targetWorkMode);
220                 // iterate through stats-ctx: propagate mode
221                 for (Map.Entry<DeviceInfo, StatisticsContext> entry : contexts.entrySet()) {
222                     switch (targetWorkMode) {
223                         case COLLECTALL:
224                             scheduleNextPolling(conductor.getDeviceContext(entry.getKey()).getDeviceState(), entry.getKey(), entry.getValue(), new TimeCounter());
225                             for (final ItemLifeCycleSource lifeCycleSource : conductor.getDeviceContext(entry.getKey()).getItemLifeCycleSourceRegistry().getLifeCycleSources()) {
226                                 lifeCycleSource.setItemLifecycleListener(null);
227                             }
228                             break;
229                         case FULLYDISABLED:
230                             final Optional<Timeout> pollTimeout = entry.getValue().getPollTimeout();
231                             if (pollTimeout.isPresent()) {
232                                 pollTimeout.get().cancel();
233                             }
234                             for (final ItemLifeCycleSource lifeCycleSource : conductor.getDeviceContext(entry.getKey()).getItemLifeCycleSourceRegistry().getLifeCycleSources()) {
235                                 lifeCycleSource.setItemLifecycleListener(entry.getValue().getItemLifeCycleListener());
236                             }
237                             break;
238                         default:
239                             LOG.warn("Statistics work mode not supported: {}", targetWorkMode);
240                     }
241                 }
242                 workMode = targetWorkMode;
243             }
244             workModeGuard.release();
245             result = RpcResultBuilder.<Void>success().buildFuture();
246         } else {
247             result = RpcResultBuilder.<Void>failed()
248                     .withError(RpcError.ErrorType.APPLICATION, "mode change already in progress")
249                     .buildFuture();
250         }
251         return result;
252     }
253
254     @Override
255     public void startScheduling(final DeviceInfo deviceInfo) {
256         if (shuttingDownStatisticsPolling) {
257             LOG.info("Statistics are shut down for device: {}", deviceInfo.getNodeId());
258             return;
259         }
260
261         final StatisticsContext statisticsContext = contexts.get(deviceInfo);
262
263         if (statisticsContext == null) {
264             LOG.warn("Statistics context not found for device: {}", deviceInfo.getNodeId());
265             return;
266         }
267
268         if (statisticsContext.isSchedulingEnabled()) {
269             LOG.debug("Statistics scheduling is already enabled for device: {}", deviceInfo.getNodeId());
270             return;
271         }
272
273         LOG.info("Scheduling statistics poll for device: {}", deviceInfo.getNodeId());
274
275         statisticsContext.setSchedulingEnabled(true);
276         scheduleNextPolling(conductor.getDeviceContext(deviceInfo).getDeviceState(), deviceInfo, statisticsContext, new TimeCounter());
277     }
278
279     @Override
280     public void stopScheduling(final DeviceInfo deviceInfo) {
281         LOG.debug("Stopping statistics scheduling for device: {}", deviceInfo.getNodeId());
282         final StatisticsContext statisticsContext = contexts.get(deviceInfo);
283
284         if (statisticsContext == null) {
285             LOG.warn("Statistics context not found for device: {}", deviceInfo.getNodeId());
286             return;
287         }
288
289         statisticsContext.setSchedulingEnabled(false);
290     }
291
292     @Override
293     public void close() {
294         if (controlServiceRegistration != null) {
295             controlServiceRegistration.close();
296             controlServiceRegistration = null;
297         }
298         for (final Iterator<StatisticsContext> iterator = Iterators.consumingIterator(contexts.values().iterator());
299                 iterator.hasNext();) {
300             iterator.next().close();
301         }
302     }
303
304     @Override
305     public void setDeviceTerminationPhaseHandler(final DeviceTerminationPhaseHandler handler) {
306         this.deviceTerminPhaseHandler = handler;
307     }
308
309     @Override
310     public <T extends OFPContext> T gainContext(DeviceInfo deviceInfo) {
311         return (T) contexts.get(deviceInfo);
312     }
313 }