Cleaned up "inactive channel" auth logic

* Cleaned up "inactive channel" auth logic.

- close and remove channel from queue on "inactive" notification
- set promise to failed if channel is inactive
- added cause to SecurityInfoNotReadyException
- add host, port, uri to timeout exception message

Author: connelly38

CHANGELOG.md

@@ -7,6 +7,7 @@ The format is based on [Keep a Changelog](http://keepachangelog.com/).
 ### Changed
 - Moved a couple internal log messages to FINE instead of INFO
 - Cleaned up messaging when can't connect to server
+- Modified internal auth logic to avoid "inactive channel: retrying" messages
 
 ## [5.4.11] 2023-06-06
 

driver/src/main/java/oracle/nosql/driver/RetryableException.java

@@ -22,6 +22,13 @@ protected RetryableException(String msg) {
         super(msg);
     }
 
+    /**
+     * @hidden
+     */
+    protected RetryableException(String msg, Throwable cause) {
+        super(msg, cause);
+    }
+
     @Override
     public boolean okToRetry() {
         return true;

driver/src/main/java/oracle/nosql/driver/SecurityInfoNotReadyException.java

@@ -21,4 +21,8 @@ public class SecurityInfoNotReadyException extends RetryableException {
     public SecurityInfoNotReadyException(String msg) {
         super(msg);
     }
+
+    public SecurityInfoNotReadyException(String msg, Throwable cause) {
+        super(msg, cause);
+    }
 }

driver/src/main/java/oracle/nosql/driver/httpclient/ConnectionPool.java

@@ -10,6 +10,7 @@
 import static oracle.nosql.driver.util.LogUtil.logFine;
 import static oracle.nosql.driver.util.LogUtil.logInfo;
 
+import java.io.IOException;
 import java.util.Map;
 import java.util.concurrent.ConcurrentHashMap;
 import java.util.concurrent.ConcurrentLinkedDeque;
@@ -237,6 +238,12 @@ public void operationComplete(
                         continue;
                     }
                 } else {
+                    /*
+                     * Note: run() may be executed some time after this method
+                     * returns a promise. So the caller may have to wait a
+                     * few milliseconds for the promise to be completed
+                     * (successfully or not).
+                     */
                     loop.execute(new Runnable() {
                             @Override
                             public void run() {
@@ -257,23 +264,32 @@ public void run() {
      * front of the queue. This class implements a LIFO algorithm to ensure
      * that the first, or first few channels on the queue remain active and
      * are not subject to inactivity timeouts from the server side.
+     * Note that inactive released channels will be closed and not
+     * re-added to the queue.
      */
     void release(Channel channel) {
         if (!channel.isActive()) {
             logFine(logger,
                     "Inactive channel on release, closing: " + channel);
             removeChannel(channel);
+        } else {
+            queue.addFirst(channel);
         }
         updateStats(channel, false);
-        queue.addFirst(channel);
         try { handler.channelReleased(channel); } catch (Exception e) {}
     }
 
     /**
-     * Closes and removes a channel from the pool entirely. This channel
-     * must not exist in the queue at this time
+     * Close and remove channel from pool.
+     * The channel may or may not currently be in the queue.
+     * This will normally only be called on channels that were acquired and
+     * found to be inactive or otherwise invalid, but it may also occasionally
+     * be called by an async netty callback when netty sees that a channel
+     * has been disconnected or become otherwise inactive. In the latter case,
+     * the channel is likely still in the queue and will be removed.
      */
-    private void removeChannel(Channel channel) {
+    public void removeChannel(Channel channel) {
+        queue.remove(channel);
         stats.remove(channel);
         channel.close();
     }
@@ -329,6 +345,7 @@ private boolean checkChannel(final Channel channel,
             logFine(logger,
                     "Inactive channel found, closing: " + channel);
             removeChannel(channel);
+            promise.tryFailure(new IOException("inactive channel"));
             return true;
         }
         try {
@@ -371,7 +388,6 @@ int pruneChannels() {
             if (!ch.isActive()) {
                 logFine(logger,
                         "Channel being pruned due to server close: " + ch);
-                queue.remove(ch);
                 removeChannel(ch);
                 pruned++;
             }

driver/src/main/java/oracle/nosql/driver/httpclient/HttpClient.java

@@ -282,11 +282,11 @@ SslContext getSslContext() {
         return sslCtx;
     }
 
-    int getPort() {
+    public int getPort() {
         return port;
     }
 
-    String getHost() {
+    public String getHost() {
         return host;
     }
 
@@ -446,6 +446,15 @@ public void releaseChannel(Channel channel) {
         pool.release(channel);
     }
 
+    /**
+     * Close and remove channel from client pool.
+     */
+    public void removeChannel(Channel channel) {
+        logFine(logger, "closing and removing channel " + channel);
+        pool.removeChannel(channel);
+    }
+
+
     /**
      * Sends an HttpRequest, setting up the ResponseHandler as the handler to
      * use for the (asynchronous) response.

driver/src/main/java/oracle/nosql/driver/httpclient/HttpClientChannelPoolHandler.java

@@ -153,6 +153,7 @@ public void channelInactive(ChannelHandlerContext ctx) {
             logFine(client.getLogger(),
                     "HttpClient " + client.getName() +
                     ", channel " + ctx.channel() + " inactive");
+            client.removeChannel(ctx.channel());
             ctx.fireChannelInactive();
         }
 

driver/src/main/java/oracle/nosql/driver/iam/SecurityTokenSupplier.java

@@ -232,7 +232,7 @@ private SecurityToken getSecurityTokenFromIAM() {
 
             return new SecurityToken(securityToken, keyPairSupplier);
         } catch (Exception e) {
-            throw new SecurityInfoNotReadyException(e.getMessage());
+            throw new SecurityInfoNotReadyException(e.getMessage(), e);
         }
     }
 

driver/src/main/java/oracle/nosql/driver/util/HttpRequestUtil.java

@@ -288,7 +288,10 @@ private static HttpResponse doRequest(HttpClient httpClient,
                 throw new RuntimeException(
                     "Unable to execute request: ", ee);
             } catch (TimeoutException te) {
-                throw new RuntimeException("Timeout exception: ", te);
+                throw new RuntimeException("Timeout exception: host=" +
+                                           httpClient.getHost() + " port=" +
+                                           httpClient.getPort() + " uri=" +
+                                           uri, te);
             } catch (Throwable t) {
                 /*
                  * this is likely an exception from Netty, perhaps a bad