From bf403ae0287ee840f5f76bb8851d3403a1e2593e Mon Sep 17 00:00:00 2001 From: Tim Brooks Date: Thu, 28 Sep 2017 17:11:26 -0600 Subject: [PATCH] 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. --- .../transport/nio/AcceptorEventHandler.java | 18 +++++++----- .../transport/nio/EventHandler.java | 29 +++++++++++++------ .../transport/nio/SocketEventHandler.java | 29 ++++++++++--------- .../nio/channel/AbstractNioChannel.java | 1 - .../nio/channel/NioServerSocketChannel.java | 8 +++++ .../nio/channel/NioSocketChannel.java | 9 ++++++ 6 files changed, 62 insertions(+), 32 deletions(-) diff --git a/test/framework/src/main/java/org/elasticsearch/transport/nio/AcceptorEventHandler.java b/test/framework/src/main/java/org/elasticsearch/transport/nio/AcceptorEventHandler.java index 7228cf4f050..0c360e11a4c 100644 --- a/test/framework/src/main/java/org/elasticsearch/transport/nio/AcceptorEventHandler.java +++ b/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); } } diff --git a/test/framework/src/main/java/org/elasticsearch/transport/nio/EventHandler.java b/test/framework/src/main/java/org/elasticsearch/transport/nio/EventHandler.java index 382a6728771..30682406d84 100644 --- a/test/framework/src/main/java/org/elasticsearch/transport/nio/EventHandler.java +++ b/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); + } } diff --git a/test/framework/src/main/java/org/elasticsearch/transport/nio/SocketEventHandler.java b/test/framework/src/main/java/org/elasticsearch/transport/nio/SocketEventHandler.java index 6905f7957b3..a57307decbb 100644 --- a/test/framework/src/main/java/org/elasticsearch/transport/nio/SocketEventHandler.java +++ b/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); } diff --git a/test/framework/src/main/java/org/elasticsearch/transport/nio/channel/AbstractNioChannel.java b/test/framework/src/main/java/org/elasticsearch/transport/nio/channel/AbstractNioChannel.java index 36f776a625a..c550785fac5 100644 --- a/test/framework/src/main/java/org/elasticsearch/transport/nio/channel/AbstractNioChannel.java +++ b/test/framework/src/main/java/org/elasticsearch/transport/nio/channel/AbstractNioChannel.java @@ -162,5 +162,4 @@ public abstract class AbstractNioChannel