Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add channel error logger for channel errors #1039

Merged
merged 1 commit into from
Oct 19, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -48,10 +48,11 @@ public class HandshakeHandler extends ReplayingDecoder<Void>
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;
Expand All @@ -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
Expand Down Expand Up @@ -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
{
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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 )
Expand All @@ -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
Expand Down Expand Up @@ -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
{
Expand All @@ -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 );
}
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -46,6 +47,7 @@ public class InboundMessageDispatcher implements ResponseMessageHandler
private final Channel channel;
private final Queue<ResponseHandler> handlers = new LinkedList<>();
private final Logger log;
private final ChannelErrorLogger errorLog;

private volatile boolean gracefullyClosed;
private Throwable currentError;
Expand All @@ -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 )
Expand Down Expand Up @@ -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();
}

Expand Down Expand Up @@ -287,4 +290,10 @@ Logger getLog()
{
return log;
}

// For testing only
Logger getErrorLog()
{
return errorLog;
}
}
Original file line number Diff line number Diff line change
@@ -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.
* <p>
* 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() ) );
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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;
Expand Down Expand Up @@ -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 );
Expand Down Expand Up @@ -406,18 +410,22 @@ 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();
Logging logging = mock( Logging.class );
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 );
Expand All @@ -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 )
Expand Down