From 4ec76ba0ea6621fbced819c3bb9a1150feb5ceea Mon Sep 17 00:00:00 2001 From: Jacob Davis-Hansson Date: Fri, 9 Nov 2018 09:11:49 -0600 Subject: [PATCH] Less intimidating error on bolt conn reset --- .../DefaultBoltProtocolPipelineInstaller.java | 2 +- .../bolt/transport/pipeline/HouseKeeper.java | 34 +++++++++++---- .../transport/pipeline/HouseKeeperTest.java | 43 +++++++++++++++---- 3 files changed, 61 insertions(+), 18 deletions(-) diff --git a/community/bolt/src/main/java/org/neo4j/bolt/transport/DefaultBoltProtocolPipelineInstaller.java b/community/bolt/src/main/java/org/neo4j/bolt/transport/DefaultBoltProtocolPipelineInstaller.java index 9ed5ab4d5a4f..982073fea627 100644 --- a/community/bolt/src/main/java/org/neo4j/bolt/transport/DefaultBoltProtocolPipelineInstaller.java +++ b/community/bolt/src/main/java/org/neo4j/bolt/transport/DefaultBoltProtocolPipelineInstaller.java @@ -67,7 +67,7 @@ public void install() pipeline.addLast( new ChunkDecoder() ); pipeline.addLast( new MessageAccumulator() ); pipeline.addLast( new MessageDecoder( neo4jPack, messageHandler, logging ) ); - pipeline.addLast( new HouseKeeper( connection, logging ) ); + pipeline.addLast( new HouseKeeper( connection, logging.getInternalLog( HouseKeeper.class ) ) ); } @Override diff --git a/community/bolt/src/main/java/org/neo4j/bolt/transport/pipeline/HouseKeeper.java b/community/bolt/src/main/java/org/neo4j/bolt/transport/pipeline/HouseKeeper.java index 2d86ca6b9dd6..d2b0bee99606 100644 --- a/community/bolt/src/main/java/org/neo4j/bolt/transport/pipeline/HouseKeeper.java +++ b/community/bolt/src/main/java/org/neo4j/bolt/transport/pipeline/HouseKeeper.java @@ -24,18 +24,19 @@ import io.netty.util.concurrent.EventExecutorGroup; import org.neo4j.bolt.runtime.BoltConnection; -import org.neo4j.kernel.impl.logging.LogService; +import org.neo4j.helpers.Exceptions; +import org.neo4j.logging.Log; public class HouseKeeper extends ChannelInboundHandlerAdapter { private final BoltConnection connection; - private final LogService logging; + private final Log log; private boolean failed; - public HouseKeeper( BoltConnection connection, LogService logging ) + public HouseKeeper( BoltConnection connection, Log log ) { this.connection = connection; - this.logging = logging; + this.log = log; } @Override @@ -51,11 +52,28 @@ public void exceptionCaught( ChannelHandlerContext ctx, Throwable cause ) { return; } - failed = true; // log only the first exception to not polute the log + failed = true; // log only the first exception to not pollute the log - logging.getInternalLog( getClass() ).error( "Fatal error occurred when handling a client connection: " + ctx.channel(), cause ); - - ctx.close(); + try + { + // Netty throws a NativeIoException on connection reset - directly importing that class + // caused a host of linking errors, because it depends on JNI to work. Hence, we just + // test on the message we know we'll get. + if ( Exceptions.contains( cause, e -> e.getMessage().contains( "Connection reset by peer" ) ) ) + { + log.warn( "Fatal error occurred when handling a client connection, " + + "remote peer unexpectedly closed connection: %s", ctx.channel() ); + } + else + { + log.error( "Fatal error occurred when handling a client connection: " + ctx.channel(), + cause ); + } + } + finally + { + ctx.close(); + } } private static boolean isShuttingDown( ChannelHandlerContext ctx ) diff --git a/community/bolt/src/test/java/org/neo4j/bolt/transport/pipeline/HouseKeeperTest.java b/community/bolt/src/test/java/org/neo4j/bolt/transport/pipeline/HouseKeeperTest.java index 16c8c3507a9c..27c15f2bf299 100644 --- a/community/bolt/src/test/java/org/neo4j/bolt/transport/pipeline/HouseKeeperTest.java +++ b/community/bolt/src/test/java/org/neo4j/bolt/transport/pipeline/HouseKeeperTest.java @@ -22,21 +22,23 @@ import io.netty.bootstrap.Bootstrap; import io.netty.channel.Channel; import io.netty.channel.ChannelFuture; +import io.netty.channel.ChannelHandlerContext; import io.netty.channel.ChannelInboundHandler; import io.netty.channel.ChannelInitializer; import io.netty.channel.embedded.EmbeddedChannel; import io.netty.channel.nio.NioEventLoopGroup; import io.netty.channel.socket.SocketChannel; import io.netty.channel.socket.nio.NioSocketChannel; +import io.netty.util.concurrent.EventExecutor; import org.junit.After; import org.junit.Test; +import java.io.IOException; import java.net.ServerSocket; import org.neo4j.bolt.runtime.BoltConnection; -import org.neo4j.kernel.impl.logging.NullLogService; -import org.neo4j.kernel.impl.logging.SimpleLogService; import org.neo4j.logging.AssertableLogProvider; +import org.neo4j.logging.NullLog; import static io.netty.buffer.ByteBufUtil.writeUtf8; import static org.hamcrest.Matchers.equalTo; @@ -45,6 +47,7 @@ import static org.mockito.Mockito.mock; import static org.mockito.Mockito.never; import static org.mockito.Mockito.verify; +import static org.mockito.Mockito.when; import static org.neo4j.logging.AssertableLogProvider.inLog; public class HouseKeeperTest @@ -64,7 +67,7 @@ public void cleanup() public void shouldStopConnectionOnChannelInactive() { BoltConnection connection = mock( BoltConnection.class ); - channel = new EmbeddedChannel( new HouseKeeper( connection, NullLogService.getInstance() ) ); + channel = new EmbeddedChannel( new HouseKeeper( connection, NullLog.getInstance() ) ); channel.pipeline().fireChannelInactive(); @@ -76,7 +79,7 @@ public void shouldNotPropagateChannelInactive() throws Exception { ChannelInboundHandler next = mock( ChannelInboundHandler.class ); BoltConnection connection = mock( BoltConnection.class ); - channel = new EmbeddedChannel( new HouseKeeper( connection, NullLogService.getInstance() ), next ); + channel = new EmbeddedChannel( new HouseKeeper( connection, NullLog.getInstance() ), next ); channel.pipeline().fireChannelInactive(); @@ -87,7 +90,7 @@ public void shouldNotPropagateChannelInactive() throws Exception public void shouldStopConnectionOnExceptionCaught() { BoltConnection connection = mock( BoltConnection.class ); - channel = new EmbeddedChannel( new HouseKeeper( connection, NullLogService.getInstance() ) ); + channel = new EmbeddedChannel( new HouseKeeper( connection, NullLog.getInstance() ) ); channel.pipeline().fireExceptionCaught( new RuntimeException( "some exception" ) ); @@ -99,7 +102,7 @@ public void shouldLogExceptionOnExceptionCaught() { AssertableLogProvider logProvider = new AssertableLogProvider(); BoltConnection connection = mock( BoltConnection.class ); - channel = new EmbeddedChannel( new HouseKeeper( connection, new SimpleLogService( logProvider ) ) ); + channel = new EmbeddedChannel( new HouseKeeper( connection, logProvider.getLog( HouseKeeper.class ) ) ); RuntimeException exception = new RuntimeException( "some exception" ); channel.pipeline().fireExceptionCaught( exception ); @@ -114,7 +117,7 @@ public void shouldNotPropagateExceptionCaught() throws Exception { ChannelInboundHandler next = mock( ChannelInboundHandler.class ); BoltConnection connection = mock( BoltConnection.class ); - channel = new EmbeddedChannel( new HouseKeeper( connection, NullLogService.getInstance() ), next ); + channel = new EmbeddedChannel( new HouseKeeper( connection, NullLog.getInstance() ), next ); channel.pipeline().fireExceptionCaught( new RuntimeException( "some exception" ) ); @@ -126,7 +129,7 @@ public void shouldNotLogExceptionsWhenEvenLoopIsShuttingDown() throws Exception { AssertableLogProvider logProvider = new AssertableLogProvider(); BoltConnection connection = mock( BoltConnection.class ); - HouseKeeper houseKeeper = new HouseKeeper( connection, new SimpleLogService( logProvider ) ); + HouseKeeper houseKeeper = new HouseKeeper( connection, logProvider.getLog( HouseKeeper.class ) ); Bootstrap bootstrap = newBootstrap( houseKeeper ); try ( ServerSocket serverSocket = new ServerSocket( 0 ) ) @@ -160,7 +163,7 @@ public void shouldLogOnlyTheFirstCaughtException() throws Exception { AssertableLogProvider logProvider = new AssertableLogProvider(); BoltConnection connection = mock( BoltConnection.class ); - HouseKeeper houseKeeper = new HouseKeeper( connection, new SimpleLogService( logProvider ) ); + HouseKeeper houseKeeper = new HouseKeeper( connection, logProvider.getLog( HouseKeeper.class ) ); Bootstrap bootstrap = newBootstrap( houseKeeper ); RuntimeException error1 = new RuntimeException( "error #1" ); @@ -190,6 +193,28 @@ public void shouldLogOnlyTheFirstCaughtException() throws Exception inLog( HouseKeeper.class ).error( startsWith( "Fatal error occurred when handling a client connection" ), equalTo( error1 ) ) ); } + @Test + public void shouldNotLogConnectionResetErrors() throws Exception + { + // Given + AssertableLogProvider logProvider = new AssertableLogProvider(); + HouseKeeper keeper = new HouseKeeper( null, logProvider.getLog( HouseKeeper.class ) ); + Channel channel = mock( Channel.class ); + when( channel.toString() ).thenReturn( "[some channel info]" ); + ChannelHandlerContext ctx = mock( ChannelHandlerContext.class ); + when( ctx.channel() ).thenReturn( channel ); + when( ctx.executor() ).thenReturn( mock( EventExecutor.class ) ); + IOException connResetError = new IOException( "Connection reset by peer" ); + + // When + keeper.exceptionCaught( ctx, connResetError ); + + // Then + logProvider.assertExactly( AssertableLogProvider.inLog( HouseKeeper.class ).warn( + "Fatal error occurred when handling a client connection, " + + "remote peer unexpectedly closed connection: %s", channel ) ); + } + private static Bootstrap newBootstrap( HouseKeeper houseKeeper ) { return new Bootstrap()