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 class AcceptorEventHandler extends EventHandler {
      *
      * @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 class AcceptorEventHandler extends EventHandler {
      * @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 class AcceptorEventHandler extends EventHandler {
      *
      * @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 class AcceptorEventHandler extends EventHandler {
      * @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 class AcceptorEventHandler extends EventHandler {
      * @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,8 +40,8 @@ public abstract class EventHandler {
      *
      * @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);
     }
 
     /**
@@ -49,8 +49,9 @@ public abstract class EventHandler {
      *
      * @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);
     }
 
     /**
@@ -58,7 +59,7 @@ public abstract class EventHandler {
      *
      * @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 abstract class EventHandler {
      *
      * @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 class SocketEventHandler extends EventHandler {
      *
      * @param channel that was registered
      */
-    public void handleRegistration(NioSocketChannel channel) {
+    void handleRegistration(NioSocketChannel channel) {
         SelectionKeyUtils.setConnectAndReadInterested(channel);
     }
 
@@ -57,8 +58,8 @@ public class SocketEventHandler extends EventHandler {
      * @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 class SocketEventHandler extends EventHandler {
      *
      * @param channel that was registered
      */
-    public void handleConnect(NioSocketChannel channel) {
+    void handleConnect(NioSocketChannel channel) {
         SelectionKeyUtils.removeConnectInterested(channel);
     }
 
@@ -78,8 +79,8 @@ public class SocketEventHandler extends EventHandler {
      * @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 class SocketEventHandler extends EventHandler {
      *
      * @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 class SocketEventHandler extends EventHandler {
      * @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 class SocketEventHandler extends EventHandler {
      *
      * @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 class SocketEventHandler extends EventHandler {
      * @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 class SocketEventHandler extends EventHandler {
      * @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 @@ public abstract class AbstractNioChannel<S extends SelectableChannel & NetworkCh
     void closeRawChannel() throws IOException {
         socketChannel.close();
     }
-
 }

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

@@ -37,4 +37,12 @@ public class NioServerSocketChannel extends AbstractNioChannel<ServerSocketChann
     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 class NioSocketChannel extends AbstractNioChannel<SocketChannel> {
         return connectFuture;
     }
 
+    @Override
+    public String toString() {
+        return "NioSocketChannel{" +
+            "profile=" + getProfile() +
+            ", localAddress=" + getLocalAddress() +
+            ", remoteAddress=" + remoteAddress +
+            '}';
+    }
+
     private boolean internalFinish() throws IOException {
         try {
             return socketChannel.finishConnect();