Skip to content

Commit 9765378

Browse files
lutovichlutovich
authored
Merge pull request #437 from zhenlineo/1.5-redirect-logging
Redirect netty logging to driver logging
2 parents ae43d77 + b90c31c commit 9765378

30 files changed

+518
-136
lines changed

‎driver/src/main/java/org/neo4j/driver/internal/DriverFactory.java

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,7 @@
2020

2121
import io.netty.bootstrap.Bootstrap;
2222
import io.netty.util.concurrent.EventExecutorGroup;
23+
import io.netty.util.internal.logging.InternalLoggerFactory;
2324

2425
import java.io.IOException;
2526
import java.net.URI;
@@ -36,6 +37,7 @@
3637
import org.neo4j.driver.internal.cluster.loadbalancing.LoadBalancer;
3738
import org.neo4j.driver.internal.cluster.loadbalancing.LoadBalancingStrategy;
3839
import org.neo4j.driver.internal.cluster.loadbalancing.RoundRobinLoadBalancingStrategy;
40+
import org.neo4j.driver.internal.logging.NettyLogging;
3941
import org.neo4j.driver.internal.retry.ExponentialBackoffRetryLogic;
4042
import org.neo4j.driver.internal.retry.RetryLogic;
4143
import org.neo4j.driver.internal.retry.RetrySettings;
@@ -69,6 +71,7 @@ public final Driver newInstance( URI uri, AuthToken authToken, RoutingSettings r
6971
RoutingSettings newRoutingSettings = routingSettings.withRoutingContext( new RoutingContext( uri ) );
7072
SecurityPlan securityPlan = createSecurityPlan( address, config );
7173

74+
InternalLoggerFactory.setDefaultFactory( new NettyLogging( config.logging() ) );
7275
Bootstrap bootstrap = createBootstrap();
7376
EventExecutorGroup eventExecutorGroup = bootstrap.config().group();
7477
RetryLogic retryLogic = createRetryLogic( retrySettings, eventExecutorGroup, config.logging() );

‎driver/src/main/java/org/neo4j/driver/internal/InternalDriver.java

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -44,6 +44,7 @@ public class InternalDriver implements Driver
4444
this.securityPlan = securityPlan;
4545
this.sessionFactory = sessionFactory;
4646
this.log = logging.getLog( Driver.class.getSimpleName() );
47+
log.info( "Driver instance %s created", this );
4748
}
4849

4950
@Override
@@ -112,7 +113,7 @@ public CompletionStage<Void> closeAsync()
112113
{
113114
if ( closed.compareAndSet( false, true ) )
114115
{
115-
log.info( "Driver instance is closing" );
116+
log.info( "Closing driver instance %s", this );
116117
return sessionFactory.close();
117118
}
118119
return completedFuture( null );

‎driver/src/main/java/org/neo4j/driver/internal/async/ProtocolUtil.java renamed to ‎driver/src/main/java/org/neo4j/driver/internal/async/BoltProtocolV1Util.java

Lines changed: 12 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -24,7 +24,7 @@
2424
import static io.netty.buffer.Unpooled.copyShort;
2525
import static io.netty.buffer.Unpooled.unreleasableBuffer;
2626

27-
public final class ProtocolUtil
27+
public final class BoltProtocolV1Util
2828
{
2929
public static final int HTTP = 1213486160; //== 0x48545450 == "HTTP"
3030

@@ -36,24 +36,30 @@ public final class ProtocolUtil
3636

3737
public static final int DEFAULT_MAX_OUTBOUND_CHUNK_SIZE_BYTES = Short.MAX_VALUE / 2;
3838

39-
private static final ByteBuf HANDSHAKE_BUF = unreleasableBuffer( copyInt(
39+
private static final ByteBuf BOLT_V1_HANDSHAKE_BUF = unreleasableBuffer( copyInt(
4040
BOLT_MAGIC_PREAMBLE,
4141
PROTOCOL_VERSION_1,
4242
NO_PROTOCOL_VERSION,
4343
NO_PROTOCOL_VERSION,
44-
NO_PROTOCOL_VERSION ) ).asReadOnly();
44+
NO_PROTOCOL_VERSION ) )
45+
.asReadOnly();
4546

4647
private static final ByteBuf MESSAGE_BOUNDARY_BUF = unreleasableBuffer( copyShort( 0 ) ).asReadOnly();
4748

4849
private static final ByteBuf CHUNK_HEADER_PLACEHOLDER_BUF = unreleasableBuffer( copyShort( 0 ) ).asReadOnly();
4950

50-
private ProtocolUtil()
51+
private BoltProtocolV1Util()
5152
{
5253
}
5354

54-
public static ByteBuf handshake()
55+
public static ByteBuf handshakeBuf()
5556
{
56-
return HANDSHAKE_BUF.duplicate();
57+
return BOLT_V1_HANDSHAKE_BUF.duplicate();
58+
}
59+
60+
public static String handshakeString()
61+
{
62+
return "[0x6060B017, 1, 0, 0, 0]";
5763
}
5864

5965
public static ByteBuf messageBoundary()

‎driver/src/main/java/org/neo4j/driver/internal/async/ChannelConnectedListener.java

Lines changed: 7 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -25,20 +25,21 @@
2525
import io.netty.channel.ChannelPromise;
2626

2727
import org.neo4j.driver.internal.BoltServerAddress;
28+
import org.neo4j.driver.internal.logging.ChannelActivityLogger;
2829
import org.neo4j.driver.v1.Logger;
2930
import org.neo4j.driver.v1.Logging;
3031
import org.neo4j.driver.v1.exceptions.ServiceUnavailableException;
3132

3233
import static java.lang.String.format;
33-
import static org.neo4j.driver.internal.async.ProtocolUtil.handshake;
34+
import static org.neo4j.driver.internal.async.BoltProtocolV1Util.handshakeBuf;
35+
import static org.neo4j.driver.internal.async.BoltProtocolV1Util.handshakeString;
3436

3537
public class ChannelConnectedListener implements ChannelFutureListener
3638
{
3739
private final BoltServerAddress address;
3840
private final ChannelPipelineBuilder pipelineBuilder;
3941
private final ChannelPromise handshakeCompletedPromise;
4042
private final Logging logging;
41-
private final Logger log;
4243

4344
public ChannelConnectedListener( BoltServerAddress address, ChannelPipelineBuilder pipelineBuilder,
4445
ChannelPromise handshakeCompletedPromise, Logging logging )
@@ -47,21 +48,22 @@ public ChannelConnectedListener( BoltServerAddress address, ChannelPipelineBuild
4748
this.pipelineBuilder = pipelineBuilder;
4849
this.handshakeCompletedPromise = handshakeCompletedPromise;
4950
this.logging = logging;
50-
this.log = logging.getLog( getClass().getSimpleName() );
5151
}
5252

5353
@Override
5454
public void operationComplete( ChannelFuture future )
5555
{
5656
Channel channel = future.channel();
57+
Logger log = new ChannelActivityLogger( channel, logging, getClass() );
5758

5859
if ( future.isSuccess() )
5960
{
60-
log.trace( "Channel %s connected, running bolt handshake", channel );
61+
log.trace( "Channel %s connected, initiating bolt handshake", channel );
6162

6263
ChannelPipeline pipeline = channel.pipeline();
6364
pipeline.addLast( new HandshakeHandler( pipelineBuilder, handshakeCompletedPromise, logging ) );
64-
ChannelFuture handshakeFuture = channel.writeAndFlush( handshake() );
65+
log.debug( "C: [Bolt Handshake] %s", handshakeString() );
66+
ChannelFuture handshakeFuture = channel.writeAndFlush( handshakeBuf() );
6567

6668
handshakeFuture.addListener( channelFuture ->
6769
{

‎driver/src/main/java/org/neo4j/driver/internal/async/ChannelConnectorImpl.java

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -71,7 +71,7 @@ public ChannelConnectorImpl( ConnectionSettings connectionSettings, SecurityPlan
7171
public ChannelFuture connect( BoltServerAddress address, Bootstrap bootstrap )
7272
{
7373
bootstrap.option( ChannelOption.CONNECT_TIMEOUT_MILLIS, connectTimeoutMillis );
74-
bootstrap.handler( new NettyChannelInitializer( address, securityPlan, clock ) );
74+
bootstrap.handler( new NettyChannelInitializer( address, securityPlan, clock, logging ) );
7575

7676
ChannelFuture channelConnected = bootstrap.connect( address.toSocketAddress() );
7777

‎driver/src/main/java/org/neo4j/driver/internal/async/HandshakeHandler.java

Lines changed: 6 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -28,7 +28,7 @@
2828
import java.util.List;
2929
import javax.net.ssl.SSLHandshakeException;
3030

31-
import org.neo4j.driver.internal.logging.PrefixedLogger;
31+
import org.neo4j.driver.internal.logging.ChannelActivityLogger;
3232
import org.neo4j.driver.internal.messaging.MessageFormat;
3333
import org.neo4j.driver.internal.messaging.PackStreamMessageFormatV1;
3434
import org.neo4j.driver.internal.util.ErrorUtil;
@@ -38,9 +38,9 @@
3838
import org.neo4j.driver.v1.exceptions.SecurityException;
3939
import org.neo4j.driver.v1.exceptions.ServiceUnavailableException;
4040

41-
import static org.neo4j.driver.internal.async.ProtocolUtil.HTTP;
42-
import static org.neo4j.driver.internal.async.ProtocolUtil.NO_PROTOCOL_VERSION;
43-
import static org.neo4j.driver.internal.async.ProtocolUtil.PROTOCOL_VERSION_1;
41+
import static org.neo4j.driver.internal.async.BoltProtocolV1Util.HTTP;
42+
import static org.neo4j.driver.internal.async.BoltProtocolV1Util.NO_PROTOCOL_VERSION;
43+
import static org.neo4j.driver.internal.async.BoltProtocolV1Util.PROTOCOL_VERSION_1;
4444

4545
public class HandshakeHandler extends ReplayingDecoder<Void>
4646
{
@@ -62,7 +62,7 @@ public HandshakeHandler( ChannelPipelineBuilder pipelineBuilder, ChannelPromise
6262
@Override
6363
public void handlerAdded( ChannelHandlerContext ctx )
6464
{
65-
log = new PrefixedLogger( ctx.channel().toString(), logging, getClass() );
65+
log = new ChannelActivityLogger( ctx.channel(), logging, getClass() );
6666
}
6767

6868
@Override
@@ -112,7 +112,7 @@ public void exceptionCaught( ChannelHandlerContext ctx, Throwable error )
112112
protected void decode( ChannelHandlerContext ctx, ByteBuf in, List<Object> out )
113113
{
114114
int serverSuggestedVersion = in.readInt();
115-
log.debug( "Server suggested protocol version %s during handshake", serverSuggestedVersion );
115+
log.debug( "S: [Bolt Handshake] %d", serverSuggestedVersion );
116116

117117
ChannelPipeline pipeline = ctx.pipeline();
118118
// this is a one-time handler, remove it when protocol version has been read

‎driver/src/main/java/org/neo4j/driver/internal/async/NettyChannelInitializer.java

Lines changed: 5 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -29,23 +29,25 @@
2929
import org.neo4j.driver.internal.async.inbound.InboundMessageDispatcher;
3030
import org.neo4j.driver.internal.security.SecurityPlan;
3131
import org.neo4j.driver.internal.util.Clock;
32+
import org.neo4j.driver.v1.Logging;
3233

3334
import static org.neo4j.driver.internal.async.ChannelAttributes.setCreationTimestamp;
3435
import static org.neo4j.driver.internal.async.ChannelAttributes.setMessageDispatcher;
3536
import static org.neo4j.driver.internal.async.ChannelAttributes.setServerAddress;
36-
import static org.neo4j.driver.internal.logging.DevNullLogging.DEV_NULL_LOGGING;
3737

3838
public class NettyChannelInitializer extends ChannelInitializer<Channel>
3939
{
4040
private final BoltServerAddress address;
4141
private final SecurityPlan securityPlan;
4242
private final Clock clock;
43+
private final Logging logging;
4344

44-
public NettyChannelInitializer( BoltServerAddress address, SecurityPlan securityPlan, Clock clock )
45+
public NettyChannelInitializer( BoltServerAddress address, SecurityPlan securityPlan, Clock clock, Logging logging )
4546
{
4647
this.address = address;
4748
this.securityPlan = securityPlan;
4849
this.clock = clock;
50+
this.logging = logging;
4951
}
5052

5153
@Override
@@ -78,6 +80,6 @@ private void updateChannelAttributes( Channel channel )
7880
{
7981
setServerAddress( channel, address );
8082
setCreationTimestamp( channel, clock.millis() );
81-
setMessageDispatcher( channel, new InboundMessageDispatcher( channel, DEV_NULL_LOGGING ) );
83+
setMessageDispatcher( channel, new InboundMessageDispatcher( channel, logging ) );
8284
}
8385
}

‎driver/src/main/java/org/neo4j/driver/internal/async/inbound/ChannelErrorHandler.java

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -24,7 +24,7 @@
2424

2525
import java.io.IOException;
2626

27-
import org.neo4j.driver.internal.logging.PrefixedLogger;
27+
import org.neo4j.driver.internal.logging.ChannelActivityLogger;
2828
import org.neo4j.driver.internal.util.ErrorUtil;
2929
import org.neo4j.driver.v1.Logger;
3030
import org.neo4j.driver.v1.Logging;
@@ -50,7 +50,7 @@ public ChannelErrorHandler( Logging logging )
5050
public void handlerAdded( ChannelHandlerContext ctx )
5151
{
5252
messageDispatcher = requireNonNull( messageDispatcher( ctx.channel() ) );
53-
log = new PrefixedLogger( ctx.channel().toString(), logging, getClass() );
53+
log = new ChannelActivityLogger( ctx.channel(), logging, getClass() );
5454
}
5555

5656
@Override

‎driver/src/main/java/org/neo4j/driver/internal/async/inbound/ChunkDecoder.java

Lines changed: 5 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -19,15 +19,14 @@
1919
package org.neo4j.driver.internal.async.inbound;
2020

2121
import io.netty.buffer.ByteBuf;
22+
import io.netty.buffer.ByteBufUtil;
2223
import io.netty.channel.ChannelHandlerContext;
2324
import io.netty.handler.codec.LengthFieldBasedFrameDecoder;
2425

25-
import org.neo4j.driver.internal.logging.PrefixedLogger;
26+
import org.neo4j.driver.internal.logging.ChannelActivityLogger;
2627
import org.neo4j.driver.v1.Logger;
2728
import org.neo4j.driver.v1.Logging;
2829

29-
import static io.netty.buffer.ByteBufUtil.prettyHexDump;
30-
3130
public class ChunkDecoder extends LengthFieldBasedFrameDecoder
3231
{
3332
private static final int MAX_FRAME_LENGTH = Short.MAX_VALUE;
@@ -48,7 +47,7 @@ public ChunkDecoder( Logging logging )
4847
@Override
4948
public void handlerAdded( ChannelHandlerContext ctx )
5049
{
51-
log = new PrefixedLogger( ctx.channel().toString(), logging, getClass() );
50+
log = new ChannelActivityLogger( ctx.channel(), logging, getClass() );
5251
}
5352

5453
@Override
@@ -65,8 +64,8 @@ protected ByteBuf extractFrame( ChannelHandlerContext ctx, ByteBuf buffer, int i
6564
int originalReaderIndex = buffer.readerIndex();
6665
int readerIndexWithChunkHeader = originalReaderIndex - INITIAL_BYTES_TO_STRIP;
6766
int lengthWithChunkHeader = INITIAL_BYTES_TO_STRIP + buffer.readableBytes();
68-
String hexDump = prettyHexDump( buffer, readerIndexWithChunkHeader, lengthWithChunkHeader );
69-
log.trace( "S:\n%s", hexDump );
67+
String hexDump = ByteBufUtil.hexDump( buffer, readerIndexWithChunkHeader, lengthWithChunkHeader );
68+
log.trace( "S: %s", hexDump );
7069
}
7170
return super.extractFrame( ctx, buffer, index, length );
7271
}

‎driver/src/main/java/org/neo4j/driver/internal/async/inbound/InboundMessageDispatcher.java

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -26,7 +26,7 @@
2626
import java.util.Queue;
2727

2828
import org.neo4j.driver.internal.handlers.AckFailureResponseHandler;
29-
import org.neo4j.driver.internal.logging.PrefixedLogger;
29+
import org.neo4j.driver.internal.logging.ChannelActivityLogger;
3030
import org.neo4j.driver.internal.messaging.MessageHandler;
3131
import org.neo4j.driver.internal.spi.ResponseHandler;
3232
import org.neo4j.driver.internal.util.ErrorUtil;
@@ -50,7 +50,7 @@ public class InboundMessageDispatcher implements MessageHandler
5050
public InboundMessageDispatcher( Channel channel, Logging logging )
5151
{
5252
this.channel = requireNonNull( channel );
53-
this.log = new PrefixedLogger( channel.toString(), logging, getClass() );
53+
this.log = new ChannelActivityLogger( channel, logging, getClass() );
5454
}
5555

5656
public void queue( ResponseHandler handler )

‎driver/src/main/java/org/neo4j/driver/internal/async/inbound/InboundMessageHandler.java

Lines changed: 6 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -23,12 +23,12 @@
2323
import io.netty.channel.SimpleChannelInboundHandler;
2424
import io.netty.handler.codec.DecoderException;
2525

26-
import org.neo4j.driver.internal.logging.PrefixedLogger;
26+
import org.neo4j.driver.internal.logging.ChannelActivityLogger;
2727
import org.neo4j.driver.internal.messaging.MessageFormat;
2828
import org.neo4j.driver.v1.Logger;
2929
import org.neo4j.driver.v1.Logging;
3030

31-
import static io.netty.buffer.ByteBufUtil.prettyHexDump;
31+
import static io.netty.buffer.ByteBufUtil.hexDump;
3232
import static java.util.Objects.requireNonNull;
3333
import static org.neo4j.driver.internal.async.ChannelAttributes.messageDispatcher;
3434

@@ -52,7 +52,7 @@ public InboundMessageHandler( MessageFormat messageFormat, Logging logging )
5252
public void handlerAdded( ChannelHandlerContext ctx )
5353
{
5454
messageDispatcher = requireNonNull( messageDispatcher( ctx.channel() ) );
55-
log = new PrefixedLogger( ctx.channel().toString(), logging, getClass() );
55+
log = new ChannelActivityLogger( ctx.channel(), logging, getClass() );
5656
}
5757

5858
@Override
@@ -68,13 +68,13 @@ protected void channelRead0( ChannelHandlerContext ctx, ByteBuf msg )
6868
if ( messageDispatcher.fatalErrorOccurred() )
6969
{
7070
log.warn( "Message ignored because of the previous fatal error. Channel will be closed. Message:\n%s",
71-
prettyHexDump( msg ) );
71+
hexDump( msg ) );
7272
return;
7373
}
7474

7575
if ( log.isTraceEnabled() )
7676
{
77-
log.trace( "S:\n%s", prettyHexDump( msg ) );
77+
log.trace( "S: %s", hexDump( msg ) );
7878
}
7979

8080
input.start( msg );
@@ -84,7 +84,7 @@ protected void channelRead0( ChannelHandlerContext ctx, ByteBuf msg )
8484
}
8585
catch ( Throwable error )
8686
{
87-
throw new DecoderException( "Failed to read inbound message:\n" + prettyHexDump( msg ) + "\n", error );
87+
throw new DecoderException( "Failed to read inbound message:\n" + hexDump( msg ) + "\n", error );
8888
}
8989
finally
9090
{

‎driver/src/main/java/org/neo4j/driver/internal/async/outbound/ChunkAwareByteBufOutput.java

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -23,9 +23,9 @@
2323
import org.neo4j.driver.internal.packstream.PackOutput;
2424

2525
import static java.util.Objects.requireNonNull;
26-
import static org.neo4j.driver.internal.async.ProtocolUtil.CHUNK_HEADER_SIZE_BYTES;
27-
import static org.neo4j.driver.internal.async.ProtocolUtil.DEFAULT_MAX_OUTBOUND_CHUNK_SIZE_BYTES;
28-
import static org.neo4j.driver.internal.async.ProtocolUtil.chunkHeaderPlaceholder;
26+
import static org.neo4j.driver.internal.async.BoltProtocolV1Util.CHUNK_HEADER_SIZE_BYTES;
27+
import static org.neo4j.driver.internal.async.BoltProtocolV1Util.DEFAULT_MAX_OUTBOUND_CHUNK_SIZE_BYTES;
28+
import static org.neo4j.driver.internal.async.BoltProtocolV1Util.chunkHeaderPlaceholder;
2929

3030
public class ChunkAwareByteBufOutput implements PackOutput
3131
{

‎driver/src/main/java/org/neo4j/driver/internal/async/outbound/OutboundMessageHandler.java

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -25,14 +25,14 @@
2525

2626
import java.util.List;
2727

28-
import org.neo4j.driver.internal.logging.PrefixedLogger;
28+
import org.neo4j.driver.internal.logging.ChannelActivityLogger;
2929
import org.neo4j.driver.internal.messaging.Message;
3030
import org.neo4j.driver.internal.messaging.MessageFormat;
3131
import org.neo4j.driver.v1.Logger;
3232
import org.neo4j.driver.v1.Logging;
3333

34-
import static io.netty.buffer.ByteBufUtil.prettyHexDump;
35-
import static org.neo4j.driver.internal.async.ProtocolUtil.messageBoundary;
34+
import static io.netty.buffer.ByteBufUtil.hexDump;
35+
import static org.neo4j.driver.internal.async.BoltProtocolV1Util.messageBoundary;
3636

3737
public class OutboundMessageHandler extends MessageToMessageEncoder<Message>
3838
{
@@ -61,7 +61,7 @@ private OutboundMessageHandler( MessageFormat messageFormat, boolean byteArraySu
6161
@Override
6262
public void handlerAdded( ChannelHandlerContext ctx )
6363
{
64-
log = new PrefixedLogger( ctx.channel().toString(), logging, getClass() );
64+
log = new ChannelActivityLogger( ctx.channel(), logging, getClass() );
6565
}
6666

6767
@Override
@@ -92,7 +92,7 @@ protected void encode( ChannelHandlerContext ctx, Message msg, List<Object> out
9292

9393
if ( log.isTraceEnabled() )
9494
{
95-
log.trace( "C:\n%s", prettyHexDump( messageBuf ) );
95+
log.trace( "C: %s", hexDump( messageBuf ) );
9696
}
9797

9898
out.add( messageBuf );

0 commit comments

Comments
 (0)