From 9c8640fcd19971891def2913ac8bd2bbe4ce26ea Mon Sep 17 00:00:00 2001 From: lutovich Date: Mon, 5 Dec 2016 12:07:18 +0100 Subject: [PATCH] Additional logging around refresh of the routing table --- .../internal/cluster/ClusterComposition.java | 20 ++++++++++--------- .../driver/internal/cluster/LoadBalancer.java | 12 ++++++++++- .../cluster/RoundRobinAddressSet.java | 7 +++++++ .../ClusterCompositionProviderTest.java | 14 +++++++------ 4 files changed, 37 insertions(+), 16 deletions(-) diff --git a/driver/src/main/java/org/neo4j/driver/internal/cluster/ClusterComposition.java b/driver/src/main/java/org/neo4j/driver/internal/cluster/ClusterComposition.java index 776c7fe049..73f35cd4b6 100644 --- a/driver/src/main/java/org/neo4j/driver/internal/cluster/ClusterComposition.java +++ b/driver/src/main/java/org/neo4j/driver/internal/cluster/ClusterComposition.java @@ -19,12 +19,14 @@ package org.neo4j.driver.internal.cluster; import java.util.HashSet; +import java.util.List; import java.util.Set; import org.neo4j.driver.internal.NetworkSession; import org.neo4j.driver.internal.net.BoltServerAddress; import org.neo4j.driver.internal.spi.Connection; import org.neo4j.driver.internal.util.Clock; +import org.neo4j.driver.v1.Logger; import org.neo4j.driver.v1.Record; import org.neo4j.driver.v1.Statement; import org.neo4j.driver.v1.StatementResult; @@ -45,29 +47,29 @@ final class Default implements Provider { private static final Statement GET_SERVER = new Statement( Provider.GET_SERVERS ); private final Clock clock; + private final Logger log; - Default( Clock clock ) + Default( Clock clock, Logger log ) { this.clock = clock; + this.log = log; } @Override public ClusterComposition getClusterComposition( Connection connection ) throws ServiceUnavailableException { StatementResult cursor = getServers( connection ); + List records = cursor.list(); + log.info( "Got getServers response: %s", records ); long now = clock.millis(); try { - if ( !cursor.hasNext() ) + if ( records.size() != 1 ) { - return null; // server returned too few rows, this is a contract violation, treat as incapable + // server returned too few or too many rows, this is a contract violation, treat as incapable + return null; } - Record record = cursor.next(); - if ( cursor.hasNext() ) - { - return null; // server returned too many rows, this is a contract violation, treat as incapable - } - return read( record, now ); + return read( records.get( 0 ), now ); } finally { diff --git a/driver/src/main/java/org/neo4j/driver/internal/cluster/LoadBalancer.java b/driver/src/main/java/org/neo4j/driver/internal/cluster/LoadBalancer.java index 17e5406d6f..76daf86796 100644 --- a/driver/src/main/java/org/neo4j/driver/internal/cluster/LoadBalancer.java +++ b/driver/src/main/java/org/neo4j/driver/internal/cluster/LoadBalancer.java @@ -51,7 +51,8 @@ public LoadBalancer( ConnectionPool connections, BoltServerAddress... routingAddresses ) throws ServiceUnavailableException { - this( settings, clock, log, connections, new ClusterComposition.Provider.Default( clock ), routingAddresses ); + this( settings, clock, log, connections, new ClusterComposition.Provider.Default( clock, log ), + routingAddresses ); } LoadBalancer( @@ -118,6 +119,9 @@ private Connection acquireConnection( RoundRobinAddressSet servers ) throws Serv } catch ( ServiceUnavailableException e ) { + log.error( String.format( "Failed to refresh routing information using routing address %s", + address ), e ); + forget( address ); } } @@ -129,6 +133,8 @@ private synchronized void ensureRouting() throws ServiceUnavailableException { if ( stale() ) { + log.info( "Routing information is stale. Ttl %s, currentTime %s, routers %s, writers %s, readers %s", + expirationTimeout, clock.millis(), routers, writers, readers ); try { // get a new routing table @@ -143,6 +149,9 @@ private synchronized void ensureRouting() throws ServiceUnavailableException { connections.purge( address ); } + + log.info( "Refreshed routing information. Ttl %s, routers %s, writers %s, readers %s", + expirationTimeout, routers, writers, readers ); } catch ( InterruptedException e ) { @@ -177,6 +186,7 @@ private ClusterComposition lookupRoutingTable() throws InterruptedException, Ser try ( Connection connection = connections.acquire( address ) ) { cluster = provider.getClusterComposition( connection ); + log.info( "Got cluster composition %s", cluster ); } catch ( Exception e ) { diff --git a/driver/src/main/java/org/neo4j/driver/internal/cluster/RoundRobinAddressSet.java b/driver/src/main/java/org/neo4j/driver/internal/cluster/RoundRobinAddressSet.java index 2310888515..abdc868b40 100644 --- a/driver/src/main/java/org/neo4j/driver/internal/cluster/RoundRobinAddressSet.java +++ b/driver/src/main/java/org/neo4j/driver/internal/cluster/RoundRobinAddressSet.java @@ -18,6 +18,7 @@ */ package org.neo4j.driver.internal.cluster; +import java.util.Arrays; import java.util.Set; import java.util.concurrent.atomic.AtomicInteger; @@ -128,6 +129,12 @@ public synchronized void remove( BoltServerAddress address ) } } + @Override + public String toString() + { + return "RoundRobinAddressSet=" + Arrays.toString( addresses ); + } + /** breaking encapsulation in order to perform white-box testing of boundary case */ void setOffset( int target ) { diff --git a/driver/src/test/java/org/neo4j/driver/internal/cluster/ClusterCompositionProviderTest.java b/driver/src/test/java/org/neo4j/driver/internal/cluster/ClusterCompositionProviderTest.java index 916a2a454b..a10e79d5fb 100644 --- a/driver/src/test/java/org/neo4j/driver/internal/cluster/ClusterCompositionProviderTest.java +++ b/driver/src/test/java/org/neo4j/driver/internal/cluster/ClusterCompositionProviderTest.java @@ -18,22 +18,23 @@ */ package org.neo4j.driver.internal.cluster; +import org.junit.Test; +import org.mockito.invocation.InvocationOnMock; +import org.mockito.stubbing.Answer; +import org.mockito.stubbing.Stubber; + import java.util.Collections; import java.util.HashMap; import java.util.HashSet; import java.util.Map; import java.util.Set; -import org.junit.Test; -import org.mockito.invocation.InvocationOnMock; -import org.mockito.stubbing.Answer; -import org.mockito.stubbing.Stubber; - import org.neo4j.driver.internal.EventHandler; import org.neo4j.driver.internal.net.BoltServerAddress; import org.neo4j.driver.internal.spi.Collector; import org.neo4j.driver.internal.spi.Connection; import org.neo4j.driver.internal.util.FakeClock; +import org.neo4j.driver.v1.Logger; import org.neo4j.driver.v1.Value; import org.neo4j.driver.v1.exceptions.ServiceUnavailableException; @@ -148,7 +149,8 @@ public void shouldPropagateConnectionFailureExceptions() throws Exception private ClusterComposition getClusterComposition() { - return new ClusterComposition.Provider.Default( clock ).getClusterComposition( connection ); + return new ClusterComposition.Provider.Default( clock, mock( Logger.class ) ) + .getClusterComposition( connection ); } private void keys( final String... keys )