From d89dd2db334e5dea8c532ca7f7cf89f834c34039 Mon Sep 17 00:00:00 2001 From: AgentK Date: Fri, 15 May 2020 17:31:35 -0500 Subject: [PATCH] netty: log SocketExceptions at FINE, too This PR changes the `NettyServerTransport#getLogLevel` method to log `SocketException`s to `LogLevel.FINE`, rather than exclusively pure IOExceptions. This may fix an unintentional regression introduced in c166ec2c, although the message in my java version (14.0.1) wouldn't have passed the old logic for quieting either. This also fixes the issue raised in #6423 that was locked for inactivity. This fixes ``` [2020/05/14 20:21:52 INFO] [io.grpc.netty.NettyServerTransport.connections] Transport failed java.net.SocketException: Connection reset at java.base/sun.nio.ch.SocketChannelImpl.throwConnectionReset(SocketChannelImpl.java:345) at java.base/sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:376) at io.netty.buffer.PooledUnsafeDirectByteBuf.setBytes(PooledUnsafeDirectByteBuf.java:288) at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1125) at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:347) at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:148) at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:677) at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:612) at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:529) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:491) at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:905) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.base/java.lang.Thread.run(Thread.java:832) ``` being logged to level INFO, which occurs whenever a socket is improperly closed by the client, such as with the grpc-health-probe (They've got an [open issue](https://github.com/grpc-ecosystem/grpc-health-probe/issues/34) for this) --- netty/src/main/java/io/grpc/netty/NettyServerTransport.java | 2 ++ .../test/java/io/grpc/netty/NettyServerTransportTest.java | 6 ++++++ 2 files changed, 8 insertions(+) diff --git a/netty/src/main/java/io/grpc/netty/NettyServerTransport.java b/netty/src/main/java/io/grpc/netty/NettyServerTransport.java index 3638dd5b0d..d9e0bdedac 100644 --- a/netty/src/main/java/io/grpc/netty/NettyServerTransport.java +++ b/netty/src/main/java/io/grpc/netty/NettyServerTransport.java @@ -38,6 +38,7 @@ import io.netty.util.concurrent.Future; import io.netty.util.concurrent.GenericFutureListener; import java.io.IOException; import java.net.SocketAddress; +import java.net.SocketException; import java.util.List; import java.util.concurrent.ScheduledExecutorService; import java.util.logging.Level; @@ -186,6 +187,7 @@ class NettyServerTransport implements ServerTransport { @VisibleForTesting static Level getLogLevel(Throwable t) { if (t.getClass().equals(IOException.class) + || t.getClass().equals(SocketException.class) || QUIET_EXCEPTIONS.contains(t.getClass().getSimpleName())) { return Level.FINE; } diff --git a/netty/src/test/java/io/grpc/netty/NettyServerTransportTest.java b/netty/src/test/java/io/grpc/netty/NettyServerTransportTest.java index 41e7791a2b..c4e0b4a2e2 100644 --- a/netty/src/test/java/io/grpc/netty/NettyServerTransportTest.java +++ b/netty/src/test/java/io/grpc/netty/NettyServerTransportTest.java @@ -22,6 +22,7 @@ import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertNull; import java.io.IOException; +import java.net.SocketException; import java.util.logging.Level; import org.junit.Test; import org.junit.runner.RunWith; @@ -34,6 +35,11 @@ public class NettyServerTransportTest { assertEquals(Level.INFO, getLogLevel(new Exception())); } + @Test + public void socketException() { + assertEquals(Level.FINE, getLogLevel(new SocketException("Connection reset"))); + } + @Test public void ioException() { assertEquals(Level.FINE, getLogLevel(new IOException("Connection reset by peer")));