Add information about nio channels in logs (#26806)

Currently we only log generic messages about errors in logs from the
nio event handler. This means that we do not know which channel had
issues connection, reading, writing, etc.

This commit changes the logs to include the local and remote addresses
and profile for a channel.

test/framework/src/main/java/org/elasticsearch/transport/nio/AcceptorEventHandler.java

@@ -20,6 +20,7 @@
 package org.elasticsearch.transport.nio;
 
 import org.apache.logging.log4j.Logger;
+import org.apache.logging.log4j.message.ParameterizedMessage;
 import org.elasticsearch.transport.nio.channel.ChannelFactory;
 import org.elasticsearch.transport.nio.channel.NioServerSocketChannel;
 import org.elasticsearch.transport.nio.channel.NioSocketChannel;
@@ -48,7 +49,7 @@ public AcceptorEventHandler(Logger logger, OpenChannels openChannels, Supplier<S
      *
      * @param nioServerSocketChannel that was registered
      */
-    public void serverChannelRegistered(NioServerSocketChannel nioServerSocketChannel) {
+    void serverChannelRegistered(NioServerSocketChannel nioServerSocketChannel) {
         SelectionKeyUtils.setAcceptInterested(nioServerSocketChannel);
         openChannels.serverChannelOpened(nioServerSocketChannel);
     }
@@ -59,8 +60,8 @@ public void serverChannelRegistered(NioServerSocketChannel nioServerSocketChanne
      * @param channel that was registered
      * @param exception that occurred
      */
-    public void registrationException(NioServerSocketChannel channel, Exception exception) {
-        logger.error("failed to register server channel", exception);
+    void registrationException(NioServerSocketChannel channel, Exception exception) {
+        logger.error(new ParameterizedMessage("failed to register server channel: {}", channel), exception);
     }
 
     /**
@@ -69,7 +70,7 @@ public void registrationException(NioServerSocketChannel channel, Exception exce
      *
      * @param nioServerChannel that can accept a connection
      */
-    public void acceptChannel(NioServerSocketChannel nioServerChannel) throws IOException {
+    void acceptChannel(NioServerSocketChannel nioServerChannel) throws IOException {
         ChannelFactory channelFactory = nioServerChannel.getChannelFactory();
         SocketSelector selector = selectorSupplier.get();
         NioSocketChannel nioSocketChannel = channelFactory.acceptNioChannel(nioServerChannel, selector, openChannels::channelClosed);
@@ -82,8 +83,9 @@ public void acceptChannel(NioServerSocketChannel nioServerChannel) throws IOExce
      * @param nioServerChannel that accepting a connection
      * @param exception that occurred
      */
-    public void acceptException(NioServerSocketChannel nioServerChannel, Exception exception) {
-        logger.debug("exception while accepting new channel", exception);
+    void acceptException(NioServerSocketChannel nioServerChannel, Exception exception) {
+        logger.debug(() -> new ParameterizedMessage("exception while accepting new channel from server channel: {}",
+            nioServerChannel), exception);
     }
 
     /**
@@ -94,7 +96,7 @@ public void acceptException(NioServerSocketChannel nioServerChannel, Exception e
      * @param channel that caused the exception
      * @param exception that was thrown
      */
-    public void genericServerChannelException(NioServerSocketChannel channel, Exception exception) {
-        logger.debug("event handling exception", exception);
+    void genericServerChannelException(NioServerSocketChannel channel, Exception exception) {
+        logger.debug(() -> new ParameterizedMessage("exception while handling event for server channel: {}", channel), exception);
     }
 }

test/framework/src/main/java/org/elasticsearch/transport/nio/EventHandler.java

@@ -20,9 +20,9 @@
 package org.elasticsearch.transport.nio;
 
 import org.apache.logging.log4j.Logger;
+import org.apache.logging.log4j.message.ParameterizedMessage;
 import org.elasticsearch.transport.nio.channel.CloseFuture;
 import org.elasticsearch.transport.nio.channel.NioChannel;
-import org.elasticsearch.transport.nio.channel.NioSocketChannel;
 
 import java.io.IOException;
 import java.nio.channels.Selector;
@@ -31,7 +31,7 @@ public abstract class EventHandler {
 
     protected final Logger logger;
 
-    public EventHandler(Logger logger) {
+    EventHandler(Logger logger) {
         this.logger = logger;
     }
 
@@ -40,25 +40,26 @@ public EventHandler(Logger logger) {
      *
      * @param exception the exception
      */
-    public void selectException(IOException exception) {
-        logger.warn("io exception during select", exception);
+    void selectException(IOException exception) {
+        logger.warn(new ParameterizedMessage("io exception during select [thread={}]", Thread.currentThread().getName()), exception);
     }
 
     /**
      * This method handles an IOException that was thrown during a call to {@link Selector#close()}.
      *
      * @param exception the exception
      */
-    public void closeSelectorException(IOException exception) {
-        logger.warn("io exception while closing selector", exception);
+    void closeSelectorException(IOException exception) {
+        logger.warn(new ParameterizedMessage("io exception while closing selector [thread={}]", Thread.currentThread().getName()),
+            exception);
     }
 
     /**
      * This method handles an exception that was uncaught during a select loop.
      *
      * @param exception that was uncaught
      */
-    public void uncaughtException(Exception exception) {
+    void uncaughtException(Exception exception) {
         Thread thread = Thread.currentThread();
         thread.getUncaughtExceptionHandler().uncaughtException(thread, exception);
     }
@@ -68,13 +69,23 @@ public void uncaughtException(Exception exception) {
      *
      * @param channel that should be closed
      */
-    public void handleClose(NioChannel channel) {
+    void handleClose(NioChannel channel) {
         channel.closeFromSelector();
         CloseFuture closeFuture = channel.getCloseFuture();
         assert closeFuture.isDone() : "Should always be done as we are on the selector thread";
         IOException closeException = closeFuture.getCloseException();
         if (closeException != null) {
-            logger.debug("exception while closing channel", closeException);
+            closeException(channel, closeException);
         }
     }
+
+    /**
+     * This method is called when an attempt to close a channel throws an exception.
+     *
+     * @param channel that was being closed
+     * @param exception that occurred
+     */
+    void closeException(NioChannel channel, Exception exception) {
+        logger.debug(() -> new ParameterizedMessage("exception while closing channel: {}", channel), exception);
+    }
 }

test/framework/src/main/java/org/elasticsearch/transport/nio/SocketEventHandler.java

@@ -20,6 +20,7 @@
 package org.elasticsearch.transport.nio;
 
 import org.apache.logging.log4j.Logger;
+import org.apache.logging.log4j.message.ParameterizedMessage;
 import org.elasticsearch.transport.nio.channel.NioSocketChannel;
 import org.elasticsearch.transport.nio.channel.SelectionKeyUtils;
 import org.elasticsearch.transport.nio.channel.WriteContext;
@@ -47,7 +48,7 @@ public SocketEventHandler(Logger logger, BiConsumer<NioSocketChannel, Throwable>
      *
      * @param channel that was registered
      */
-    public void handleRegistration(NioSocketChannel channel) {
+    void handleRegistration(NioSocketChannel channel) {
         SelectionKeyUtils.setConnectAndReadInterested(channel);
     }
 
@@ -57,8 +58,8 @@ public void handleRegistration(NioSocketChannel channel) {
      * @param channel that was registered
      * @param exception that occurred
      */
-    public void registrationException(NioSocketChannel channel, Exception exception) {
-        logger.trace("failed to register channel", exception);
+    void registrationException(NioSocketChannel channel, Exception exception) {
+        logger.debug(() -> new ParameterizedMessage("failed to register socket channel: {}", channel), exception);
         exceptionCaught(channel, exception);
     }
 
@@ -68,7 +69,7 @@ public void registrationException(NioSocketChannel channel, Exception exception)
      *
      * @param channel that was registered
      */
-    public void handleConnect(NioSocketChannel channel) {
+    void handleConnect(NioSocketChannel channel) {
         SelectionKeyUtils.removeConnectInterested(channel);
     }
 
@@ -78,8 +79,8 @@ public void handleConnect(NioSocketChannel channel) {
      * @param channel that was connecting
      * @param exception that occurred
      */
-    public void connectException(NioSocketChannel channel, Exception exception) {
-        logger.trace("failed to connect to channel", exception);
+    void connectException(NioSocketChannel channel, Exception exception) {
+        logger.debug(() -> new ParameterizedMessage("failed to connect to socket channel: {}", channel), exception);
         exceptionCaught(channel, exception);
 
     }
@@ -90,7 +91,7 @@ public void connectException(NioSocketChannel channel, Exception exception) {
      *
      * @param channel that can be read
      */
-    public void handleRead(NioSocketChannel channel) throws IOException {
+    void handleRead(NioSocketChannel channel) throws IOException {
         int bytesRead = channel.getReadContext().read();
         if (bytesRead == -1) {
             handleClose(channel);
@@ -103,8 +104,8 @@ public void handleRead(NioSocketChannel channel) throws IOException {
      * @param channel that was being read
      * @param exception that occurred
      */
-    public void readException(NioSocketChannel channel, Exception exception) {
-        logger.trace("failed to read from channel", exception);
+    void readException(NioSocketChannel channel, Exception exception) {
+        logger.debug(() -> new ParameterizedMessage("exception while reading from socket channel: {}", channel), exception);
         exceptionCaught(channel, exception);
     }
 
@@ -114,7 +115,7 @@ public void readException(NioSocketChannel channel, Exception exception) {
      *
      * @param channel that can be read
      */
-    public void handleWrite(NioSocketChannel channel) throws IOException {
+    void handleWrite(NioSocketChannel channel) throws IOException {
         WriteContext channelContext = channel.getWriteContext();
         channelContext.flushChannel();
         if (channelContext.hasQueuedWriteOps()) {
@@ -130,8 +131,8 @@ public void handleWrite(NioSocketChannel channel) throws IOException {
      * @param channel that was being written to
      * @param exception that occurred
      */
-    public void writeException(NioSocketChannel channel, Exception exception) {
-        logger.trace("failed to write to channel", exception);
+    void writeException(NioSocketChannel channel, Exception exception) {
+        logger.debug(() -> new ParameterizedMessage("exception while writing to socket channel: {}", channel), exception);
         exceptionCaught(channel, exception);
     }
 
@@ -143,8 +144,8 @@ public void writeException(NioSocketChannel channel, Exception exception) {
      * @param channel that caused the exception
      * @param exception that was thrown
      */
-    public void genericChannelException(NioSocketChannel channel, Exception exception) {
-        logger.trace("event handling failed", exception);
+    void genericChannelException(NioSocketChannel channel, Exception exception) {
+        logger.debug(() -> new ParameterizedMessage("exception while handling event for socket channel: {}", channel), exception);
         exceptionCaught(channel, exception);
     }
 

test/framework/src/main/java/org/elasticsearch/transport/nio/channel/AbstractNioChannel.java

@@ -162,5 +162,4 @@ void setSelectionKey(SelectionKey selectionKey) {
     void closeRawChannel() throws IOException {
         socketChannel.close();
     }
-
 }

test/framework/src/main/java/org/elasticsearch/transport/nio/channel/NioServerSocketChannel.java

@@ -37,4 +37,12 @@ public NioServerSocketChannel(String profile, ServerSocketChannel socketChannel,
     public ChannelFactory getChannelFactory() {
         return channelFactory;
     }
+
+    @Override
+    public String toString() {
+        return "NioServerSocketChannel{" +
+            "profile=" + getProfile() +
+            ", localAddress=" + getLocalAddress() +
+            '}';
+    }
 }

test/framework/src/main/java/org/elasticsearch/transport/nio/channel/NioSocketChannel.java

@@ -155,6 +155,15 @@ public ConnectFuture getConnectFuture() {
         return connectFuture;
     }
 
+    @Override
+    public String toString() {
+        return "NioSocketChannel{" +
+            "profile=" + getProfile() +
+            ", localAddress=" + getLocalAddress() +
+            ", remoteAddress=" + remoteAddress +
+            '}';
+    }
+
     private boolean internalFinish() throws IOException {
         try {
             return socketChannel.finishConnect();