Skip to content

Commit

Permalink
Handle exceptions on transport selection stage with less noise
Browse files Browse the repository at this point in the history
  • Loading branch information
ali-ince committed Dec 11, 2018
1 parent 49e4662 commit 513b99d
Show file tree
Hide file tree
Showing 4 changed files with 159 additions and 9 deletions.
Expand Up @@ -23,6 +23,7 @@
import io.netty.channel.ChannelHandlerContext;
import io.netty.channel.ChannelInboundHandlerAdapter;

import org.neo4j.helpers.Exceptions;
import org.neo4j.logging.Log;
import org.neo4j.logging.LogProvider;

Expand Down Expand Up @@ -83,8 +84,26 @@ public void handlerRemoved( ChannelHandlerContext ctx ) throws Exception
@Override
public void exceptionCaught( ChannelHandlerContext ctx, Throwable cause ) throws Exception
{
log.error( "Fatal error occurred when handling a client connection: " + cause.getMessage(), cause );
close( ctx );
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( String.format( "Fatal error occurred when handling a client connection: %s", ctx.channel() ),
cause );
}
}
finally
{
close( ctx );
}
}

private void close( ChannelHandlerContext ctx )
Expand Down
Expand Up @@ -35,6 +35,8 @@
import java.util.Map;
import java.util.function.BiFunction;

import org.neo4j.helpers.Exceptions;
import org.neo4j.logging.Log;
import org.neo4j.logging.LogProvider;

import static org.neo4j.bolt.transport.ProtocolChooser.BOLT_MAGIC_PREAMBLE;
Expand All @@ -49,6 +51,7 @@ public class TransportSelectionHandler extends ByteToMessageDecoder
private final boolean encryptionRequired;
private final boolean isEncrypted;
private final LogProvider logging;
private final Log log;
private final Map<Long, BiFunction<Channel, Boolean, BoltProtocol>> protocolVersions;

TransportSelectionHandler( SslContext sslCtx, boolean encryptionRequired, boolean isEncrypted, LogProvider logging,
Expand All @@ -58,6 +61,7 @@ public class TransportSelectionHandler extends ByteToMessageDecoder
this.encryptionRequired = encryptionRequired;
this.isEncrypted = isEncrypted;
this.logging = logging;
this.log = logging.getLog( TransportSelectionHandler.class );
this.protocolVersions = protocolVersions;
}

Expand Down Expand Up @@ -90,6 +94,30 @@ else if ( isBoltPreamble( in ) )
}
}

@Override
public void exceptionCaught( ChannelHandlerContext ctx, Throwable cause ) throws Exception
{
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 initialising pipeline, " +
"remote peer unexpectedly closed connection: %s", ctx.channel() );
}
else
{
log.error( "Fatal error occurred when initialising pipeline: " + ctx.channel(), cause );
}
}
finally
{
ctx.close();
}
}

private boolean isBoltPreamble( ByteBuf in )
{
return in.getInt( 0 ) == BOLT_MAGIC_PREAMBLE;
Expand Down
Expand Up @@ -17,21 +17,19 @@
* You should have received a copy of the GNU General Public License
* along with this program. If not, see <http://www.gnu.org/licenses/>.
*/
package org.neo4j.bolt.v1.transport.socket;
package org.neo4j.bolt.transport;

import io.netty.buffer.ByteBuf;
import io.netty.buffer.UnpooledByteBufAllocator;
import io.netty.channel.Channel;
import io.netty.channel.ChannelHandlerContext;
import org.junit.Test;

import java.io.IOException;
import java.util.HashMap;
import java.util.Map;
import java.util.function.BiFunction;

import org.neo4j.bolt.transport.BoltProtocol;
import org.neo4j.bolt.transport.ProtocolChooser;
import org.neo4j.bolt.transport.SocketTransportHandler;
import org.neo4j.bolt.v1.runtime.BoltStateMachine;
import org.neo4j.bolt.v1.runtime.SynchronousBoltWorker;
import org.neo4j.bolt.v1.transport.BoltProtocolV1;
Expand Down Expand Up @@ -135,14 +133,14 @@ public void logsAndClosesProtocolOnUnexpectedExceptions() throws Throwable
// Then
verify( machine ).close();
logging.assertExactly( inLog( SocketTransportHandler.class )
.error( equalTo( "Fatal error occurred when handling a client connection: Oh no!" ), is( cause ) ) );
.error( equalTo( "Fatal error occurred when handling a client connection: " + ctx.channel() ), is( cause ) ) );
}

@Test
public void logsAndClosesContextWhenProtocolNotInitializedOnUnexpectedExceptions() throws Throwable
{
// Given
ChannelHandlerContext context = mock( ChannelHandlerContext.class );
ChannelHandlerContext context = channelHandlerContextMock();
AssertableLogProvider logging = new AssertableLogProvider();
SocketTransportHandler handler = new SocketTransportHandler( mock( ProtocolChooser.class ), logging );

Expand All @@ -153,10 +151,30 @@ public void logsAndClosesContextWhenProtocolNotInitializedOnUnexpectedExceptions
// Then
verify( context ).close();
logging.assertExactly( inLog( SocketTransportHandler.class )
.error( equalTo( "Fatal error occurred when handling a client connection: Oh no!" ),
.error( equalTo( "Fatal error occurred when handling a client connection: " + context.channel() ),
is( cause ) ) );
}

@Test
public void shouldLogConnectionResetErrorsAtWarningLevelAndClosesContext() throws Exception
{
// Given
ChannelHandlerContext context = channelHandlerContextMock();
AssertableLogProvider logging = new AssertableLogProvider();
SocketTransportHandler handler = new SocketTransportHandler( mock( ProtocolChooser.class ), logging );

IOException connResetError = new IOException( "Connection reset by peer" );

// When
handler.exceptionCaught( context, connResetError );

// Then
verify( context ).close();
logging.assertExactly( inLog( SocketTransportHandler.class )
.warn( "Fatal error occurred when handling a client connection, " +
"remote peer unexpectedly closed connection: %s", context.channel() ) );
}

@Test
public void shouldInitializeProtocolOnFirstMessage() throws Exception
{
Expand Down
@@ -0,0 +1,85 @@
/*
* Copyright (c) 2002-2018 "Neo4j,"
* Neo4j Sweden AB [http://neo4j.com]
*
* This file is part of Neo4j.
*
* Neo4j is free software: you can redistribute it and/or modify
* it under the terms of the GNU General Public License as published by
* the Free Software Foundation, either version 3 of the License, or
* (at your option) any later version.
*
* This program is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU General Public License for more details.
*
* You should have received a copy of the GNU General Public License
* along with this program. If not, see <http://www.gnu.org/licenses/>.
*/
package org.neo4j.bolt.transport;

import io.netty.channel.Channel;
import io.netty.channel.ChannelHandlerContext;
import org.junit.Test;

import java.io.IOException;

import org.neo4j.logging.AssertableLogProvider;

import static org.hamcrest.Matchers.equalTo;
import static org.hamcrest.Matchers.sameInstance;
import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.verify;
import static org.mockito.Mockito.when;
import static org.neo4j.logging.AssertableLogProvider.inLog;

public class TransportSelectionHandlerTest
{

@Test
public void shouldLogOnUnexpectedExceptionsAndClosesContext() throws Throwable
{
// Given
ChannelHandlerContext context = channelHandlerContextMock();
AssertableLogProvider logging = new AssertableLogProvider();
TransportSelectionHandler handler = new TransportSelectionHandler( null, false, false, logging, null );

// When
Throwable cause = new Throwable( "Oh no!" );
handler.exceptionCaught( context, cause );

// Then
verify( context ).close();
logging.assertExactly( inLog( TransportSelectionHandler.class )
.error( equalTo( "Fatal error occurred when initialising pipeline: " + context.channel() ), sameInstance( cause ) ) );
}

@Test
public void shouldLogConnectionResetErrorsAtWarningLevelAndClosesContext() throws Exception
{
// Given
ChannelHandlerContext context = channelHandlerContextMock();
AssertableLogProvider logging = new AssertableLogProvider();
TransportSelectionHandler handler = new TransportSelectionHandler( null, false, false, logging, null );

IOException connResetError = new IOException( "Connection reset by peer" );

// When
handler.exceptionCaught( context, connResetError );

// Then
verify( context ).close();
logging.assertExactly( inLog( TransportSelectionHandler.class )
.warn( "Fatal error occurred when initialising pipeline, " +
"remote peer unexpectedly closed connection: %s", context.channel() ) );
}

private static ChannelHandlerContext channelHandlerContextMock()
{
Channel channel = mock( Channel.class );
ChannelHandlerContext context = mock( ChannelHandlerContext.class );
when( context.channel() ).thenReturn( channel );
return context;
}
}

0 comments on commit 513b99d

Please sign in to comment.