From da1270476673017b360ad633d47094f393959242 Mon Sep 17 00:00:00 2001 From: Dmitriy Tverdiakov Date: Tue, 19 Oct 2021 11:31:52 +0100 Subject: [PATCH] Add channel error logger for channel errors The new logger provides a dedicated facility for channel error logging in debug and trace modes. --- .../async/connection/HandshakeHandler.java | 18 ++++--- .../async/inbound/ChannelErrorHandler.java | 10 ++-- .../inbound/InboundMessageDispatcher.java | 11 +++- .../internal/logging/ChannelErrorLogger.java | 50 +++++++++++++++++++ .../inbound/InboundMessageDispatcherTest.java | 13 ++++- 5 files changed, 87 insertions(+), 15 deletions(-) create mode 100644 driver/src/main/java/org/neo4j/driver/internal/logging/ChannelErrorLogger.java diff --git a/driver/src/main/java/org/neo4j/driver/internal/async/connection/HandshakeHandler.java b/driver/src/main/java/org/neo4j/driver/internal/async/connection/HandshakeHandler.java index 988b029b4f..6fa8a0244e 100644 --- a/driver/src/main/java/org/neo4j/driver/internal/async/connection/HandshakeHandler.java +++ b/driver/src/main/java/org/neo4j/driver/internal/async/connection/HandshakeHandler.java @@ -27,16 +27,16 @@ import java.util.List; import javax.net.ssl.SSLHandshakeException; +import org.neo4j.driver.Logging; +import org.neo4j.driver.exceptions.ClientException; +import org.neo4j.driver.exceptions.SecurityException; +import org.neo4j.driver.exceptions.ServiceUnavailableException; import org.neo4j.driver.internal.logging.ChannelActivityLogger; +import org.neo4j.driver.internal.logging.ChannelErrorLogger; import org.neo4j.driver.internal.messaging.BoltProtocol; import org.neo4j.driver.internal.messaging.BoltProtocolVersion; import org.neo4j.driver.internal.messaging.MessageFormat; import org.neo4j.driver.internal.util.ErrorUtil; -import org.neo4j.driver.Logger; -import org.neo4j.driver.Logging; -import org.neo4j.driver.exceptions.ClientException; -import org.neo4j.driver.exceptions.SecurityException; -import org.neo4j.driver.exceptions.ServiceUnavailableException; import static org.neo4j.driver.internal.async.connection.BoltProtocolUtil.NO_PROTOCOL_VERSION; import static org.neo4j.driver.internal.messaging.BoltProtocolVersion.isHttp; @@ -48,10 +48,11 @@ public class HandshakeHandler extends ReplayingDecoder private final Logging logging; private boolean failed; - private Logger log; + private ChannelActivityLogger log; + private ChannelErrorLogger errorLog; public HandshakeHandler( ChannelPipelineBuilder pipelineBuilder, ChannelPromise handshakeCompletedPromise, - Logging logging ) + Logging logging ) { this.pipelineBuilder = pipelineBuilder; this.handshakeCompletedPromise = handshakeCompletedPromise; @@ -62,6 +63,7 @@ public HandshakeHandler( ChannelPipelineBuilder pipelineBuilder, ChannelPromise public void handlerAdded( ChannelHandlerContext ctx ) { log = new ChannelActivityLogger( ctx.channel(), logging, getClass() ); + errorLog = new ChannelErrorLogger( ctx.channel(), logging ); } @Override @@ -89,7 +91,7 @@ public void exceptionCaught( ChannelHandlerContext ctx, Throwable error ) { if ( failed ) { - log.warn( "Another fatal error occurred in the pipeline", error ); + errorLog.traceOrDebug( "Another fatal error occurred in the pipeline", error ); } else { diff --git a/driver/src/main/java/org/neo4j/driver/internal/async/inbound/ChannelErrorHandler.java b/driver/src/main/java/org/neo4j/driver/internal/async/inbound/ChannelErrorHandler.java index 311da7a0f0..1a6de004c0 100644 --- a/driver/src/main/java/org/neo4j/driver/internal/async/inbound/ChannelErrorHandler.java +++ b/driver/src/main/java/org/neo4j/driver/internal/async/inbound/ChannelErrorHandler.java @@ -24,11 +24,11 @@ import java.io.IOException; -import org.neo4j.driver.Logger; import org.neo4j.driver.Logging; import org.neo4j.driver.exceptions.ConnectionReadTimeoutException; import org.neo4j.driver.exceptions.ServiceUnavailableException; import org.neo4j.driver.internal.logging.ChannelActivityLogger; +import org.neo4j.driver.internal.logging.ChannelErrorLogger; import org.neo4j.driver.internal.util.ErrorUtil; import static java.util.Objects.requireNonNull; @@ -40,7 +40,8 @@ public class ChannelErrorHandler extends ChannelInboundHandlerAdapter private final Logging logging; private InboundMessageDispatcher messageDispatcher; - private Logger log; + private ChannelActivityLogger log; + private ChannelErrorLogger errorLog; private boolean failed; public ChannelErrorHandler( Logging logging ) @@ -53,6 +54,7 @@ public void handlerAdded( ChannelHandlerContext ctx ) { messageDispatcher = requireNonNull( messageDispatcher( ctx.channel() ) ); log = new ChannelActivityLogger( ctx.channel(), logging, getClass() ); + errorLog = new ChannelErrorLogger( ctx.channel(), logging ); } @Override @@ -90,7 +92,7 @@ public void exceptionCaught( ChannelHandlerContext ctx, Throwable error ) { if ( failed ) { - log.warn( "Another fatal error occurred in the pipeline", error ); + errorLog.traceOrDebug( "Another fatal error occurred in the pipeline", error ); } else { @@ -104,7 +106,7 @@ private void logUnexpectedErrorWarning( Throwable error ) { if ( !(error instanceof ConnectionReadTimeoutException) ) { - log.warn( "Fatal error occurred in the pipeline", error ); + errorLog.traceOrDebug( "Fatal error occurred in the pipeline", error ); } } diff --git a/driver/src/main/java/org/neo4j/driver/internal/async/inbound/InboundMessageDispatcher.java b/driver/src/main/java/org/neo4j/driver/internal/async/inbound/InboundMessageDispatcher.java index 21ecc9652f..6b958b4e73 100644 --- a/driver/src/main/java/org/neo4j/driver/internal/async/inbound/InboundMessageDispatcher.java +++ b/driver/src/main/java/org/neo4j/driver/internal/async/inbound/InboundMessageDispatcher.java @@ -32,6 +32,7 @@ import org.neo4j.driver.exceptions.ClientException; import org.neo4j.driver.internal.handlers.ResetResponseHandler; import org.neo4j.driver.internal.logging.ChannelActivityLogger; +import org.neo4j.driver.internal.logging.ChannelErrorLogger; import org.neo4j.driver.internal.messaging.ResponseMessageHandler; import org.neo4j.driver.internal.spi.ResponseHandler; import org.neo4j.driver.internal.util.ErrorUtil; @@ -46,6 +47,7 @@ public class InboundMessageDispatcher implements ResponseMessageHandler private final Channel channel; private final Queue handlers = new LinkedList<>(); private final Logger log; + private final ChannelErrorLogger errorLog; private volatile boolean gracefullyClosed; private Throwable currentError; @@ -58,6 +60,7 @@ public InboundMessageDispatcher( Channel channel, Logging logging ) { this.channel = requireNonNull( channel ); this.log = new ChannelActivityLogger( channel, logging, getClass() ); + this.errorLog = new ChannelErrorLogger( channel, logging ); } public void enqueue( ResponseHandler handler ) @@ -198,7 +201,7 @@ public void handleChannelError( Throwable error ) handler.onFailure( currentError ); } - log.debug( "Closing channel because of a failure", error ); + errorLog.traceOrDebug( "Closing channel because of a failure", error ); channel.close(); } @@ -287,4 +290,10 @@ Logger getLog() { return log; } + + // For testing only + Logger getErrorLog() + { + return errorLog; + } } diff --git a/driver/src/main/java/org/neo4j/driver/internal/logging/ChannelErrorLogger.java b/driver/src/main/java/org/neo4j/driver/internal/logging/ChannelErrorLogger.java new file mode 100644 index 0000000000..82262c52f8 --- /dev/null +++ b/driver/src/main/java/org/neo4j/driver/internal/logging/ChannelErrorLogger.java @@ -0,0 +1,50 @@ +/* + * Copyright (c) "Neo4j" + * Neo4j Sweden AB [http://neo4j.com] + * + * This file is part of Neo4j. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.neo4j.driver.internal.logging; + +import io.netty.channel.Channel; + +import org.neo4j.driver.Logging; + +/** + * Dedicated logger for channel error logging. + *

+ * It keeps messages shorter in debug mode and provides more details in trace mode. + */ +public class ChannelErrorLogger extends ChannelActivityLogger +{ + private static final String DEBUG_MESSAGE_FORMAT = "%s (%s)"; + + public ChannelErrorLogger( Channel channel, Logging logging ) + { + super( channel, logging, ChannelErrorLogger.class ); + } + + public void traceOrDebug( String message, Throwable error ) + { + if ( isTraceEnabled() ) + { + trace( message, error ); + } + else + { + debug( String.format( DEBUG_MESSAGE_FORMAT, message, error.getClass() ) ); + } + } +} diff --git a/driver/src/test/java/org/neo4j/driver/internal/async/inbound/InboundMessageDispatcherTest.java b/driver/src/test/java/org/neo4j/driver/internal/async/inbound/InboundMessageDispatcherTest.java index 4bf876a0bc..da209b48d9 100644 --- a/driver/src/test/java/org/neo4j/driver/internal/async/inbound/InboundMessageDispatcherTest.java +++ b/driver/src/test/java/org/neo4j/driver/internal/async/inbound/InboundMessageDispatcherTest.java @@ -38,6 +38,7 @@ import org.neo4j.driver.exceptions.ClientException; import org.neo4j.driver.exceptions.Neo4jException; import org.neo4j.driver.internal.logging.ChannelActivityLogger; +import org.neo4j.driver.internal.logging.ChannelErrorLogger; import org.neo4j.driver.internal.messaging.Message; import org.neo4j.driver.internal.messaging.response.FailureMessage; import org.neo4j.driver.internal.messaging.response.IgnoredMessage; @@ -56,6 +57,7 @@ import static org.mockito.ArgumentMatchers.anyBoolean; import static org.mockito.ArgumentMatchers.anyString; import static org.mockito.ArgumentMatchers.argThat; +import static org.mockito.ArgumentMatchers.contains; import static org.mockito.ArgumentMatchers.eq; import static org.mockito.Mockito.inOrder; import static org.mockito.Mockito.mock; @@ -378,6 +380,8 @@ void shouldCreateChannelActivityLoggerAndLogDebugMessageOnMessageHandling( Class Logger logger = mock( Logger.class ); when( logger.isDebugEnabled() ).thenReturn( true ); when( logging.getLog( InboundMessageDispatcher.class ) ).thenReturn( logger ); + ChannelErrorLogger errorLogger = mock( ChannelErrorLogger.class ); + when( logging.getLog( ChannelErrorLogger.class ) ).thenReturn( errorLogger ); InboundMessageDispatcher dispatcher = new InboundMessageDispatcher( channel, logging ); ResponseHandler handler = mock( ResponseHandler.class ); dispatcher.enqueue( handler ); @@ -406,11 +410,12 @@ else if ( IgnoredMessage.class.isAssignableFrom( message ) ) // THEN assertTrue( dispatcher.getLog() instanceof ChannelActivityLogger ); + assertTrue( dispatcher.getErrorLog() instanceof ChannelErrorLogger ); verify( logger ).debug( anyString(), any( Object.class ) ); } @Test - void shouldCreateChannelActivityLoggerAndLogDebugMessageOnChannelError() + void shouldCreateChannelErrorLoggerAndLogDebugMessageOnChannelError() { // GIVEN Channel channel = newChannelMock(); @@ -418,6 +423,9 @@ void shouldCreateChannelActivityLoggerAndLogDebugMessageOnChannelError() Logger logger = mock( Logger.class ); when( logger.isDebugEnabled() ).thenReturn( true ); when( logging.getLog( InboundMessageDispatcher.class ) ).thenReturn( logger ); + ChannelErrorLogger errorLogger = mock( ChannelErrorLogger.class ); + when( errorLogger.isDebugEnabled() ).thenReturn( true ); + when( logging.getLog( ChannelErrorLogger.class ) ).thenReturn( errorLogger ); InboundMessageDispatcher dispatcher = new InboundMessageDispatcher( channel, logging ); ResponseHandler handler = mock( ResponseHandler.class ); dispatcher.enqueue( handler ); @@ -428,7 +436,8 @@ void shouldCreateChannelActivityLoggerAndLogDebugMessageOnChannelError() // THEN assertTrue( dispatcher.getLog() instanceof ChannelActivityLogger ); - verify( logger ).debug( anyString(), eq( throwable ) ); + assertTrue( dispatcher.getErrorLog() instanceof ChannelErrorLogger ); + verify( errorLogger ).debug( contains( throwable.getClass().toString() ) ); } private static void verifyFailure( ResponseHandler handler )