Merge pull request #407 from lutovich/1.4-tls-logging

Improve logging around connection establishment

Author: zhenlineo

driver/src/main/java/org/neo4j/driver/internal/net/SocketClient.java

@@ -120,12 +120,17 @@ public void start()
     {
         try
         {
-            logger.debug( "~~ [CONNECT] %s", address );
+            logger.debug( "Connecting to %s, secure: %s", address, securityPlan.requiresEncryption() );
             if( channel == null )
             {
                 setChannel( ChannelFactory.create( address, securityPlan, timeoutMillis, logger ) );
+                logger.debug( "Connected to %s, secure: %s", address, securityPlan.requiresEncryption() );
             }
-            setProtocol( negotiateProtocol() );
+
+            logger.debug( "Negotiating protocol with %s", address );
+            SocketProtocol protocol = negotiateProtocol();
+            setProtocol( protocol );
+            logger.debug( "Selected protocol %s with %s", protocol.getClass(), address );
         }
         catch ( ConnectException e )
         {
@@ -206,7 +211,7 @@ public void stop()
             {
                 channel.close();
                 setChannel( null );
-                logger.debug( "~~ [DISCONNECT]" );
+                logger.debug( "Disconnected from %s", address );
             }
         }
         catch ( IOException e )

driver/src/main/java/org/neo4j/driver/internal/security/TLSSocketChannel.java

@@ -121,7 +121,8 @@ public static TLSSocketChannel create( ByteChannel channel, Logger logger, SSLEn
      */
     private void runHandshake() throws IOException
     {
-        logger.debug( "~~ [OPENING SECURE CHANNEL]" );
+        logger.debug( "Running TLS handshake" );
+
         sslEngine.beginHandshake();
         HandshakeStatus handshakeStatus = sslEngine.getHandshakeStatus();
         while ( handshakeStatus != FINISHED && handshakeStatus != NOT_HANDSHAKING )
@@ -142,6 +143,8 @@ private void runHandshake() throws IOException
                 break;
             }
         }
+
+        logger.debug( "TLS handshake completed" );
     }
 
     private HandshakeStatus runDelegatedTasks()
@@ -479,7 +482,7 @@ public void close() throws IOException
             }
             // Close transport
             channel.close();
-            logger.debug( "~~ [CLOSED SECURE CHANNEL]" );
+            logger.debug( "Closed secure channel" );
         }
         catch ( IOException e )
         {

driver/src/test/java/org/neo4j/driver/v1/integration/TLSSocketChannelIT.java

@@ -124,7 +124,7 @@ public void shouldPerformTLSHandshakeWithTrustedCert() throws Throwable
             sslChannel.close();
 
             // Then
-            verify( logger, atLeastOnce() ).debug( "~~ [OPENING SECURE CHANNEL]" );
+            verify( logger, atLeastOnce() ).debug( "Running TLS handshake" );
         }
         finally
         {
@@ -290,7 +290,7 @@ public void shouldPerformTLSHandshakeWithTheSameTrustedServerCert() throws Throw
         sslChannel.close();
 
         // Then
-        verify( logger, atLeastOnce() ).debug( "~~ [OPENING SECURE CHANNEL]" );
+        verify( logger, atLeastOnce() ).debug( "Running TLS handshake" );
     }
 
     @Test
@@ -357,7 +357,7 @@ private void performTLSHandshakeUsingKnownCerts( File knownCerts ) throws Throwa
         sslChannel.close();
 
         // Then
-        verify( logger, atLeastOnce() ).debug( "~~ [CLOSED SECURE CHANNEL]" );
+        verify( logger, atLeastOnce() ).debug( "Closed secure channel" );
     }
 
     private File installRootCertificate() throws Exception