Add channel error logger for channel errors (#1039)

The new logger provides a dedicated facility for channel error logging in debug and trace modes.

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<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;
@@ -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
         {

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 );
         }
     }
 

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<ResponseHandler> 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;
+    }
 }

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.
+ * <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() ) );
+        }
+    }
+}

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,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 );
@@ -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 )