Fix SwitchIdleEvent echo request-reply xid
[openflowplugin.git] / openflowplugin-impl / src / main / java / org / opendaylight / openflowplugin / impl / connection / listener / SystemNotificationsListenerImpl.java
index d37777e33cfd8ece1628148e7eb060af57346698..5f7a8e9d04d1decb93e6ccbbf9fb7cdf6858ce7c 100644 (file)
@@ -7,16 +7,15 @@
  */
 package org.opendaylight.openflowplugin.impl.connection.listener;
 
-import org.opendaylight.openflowplugin.api.openflow.connection.HandshakeContext;
 import com.google.common.annotations.VisibleForTesting;
-import com.google.common.util.concurrent.FutureCallback;
-import com.google.common.util.concurrent.Futures;
-import com.google.common.util.concurrent.JdkFutureAdapters;
-import com.google.common.util.concurrent.ListenableFuture;
+import com.google.common.base.Preconditions;
 import java.net.InetSocketAddress;
+import java.util.Date;
+import java.util.Objects;
 import java.util.concurrent.Future;
+import java.util.concurrent.ThreadPoolExecutor;
 import java.util.concurrent.TimeUnit;
-import org.opendaylight.openflowjava.protocol.api.connection.ConnectionAdapter;
+import javax.annotation.Nonnull;
 import org.opendaylight.openflowplugin.api.openflow.connection.ConnectionContext;
 import org.opendaylight.openflowplugin.api.openflow.device.Xid;
 import org.opendaylight.yang.gen.v1.urn.opendaylight.openflow.protocol.rev130731.EchoInputBuilder;
@@ -35,119 +34,91 @@ import org.slf4j.LoggerFactory;
  */
 public class SystemNotificationsListenerImpl implements SystemNotificationsListener {
 
-    private ConnectionContext connectionContext;
-    HandshakeContext handshakeContext;
     private static final Logger LOG = LoggerFactory.getLogger(SystemNotificationsListenerImpl.class);
+    private static final Xid ECHO_XID = new Xid(0L);
+
+    private final ConnectionContext connectionContext;
     @VisibleForTesting
     static final long MAX_ECHO_REPLY_TIMEOUT = 2000;
+    private final long echoReplyTimeout;
+    private final ThreadPoolExecutor threadPool;
 
-    public SystemNotificationsListenerImpl(final ConnectionContext connectionContext, 
-            final HandshakeContext handshakeContext) {
-        this.connectionContext = connectionContext;
-        this.handshakeContext = handshakeContext;
+    public SystemNotificationsListenerImpl(@Nonnull final ConnectionContext connectionContext,
+                                           long echoReplyTimeout,
+                                           @Nonnull final ThreadPoolExecutor threadPool) {
+        this.threadPool = threadPool;
+        this.connectionContext = Preconditions.checkNotNull(connectionContext);
+        this.echoReplyTimeout = echoReplyTimeout;
     }
 
     @Override
-    public void onDisconnectEvent(DisconnectEvent notification) {
-        disconnect();
+    public void onDisconnectEvent(final DisconnectEvent notification) {
+        LOG.info("ConnectionEvent: Connection closed by device, Device:{}, NodeId:{}",
+                connectionContext.getConnectionAdapter().getRemoteAddress(), connectionContext.getSafeNodeIdForLOG());
+        connectionContext.onConnectionClosed();
     }
 
     @Override
-    public void onSwitchIdleEvent(SwitchIdleEvent notification) {
-        new Thread(new Runnable() {
-            @Override
-            public void run() {
-                boolean shouldBeDisconnected = true;
-
-                final InetSocketAddress remoteAddress = connectionContext.getConnectionAdapter().getRemoteAddress();
-
-                if (ConnectionContext.CONNECTION_STATE.WORKING.equals(connectionContext.getConnectionState())) {
-                    FeaturesReply features = connectionContext.getFeatures();
-                    LOG.debug(
-                            "first idle state occured, node={}|auxId={}",
-                            remoteAddress, features.getAuxiliaryId());
-                    connectionContext.setConnectionState(ConnectionContext.CONNECTION_STATE.TIMEOUTING);
-                    EchoInputBuilder builder = new EchoInputBuilder();
-                    builder.setVersion(features.getVersion());
-                    Xid xid = new Xid(0);
-                    builder.setXid(xid.getValue());
-
-                    Future<RpcResult<EchoOutput>> echoReplyFuture = connectionContext.getConnectionAdapter()
-                            .echo(builder.build());
-
-                    try {
-                        RpcResult<EchoOutput> echoReplyValue = echoReplyFuture.get(MAX_ECHO_REPLY_TIMEOUT, TimeUnit.MILLISECONDS);
-                        if (echoReplyValue.isSuccessful()) {
-                            connectionContext.setConnectionState(ConnectionContext.CONNECTION_STATE.WORKING);
-                            shouldBeDisconnected = false;
-                        } else {
-                            for (RpcError replyError : echoReplyValue
-                                    .getErrors()) {
-                                Throwable cause = replyError.getCause();
-                                LOG.warn("while receiving echoReply [{}] in TIMEOUTING state {} ",
-                                        remoteAddress,
-                                        cause.getMessage());
-                                LOG.trace("while receiving echoReply [{}] in TIMEOUTING state ..", remoteAddress, cause);
-                            }
-                        }
-                    } catch (Exception e) {
-                        LOG.warn("while waiting for echoReply in TIMEOUTING state: {}", e.getMessage());
-                        LOG.trace("while waiting for echoReply in TIMEOUTING state ..", remoteAddress, e);
-                    }
+    public void onSwitchIdleEvent(final SwitchIdleEvent notification) {
+        threadPool.execute(this::executeOnSwitchIdleEvent);
+    }
+
+    private void executeOnSwitchIdleEvent() {
+        boolean shouldBeDisconnected = true;
+
+        final InetSocketAddress remoteAddress = connectionContext.getConnectionAdapter().getRemoteAddress();
+
+        if (ConnectionContext.CONNECTION_STATE.WORKING.equals(connectionContext.getConnectionState())) {
+            FeaturesReply features = connectionContext.getFeatures();
+            LOG.info("Switch Idle state occurred, node={}|auxId={}", remoteAddress, features.getAuxiliaryId());
+            connectionContext.changeStateToTimeouting();
+            EchoInputBuilder builder = new EchoInputBuilder();
+            builder.setVersion(features.getVersion());
+            builder.setXid(ECHO_XID.getValue());
+
+            Future<RpcResult<EchoOutput>> echoReplyFuture = connectionContext.getConnectionAdapter().echo(builder.build());
+
+            try {
+                RpcResult<EchoOutput> echoReplyValue = echoReplyFuture.get(echoReplyTimeout, TimeUnit.MILLISECONDS);
+                if (echoReplyValue.isSuccessful() &&
+                        Objects.equals(echoReplyValue.getResult().getXid(), ECHO_XID.getValue())) {
+                    connectionContext.changeStateToWorking();
+                    shouldBeDisconnected = false;
+                } else {
+                    logErrors(remoteAddress, echoReplyValue);
                 }
-                if (shouldBeDisconnected) {
-                    disconnect();
+            } catch (Exception e) {
+                if (LOG.isWarnEnabled()) {
+                    LOG.warn("Exception while  waiting for echoReply from [{}] in TIMEOUTING state: {}", remoteAddress, e.getMessage());
+                }
+
+                if (LOG.isTraceEnabled()) {
+                    LOG.trace("Exception while  waiting for echoReply from [{}] in TIMEOUTING state: {}", remoteAddress, e);
                 }
-            }
-        }).start();
-    }
 
-    private void disconnect() {
-        final ConnectionAdapter connectionAdapter = connectionContext.getConnectionAdapter();
-        short auxId = -1;
-        if (null != connectionContext.getFeatures() && null != connectionContext.getFeatures().getAuxiliaryId()) {
-            auxId = connectionContext.getFeatures().getAuxiliaryId();
+            }
         }
-        final Short auxiliaryId = auxId;
-        final InetSocketAddress remoteAddress = connectionAdapter.getRemoteAddress();
-
-        LOG.trace("disconnecting: node={}|auxId={}|connection state = {}",
-                remoteAddress,
-                auxiliaryId,
-                connectionContext.getConnectionState());
-
-        ListenableFuture<Boolean> result = null;
-        if (connectionAdapter.isAlive()) {
-            result = JdkFutureAdapters.listenInPoolThread(connectionAdapter.disconnect());
-        } else {
-            LOG.debug("connection already disconnected");
-            result = Futures.immediateFuture(true);
+        if (shouldBeDisconnected) {
+            if (LOG.isInfoEnabled()) {
+                LOG.info("ConnectionEvent:Closing connection as device is idle. Echo sent at {}. Device:{}, NodeId:{}",
+                        new Date(System.currentTimeMillis() - echoReplyTimeout), remoteAddress, connectionContext.getSafeNodeIdForLOG());
+            }
+
+            connectionContext.closeConnection(true);
         }
-        connectionContext.setConnectionState(ConnectionContext.CONNECTION_STATE.RIP);
-        Futures.addCallback(result, new FutureCallback<Boolean>() {
-            @Override
-            public void onSuccess(final Boolean aBoolean) {
-                LOG.debug("Connection node={}|auxId={}|connection state = {}, closed successfully:{}.",
-                        remoteAddress,
-                        auxiliaryId,
-                        connectionContext.getConnectionState(),
-                        aBoolean);
+    }
+
+    private void logErrors(InetSocketAddress remoteAddress, RpcResult<EchoOutput> echoReplyValue) {
+        for (RpcError replyError : echoReplyValue.getErrors()) {
+            Throwable cause = replyError.getCause();
+            if (LOG.isWarnEnabled()) {
+                LOG.warn("Received EchoReply from [{}] in TIMEOUTING state, Error:{}", remoteAddress, cause.getMessage());
             }
 
-            @Override
-            public void onFailure(final Throwable throwable) {
-                LOG.debug("Connection node={}|auxId={}|connection state = {} close failed.",
-                        remoteAddress,
-                        auxiliaryId,
-                        connectionContext.getConnectionState());
+            if (LOG.isTraceEnabled()) {
+                LOG.trace("Received EchoReply from [{}] in TIMEOUTING state, Error:{}", remoteAddress, cause);
             }
-        });
 
-        connectionContext.propagateClosingConnection();
-        try {
-            handshakeContext.close();
-        } catch (Exception e) {
-            LOG.debug("Closing of handshake context wasn't successfull. {}", e);
         }
     }
 }