Removes the gRPC channel if an exception occurs while instantiating the client

Includes also other minor changes to gRPC channel creation/connection
process, such as:
- More compact logs showing the gRPC client key
- GrpcChannelController.connectChannel() now returns the same
 StatusRuntime exception, no need to wrap it in an IOException
- Wait for channel shutdown after initial connection error

Change-Id: Ib7d2b728b8c82d9f9b2097cffcebd31cac891b27
diff --git a/drivers/p4runtime/src/main/java/org/onosproject/drivers/p4runtime/AbstractP4RuntimeHandlerBehaviour.java b/drivers/p4runtime/src/main/java/org/onosproject/drivers/p4runtime/AbstractP4RuntimeHandlerBehaviour.java
index 7f9c8c6..41c2b68 100644
--- a/drivers/p4runtime/src/main/java/org/onosproject/drivers/p4runtime/AbstractP4RuntimeHandlerBehaviour.java
+++ b/drivers/p4runtime/src/main/java/org/onosproject/drivers/p4runtime/AbstractP4RuntimeHandlerBehaviour.java
@@ -161,7 +161,7 @@
         final P4RuntimeClientKey clientKey = new P4RuntimeClientKey(
                 deviceId, serverAddr, serverPort, p4DeviceId);
         if (!controller.createClient(clientKey)) {
-            log.warn("Unable to create client for {}, aborting operation", deviceId);
+            log.debug("Unable to create client for {}, aborting operation", deviceId);
             return null;
         }
 
diff --git a/protocols/gnmi/api/src/main/java/org/onosproject/gnmi/api/GnmiClientKey.java b/protocols/gnmi/api/src/main/java/org/onosproject/gnmi/api/GnmiClientKey.java
index bc18b9a..137cbb8 100644
--- a/protocols/gnmi/api/src/main/java/org/onosproject/gnmi/api/GnmiClientKey.java
+++ b/protocols/gnmi/api/src/main/java/org/onosproject/gnmi/api/GnmiClientKey.java
@@ -26,7 +26,7 @@
 @Beta
 public class GnmiClientKey extends GrpcClientKey {
 
-    private static final String GNMI = "gnmi";
+    private static final String GNMI = "gNMI";
 
     /**
      * Creates a new gNMI client key.
diff --git a/protocols/grpc/api/src/main/java/org/onosproject/grpc/api/GrpcChannelController.java b/protocols/grpc/api/src/main/java/org/onosproject/grpc/api/GrpcChannelController.java
index 4775db5..fdd5980 100644
--- a/protocols/grpc/api/src/main/java/org/onosproject/grpc/api/GrpcChannelController.java
+++ b/protocols/grpc/api/src/main/java/org/onosproject/grpc/api/GrpcChannelController.java
@@ -19,9 +19,9 @@
 import com.google.common.annotations.Beta;
 import io.grpc.ManagedChannel;
 import io.grpc.ManagedChannelBuilder;
+import io.grpc.StatusRuntimeException;
 import org.onosproject.net.DeviceId;
 
-import java.io.IOException;
 import java.util.Collection;
 import java.util.Map;
 import java.util.Optional;
@@ -42,20 +42,19 @@
      * <p>
      * This method blocks until the channel is open or a timeout expires. By
      * default the timeout is {@link #CONNECTION_TIMEOUT_SECONDS} seconds. If
-     * the timeout expires, an {@link IOException} is thrown. If another channel
-     * with the same ID already exists, an {@link IllegalArgumentException} is
-     * thrown.
+     * the timeout expires, a {@link StatusRuntimeException} is thrown. If
+     * another channel with the same ID already exists, an {@link
+     * IllegalArgumentException} is thrown.
      *
      * @param channelId      ID of the channel
      * @param channelBuilder builder of the managed channel
      * @return the managed channel created
-     * @throws IOException              if the channel cannot be opened
+     * @throws StatusRuntimeException   if the channel cannot be opened
      * @throws IllegalArgumentException if a channel with the same ID already
      *                                  exists
      */
     ManagedChannel connectChannel(GrpcChannelId channelId,
-                                  ManagedChannelBuilder<?> channelBuilder)
-            throws IOException;
+                                  ManagedChannelBuilder<?> channelBuilder);
 
     /**
      * Closes the gRPC managed channel (i.e., disconnects from the gRPC server)
diff --git a/protocols/grpc/api/src/main/java/org/onosproject/grpc/api/GrpcClientKey.java b/protocols/grpc/api/src/main/java/org/onosproject/grpc/api/GrpcClientKey.java
index ad8a7da..99ea23f 100644
--- a/protocols/grpc/api/src/main/java/org/onosproject/grpc/api/GrpcClientKey.java
+++ b/protocols/grpc/api/src/main/java/org/onosproject/grpc/api/GrpcClientKey.java
@@ -17,12 +17,12 @@
 package org.onosproject.grpc.api;
 
 import com.google.common.annotations.Beta;
-import com.google.common.base.MoreObjects;
 import com.google.common.base.Objects;
 import org.onosproject.net.DeviceId;
 
 import static com.google.common.base.Preconditions.checkArgument;
 import static com.google.common.base.Preconditions.checkNotNull;
+import static java.lang.String.format;
 
 /**
  * Key that uniquely identifies a gRPC client.
@@ -113,16 +113,8 @@
         return Objects.hashCode(serviceName, deviceId, serverAddr, serverPort);
     }
 
-    protected MoreObjects.ToStringHelper toStringHelper() {
-        return MoreObjects.toStringHelper(this)
-                .add("serviceName", serviceName)
-                .add("deviceId", deviceId)
-                .add("serverAddr", serverAddr)
-                .add("serverPort", serverPort);
-    }
-
     @Override
     public String toString() {
-        return toStringHelper().toString();
+        return format("%s/%s@%s:%s", deviceId, serviceName, serverAddr, serverPort);
     }
-}
\ No newline at end of file
+}
diff --git a/protocols/grpc/ctl/src/main/java/org/onosproject/grpc/ctl/AbstractGrpcClientController.java b/protocols/grpc/ctl/src/main/java/org/onosproject/grpc/ctl/AbstractGrpcClientController.java
index db29284..4f0403a 100644
--- a/protocols/grpc/ctl/src/main/java/org/onosproject/grpc/ctl/AbstractGrpcClientController.java
+++ b/protocols/grpc/ctl/src/main/java/org/onosproject/grpc/ctl/AbstractGrpcClientController.java
@@ -19,6 +19,7 @@
 import com.google.common.collect.Maps;
 import com.google.common.util.concurrent.Striped;
 import io.grpc.ManagedChannel;
+import io.grpc.StatusRuntimeException;
 import io.grpc.netty.GrpcSslContexts;
 import io.grpc.netty.NettyChannelBuilder;
 import io.netty.handler.ssl.NotSslRecordException;
@@ -40,13 +41,12 @@
 import org.slf4j.Logger;
 
 import javax.net.ssl.SSLException;
-import java.io.IOException;
 import java.util.Map;
 import java.util.concurrent.locks.Lock;
 import java.util.function.Supplier;
 
 import static com.google.common.base.Preconditions.checkNotNull;
-import static com.google.common.base.Preconditions.checkState;
+import static java.lang.String.format;
 import static org.slf4j.LoggerFactory.getLogger;
 
 /**
@@ -105,82 +105,103 @@
     }
 
     private boolean doCreateClient(K clientKey, boolean useTls, boolean fallbackToPlainText) {
-        DeviceId deviceId = clientKey.deviceId();
-        String serverAddr = clientKey.serverAddr();
-        int serverPort = clientKey.serverPort();
+        final DeviceId deviceId = clientKey.deviceId();
+        final String serverAddr = clientKey.serverAddr();
+        final int serverPort = clientKey.serverPort();
 
         if (clientKeys.containsKey(deviceId)) {
             final GrpcClientKey existingKey = clientKeys.get(deviceId);
             if (clientKey.equals(existingKey)) {
-                log.debug("Not creating client for {} as it already exists (key={})...",
-                        deviceId, clientKey);
+                log.debug("Not creating {} as it already exists... (key={})",
+                          clientName(clientKey), clientKey);
                 return true;
             } else {
-                log.info("Requested client for {} with new " +
-                                "endpoint, removing old client (key={})...",
-                        deviceId, clientKey);
+                log.info("Requested new {} with updated key, removing old client... (oldKey={})",
+                         clientName(clientKey), existingKey);
                 doRemoveClient(deviceId);
             }
         }
-        log.info("Creating client for {} (server={}:{})...", deviceId, serverAddr, serverPort);
 
-        SslContext sslContext = null;
-        if (useTls) {
-            try {
-                // Accept any server certificate; this is insecure and should not be used in production
-                sslContext = GrpcSslContexts.forClient().trustManager(InsecureTrustManagerFactory.INSTANCE).build();
-            } catch (SSLException e) {
-                log.error("Failed to build SSL Context", e);
-                return false;
-            }
-        }
+        log.info("Creating new {}... (key={}, useTls={}, fallbackToPlainText={})",
+                 clientName(clientKey), clientKey, useTls,
+                 fallbackToPlainText);
 
-        GrpcChannelId channelId = GrpcChannelId.of(clientKey.deviceId(), clientKey.toString());
-        NettyChannelBuilder channelBuilder = NettyChannelBuilder
+        final GrpcChannelId channelId = GrpcChannelId.of(
+                clientKey.deviceId(), clientKey.toString());
+        final NettyChannelBuilder channelBuilder = NettyChannelBuilder
                 .forAddress(serverAddr, serverPort)
                 .maxInboundMessageSize(DEFAULT_MAX_INBOUND_MSG_SIZE * MEGABYTES);
-        if (sslContext != null) {
-            log.debug("Using SSL for gRPC connection to {}", deviceId);
+
+        if (useTls) {
+            // FIXME: logic to create/manage SSL properties of a channel builder
+            //  should belong to the GrpcChannelController.
+            log.debug("Using SSL for {}", clientName(clientKey), deviceId);
+            final SslContext sslContext;
+            try {
+                // Accept any server certificate; this is insecure and should
+                // not be used in production
+                sslContext = GrpcSslContexts.forClient()
+                        .trustManager(InsecureTrustManagerFactory.INSTANCE)
+                        .build();
+            } catch (SSLException e) {
+                log.error("Failed to build SSL context for {}", clientName(clientKey), e);
+                return false;
+            }
             channelBuilder
                     .sslContext(sslContext)
                     .useTransportSecurity();
         } else {
-            checkState(!useTls,
-                    "Not authorized to use plaintext for gRPC connection to {}", deviceId);
-            log.debug("Using plaintext TCP for gRPC connection to {}", deviceId);
+            log.debug("Using plaintext TCP for {}", clientName(clientKey));
             channelBuilder.usePlaintext();
         }
 
-        ManagedChannel channel;
+        final ManagedChannel channel;
         try {
             channel = grpcChannelController.connectChannel(channelId, channelBuilder);
-        } catch (IOException e) {
+        } catch (Throwable e) {
             for (Throwable cause = e; cause != null; cause = cause.getCause()) {
                 if (useTls && cause instanceof NotSslRecordException) {
                     // Likely root cause is that server is using plaintext
-                    log.info("Failed to connect to server (device={}) using TLS", deviceId);
+                    log.warn("Failed to connect {} using TLS", clientName(clientKey));
                     log.debug("TLS connection exception", e);
                     if (fallbackToPlainText) {
-                        log.info("Falling back to plaintext for connection to {}", deviceId);
+                        log.info("Falling back to plaintext TCP for {}", clientName(clientKey));
                         return doCreateClient(clientKey, false, false);
                     }
                 }
                 if (!useTls && "Connection reset by peer".equals(cause.getMessage())) {
                     // Not a great signal, but could indicate the server is expected a TLS connection
-                    log.error("Failed to connect to server (device={}) using plaintext TCP; is the server using TLS?",
-                            deviceId);
+                    log.warn("Failed to connect {} using plaintext TCP; " +
+                                     "is the server using TLS?",
+                             clientName(clientKey));
                     break;
                 }
             }
-            log.warn("Unable to connect to gRPC server for {}", deviceId, e);
+            if (e instanceof StatusRuntimeException) {
+                log.warn("Unable to connect {}: {}", clientName(clientKey), e.getMessage());
+                log.debug("Connection exception", e);
+            } else {
+                log.error("Exception while connecting {}", clientName(clientKey), e);
+            }
             return false;
         }
 
-        C client = createClientInstance(clientKey, channel);
-        if (client == null) {
-            log.warn("Cannot create client for {} (key={})", deviceId, clientKey);
+        final C client;
+        try {
+            client = createClientInstance(clientKey, channel);
+        } catch (Throwable e) {
+            log.error("Exception while creating {}", clientName(clientKey), e);
+            grpcChannelController.disconnectChannel(channelId);
             return false;
         }
+
+        if (client == null) {
+            log.error("Unable to create {}, implementation returned null... (key={})",
+                      clientName(clientKey), clientKey);
+            grpcChannelController.disconnectChannel(channelId);
+            return false;
+        }
+
         clientKeys.put(deviceId, clientKey);
         clients.put(clientKey, client);
         channelIds.put(deviceId, channelId);
@@ -231,7 +252,7 @@
         // Default behaviour checks only the gRPC channel, should
         // check according to different gRPC service
         if (!clientKeys.containsKey(deviceId)) {
-            log.debug("No client for {}, can't check for reachability", deviceId);
+            log.debug("Missing client for {}, cannot check for reachability", deviceId);
             return false;
         }
         return grpcChannelController.isChannelOpen(channelIds.get(deviceId));
@@ -246,4 +267,8 @@
             lock.unlock();
         }
     }
+
+    private String clientName(GrpcClientKey key) {
+        return format("%s client for %s", key.serviceName(), key.deviceId());
+    }
 }
diff --git a/protocols/grpc/ctl/src/main/java/org/onosproject/grpc/ctl/GrpcChannelControllerImpl.java b/protocols/grpc/ctl/src/main/java/org/onosproject/grpc/ctl/GrpcChannelControllerImpl.java
index 7b9290e..4ad3166 100644
--- a/protocols/grpc/ctl/src/main/java/org/onosproject/grpc/ctl/GrpcChannelControllerImpl.java
+++ b/protocols/grpc/ctl/src/main/java/org/onosproject/grpc/ctl/GrpcChannelControllerImpl.java
@@ -48,7 +48,6 @@
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
-import java.io.IOException;
 import java.util.Collection;
 import java.util.Dictionary;
 import java.util.HashSet;
@@ -115,8 +114,7 @@
 
     @Override
     public ManagedChannel connectChannel(GrpcChannelId channelId,
-                                         ManagedChannelBuilder<?> channelBuilder)
-            throws IOException {
+                                         ManagedChannelBuilder<?> channelBuilder) {
         checkNotNull(channelId);
         checkNotNull(channelBuilder);
 
@@ -137,8 +135,8 @@
             try {
                 doDummyMessage(channel);
             } catch (StatusRuntimeException e) {
-                channel.shutdownNow();
-                throw new IOException(e);
+                shutdownNowAndWait(channel, channelId);
+                throw e;
             }
             // If here, channel is open.
             channels.put(channelId, channel);
@@ -199,27 +197,28 @@
         lock.lock();
         try {
             final ManagedChannel channel = channels.remove(channelId);
-            if (channel == null) {
-                // Nothing to do.
-                return;
-            }
-
-            try {
-                if (!channel.shutdownNow()
-                        .awaitTermination(5, TimeUnit.SECONDS)) {
-                    log.error("Channel '{}' didn't terminate, although we " +
-                                      "triggered a shut down and waited",
-                              channelId);
-                }
-            } catch (InterruptedException e) {
-                log.warn("Channel {} didn't shut down in time", channelId);
-                Thread.currentThread().interrupt();
+            if (channel != null) {
+                shutdownNowAndWait(channel, channelId);
             }
         } finally {
             lock.unlock();
         }
     }
 
+    private void shutdownNowAndWait(ManagedChannel channel, GrpcChannelId channelId) {
+        try {
+            if (!channel.shutdownNow()
+                    .awaitTermination(5, TimeUnit.SECONDS)) {
+                log.error("Channel '{}' didn't terminate, although we " +
+                                  "triggered a shutdown and waited",
+                          channelId);
+            }
+        } catch (InterruptedException e) {
+            log.warn("Channel {} didn't shutdown in time", channelId);
+            Thread.currentThread().interrupt();
+        }
+    }
+
     @Override
     public Map<GrpcChannelId, ManagedChannel> getChannels() {
         return ImmutableMap.copyOf(channels);
diff --git a/protocols/p4runtime/api/src/main/java/org/onosproject/p4runtime/api/P4RuntimeClientKey.java b/protocols/p4runtime/api/src/main/java/org/onosproject/p4runtime/api/P4RuntimeClientKey.java
index 70bf33c..4c23bbc 100644
--- a/protocols/p4runtime/api/src/main/java/org/onosproject/p4runtime/api/P4RuntimeClientKey.java
+++ b/protocols/p4runtime/api/src/main/java/org/onosproject/p4runtime/api/P4RuntimeClientKey.java
@@ -27,7 +27,7 @@
  */
 @Beta
 public final class P4RuntimeClientKey extends GrpcClientKey {
-    private static final String P4R_SERVICE_NAME = "p4runtime";
+    private static final String P4RUNTIME = "P4Runtime";
     private final long p4DeviceId;
 
     /**
@@ -40,7 +40,7 @@
      */
     public P4RuntimeClientKey(DeviceId deviceId, String serverAddr,
                               int serverPort, long p4DeviceId) {
-        super(P4R_SERVICE_NAME, deviceId, serverAddr, serverPort);
+        super(P4RUNTIME, deviceId, serverAddr, serverPort);
         this.p4DeviceId = p4DeviceId;
     }
 
@@ -75,8 +75,6 @@
 
     @Override
     public String toString() {
-        return super.toStringHelper()
-                .add("p4DeviceId", p4DeviceId)
-                .toString();
+        return super.toString() + "/" + p4DeviceId;
     }
 }
diff --git a/providers/general/device/src/main/java/org/onosproject/provider/general/device/impl/GeneralDeviceProvider.java b/providers/general/device/src/main/java/org/onosproject/provider/general/device/impl/GeneralDeviceProvider.java
index bbf71f2..1eaa808 100644
--- a/providers/general/device/src/main/java/org/onosproject/provider/general/device/impl/GeneralDeviceProvider.java
+++ b/providers/general/device/src/main/java/org/onosproject/provider/general/device/impl/GeneralDeviceProvider.java
@@ -501,9 +501,9 @@
                 (description.isDefaultAvailable() &&
                         !deviceService.isAvailable(deviceId))) {
             if (!isPipelineReady) {
-                log.info("Advertising device to core with available={} as " +
+                log.info("Advertising device {} to core with available={} as " +
                                  "device pipeline is not ready yet",
-                         description.isDefaultAvailable());
+                         deviceId, description.isDefaultAvailable());
             }
             providerService.deviceConnected(deviceId, description);
         }