Skip to content

Commit d488666

Browse files
authored
Merge pull request #240 from zhenlineo/1.1-log-for-each-conn
Make the log record a connection id
2 parents 68ff674 + 17420c9 commit d488666

17 files changed

+84
-39
lines changed

driver/src/main/java/org/neo4j/driver/internal/BaseDriver.java

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -29,11 +29,12 @@ abstract class BaseDriver implements Driver
2929
{
3030
private final SecurityPlan securityPlan;
3131
protected final Logger log;
32+
private final static String DRIVER_LOG_NAME = "Driver";
3233

3334
BaseDriver( SecurityPlan securityPlan, Logging logging )
3435
{
3536
this.securityPlan = securityPlan;
36-
this.log = logging.getLog( Session.LOG_NAME );
37+
this.log = logging.getLog( DRIVER_LOG_NAME );
3738
}
3839

3940
@Override

driver/src/main/java/org/neo4j/driver/internal/DirectDriver.java

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -43,7 +43,7 @@ public DirectDriver( BoltServerAddress address, ConnectionPool connections, Secu
4343
@Override
4444
public Session session()
4545
{
46-
return new NetworkSession( connections.acquire( address ), log );
46+
return new NetworkSession( connections.acquire( address ) );
4747
}
4848

4949
@Override

driver/src/main/java/org/neo4j/driver/internal/NetworkSession.java

Lines changed: 22 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -19,8 +19,10 @@
1919
package org.neo4j.driver.internal;
2020

2121
import java.util.Map;
22+
import java.util.UUID;
2223
import java.util.concurrent.atomic.AtomicBoolean;
2324

25+
import org.neo4j.driver.internal.logging.DevNullLogger;
2426
import org.neo4j.driver.internal.spi.Connection;
2527
import org.neo4j.driver.internal.types.InternalTypeSystem;
2628
import org.neo4j.driver.v1.Logger;
@@ -39,6 +41,7 @@
3941
public class NetworkSession implements Session
4042
{
4143
protected Connection connection;
44+
private final String sessionId;
4245
private final Logger logger;
4346

4447
private String lastBookmark = null;
@@ -63,10 +66,20 @@ public void run()
6366
private ExplicitTransaction currentTransaction;
6467
private AtomicBoolean isOpen = new AtomicBoolean( true );
6568

66-
public NetworkSession( Connection connection, Logger logger )
69+
public NetworkSession( Connection connection )
6770
{
6871
this.connection = connection;
69-
this.logger = logger;
72+
73+
if( connection != null && connection.logger() != null )
74+
{
75+
this.logger = connection.logger();
76+
}
77+
else
78+
{
79+
this.logger = DevNullLogger.DEV_NULL_LOGGER;
80+
}
81+
sessionId = UUID.randomUUID().toString();
82+
this.logger.debug( "~~ connection claimed by [session-%s]", sessionId );
7083
}
7184

7285
@Override
@@ -149,15 +162,22 @@ public void close()
149162
catch ( Throwable e )
150163
{
151164
// Best-effort
165+
logger.error( "Failed to close tx due to error: " + e.toString(), e );
152166
}
153167
}
154168
}
155169
try
156170
{
157171
connection.sync();
158172
}
173+
catch( Throwable t )
174+
{
175+
logger.error( "Failed to sync messages due to error: " + t.toString(), t );
176+
throw t;
177+
}
159178
finally
160179
{
180+
logger.debug( "~~ connection released by [session-%s]", sessionId );
161181
connection.close();
162182
}
163183
}

driver/src/main/java/org/neo4j/driver/internal/RoutingDriver.java

Lines changed: 4 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -33,7 +33,6 @@
3333
import org.neo4j.driver.internal.util.ConcurrentRoundRobinSet;
3434
import org.neo4j.driver.internal.util.Consumer;
3535
import org.neo4j.driver.v1.AccessMode;
36-
import org.neo4j.driver.v1.Logger;
3736
import org.neo4j.driver.v1.Logging;
3837
import org.neo4j.driver.v1.Record;
3938
import org.neo4j.driver.v1.Session;
@@ -42,7 +41,6 @@
4241
import org.neo4j.driver.v1.exceptions.ClientException;
4342
import org.neo4j.driver.v1.exceptions.ConnectionFailureException;
4443
import org.neo4j.driver.v1.exceptions.ServiceUnavailableException;
45-
import org.neo4j.driver.v1.util.BiFunction;
4644
import org.neo4j.driver.v1.util.Function;
4745

4846
import static java.lang.String.format;
@@ -67,7 +65,7 @@ public int compare( BoltServerAddress o1, BoltServerAddress o2 )
6765
};
6866
private static final int MIN_SERVERS = 1;
6967
private final ConnectionPool connections;
70-
private final BiFunction<Connection,Logger,Session> sessionProvider;
68+
private final Function<Connection,Session> sessionProvider;
7169
private final Clock clock;
7270
private final ConcurrentRoundRobinSet<BoltServerAddress> routingServers =
7371
new ConcurrentRoundRobinSet<>( COMPARATOR );
@@ -78,7 +76,7 @@ public int compare( BoltServerAddress o1, BoltServerAddress o2 )
7876
public RoutingDriver( BoltServerAddress seedAddress,
7977
ConnectionPool connections,
8078
SecurityPlan securityPlan,
81-
BiFunction<Connection,Logger,Session> sessionProvider,
79+
Function<Connection,Session> sessionProvider,
8280
Clock clock,
8381
Logging logging )
8482
{
@@ -241,7 +239,7 @@ private boolean call( BoltServerAddress address, String procedureName, Consumer<
241239
try
242240
{
243241
acquire = connections.acquire( address );
244-
session = sessionProvider.apply( acquire, log );
242+
session = sessionProvider.apply( acquire );
245243

246244
StatementResult records = session.run( format( "CALL %s", procedureName ) );
247245
while ( records.hasNext() )
@@ -300,8 +298,7 @@ public void onWriteFailure( BoltServerAddress address )
300298
{
301299
writeServers.remove( address );
302300
}
303-
},
304-
log );
301+
});
305302
}
306303

307304
private Connection acquireConnection( AccessMode role )

driver/src/main/java/org/neo4j/driver/internal/RoutingNetworkSession.java

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -22,7 +22,6 @@
2222
import org.neo4j.driver.internal.net.BoltServerAddress;
2323
import org.neo4j.driver.internal.spi.Connection;
2424
import org.neo4j.driver.v1.AccessMode;
25-
import org.neo4j.driver.v1.Logger;
2625
import org.neo4j.driver.v1.Statement;
2726
import org.neo4j.driver.v1.StatementResult;
2827
import org.neo4j.driver.v1.exceptions.ClientException;
@@ -38,9 +37,9 @@ public class RoutingNetworkSession extends NetworkSession
3837
private final RoutingErrorHandler onError;
3938

4039
RoutingNetworkSession( AccessMode mode, Connection connection,
41-
RoutingErrorHandler onError, Logger logger )
40+
RoutingErrorHandler onError )
4241
{
43-
super( connection, logger );
42+
super( connection );
4443
this.mode = mode;
4544
this.onError = onError;
4645
}

driver/src/main/java/org/neo4j/driver/internal/logging/ConsoleLogging.java

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -93,7 +93,8 @@ public String format( LogRecord record )
9393
{
9494
StringBuilder builder = new StringBuilder( 1000 );
9595
builder.append( dateFormat.format( new Date( record.getMillis() ) ) );
96-
builder.append(" ");
96+
builder.append(" ");
97+
builder.append("[").append(record.getLoggerName()).append("] ");
9798
// builder.append( "[" ).append( record.getSourceClassName() ).append( "." );
9899
// builder.append( record.getSourceMethodName() ).append( "] - " );
99100
// builder.append( "[" ).append( record.getLevel() ).append( "] - " );

driver/src/main/java/org/neo4j/driver/internal/logging/DevNullLogger.java

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -22,6 +22,7 @@
2222

2323
public class DevNullLogger implements Logger
2424
{
25+
public static final DevNullLogger DEV_NULL_LOGGER = new DevNullLogger();
2526

2627
@Override
2728
public void error( String message, Throwable cause )

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

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -23,6 +23,7 @@
2323

2424
import org.neo4j.driver.internal.spi.Collector;
2525
import org.neo4j.driver.internal.spi.Connection;
26+
import org.neo4j.driver.v1.Logger;
2627
import org.neo4j.driver.v1.Value;
2728
import org.neo4j.driver.v1.exceptions.ClientException;
2829

@@ -240,4 +241,10 @@ public BoltServerAddress address()
240241
{
241242
return delegate.address();
242243
}
244+
245+
@Override
246+
public Logger logger()
247+
{
248+
return delegate.logger();
249+
}
243250
}

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

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -23,6 +23,7 @@
2323
import java.util.LinkedList;
2424
import java.util.Map;
2525
import java.util.Queue;
26+
import java.util.UUID;
2627
import java.util.concurrent.atomic.AtomicBoolean;
2728

2829
import org.neo4j.driver.internal.messaging.InitMessage;
@@ -37,6 +38,7 @@
3738
import org.neo4j.driver.v1.exceptions.ClientException;
3839
import org.neo4j.driver.v1.exceptions.Neo4jException;
3940

41+
import static java.lang.String.format;
4042
import static org.neo4j.driver.internal.messaging.AckFailureMessage.ACK_FAILURE;
4143
import static org.neo4j.driver.internal.messaging.DiscardAllMessage.DISCARD_ALL;
4244
import static org.neo4j.driver.internal.messaging.PullAllMessage.PULL_ALL;
@@ -52,9 +54,11 @@ public class SocketConnection implements Connection
5254

5355
private final SocketClient socket;
5456

57+
private final Logger logger;
58+
5559
public SocketConnection( BoltServerAddress address, SecurityPlan securityPlan, Logging logging )
5660
{
57-
Logger logger = logging.getLog( String.valueOf( System.currentTimeMillis() ) );
61+
this.logger = logging.getLog( format( "conn-%s", UUID.randomUUID().toString() ) );
5862

5963
if( logger.isDebugEnabled() )
6064
{
@@ -273,4 +277,10 @@ public BoltServerAddress address()
273277
{
274278
return this.socket.address();
275279
}
280+
281+
@Override
282+
public Logger logger()
283+
{
284+
return this.logger;
285+
}
276286
}

driver/src/main/java/org/neo4j/driver/internal/net/pooling/PooledConnection.java

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,7 @@
2525
import org.neo4j.driver.internal.spi.Connection;
2626
import org.neo4j.driver.internal.util.Clock;
2727
import org.neo4j.driver.internal.util.Consumer;
28+
import org.neo4j.driver.v1.Logger;
2829
import org.neo4j.driver.v1.Value;
2930
import org.neo4j.driver.v1.exceptions.Neo4jException;
3031
/**
@@ -243,6 +244,12 @@ public BoltServerAddress address()
243244
return delegate.address();
244245
}
245246

247+
@Override
248+
public Logger logger()
249+
{
250+
return delegate.logger();
251+
}
252+
246253
public void dispose()
247254
{
248255
delegate.close();

driver/src/main/java/org/neo4j/driver/internal/spi/Connection.java

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@
2121
import java.util.Map;
2222

2323
import org.neo4j.driver.internal.net.BoltServerAddress;
24+
import org.neo4j.driver.v1.Logger;
2425
import org.neo4j.driver.v1.Value;
2526

2627
/**
@@ -129,4 +130,9 @@ public interface Connection extends AutoCloseable
129130
* Returns the BoltServerAddress connected to
130131
*/
131132
BoltServerAddress address();
133+
134+
/**
135+
* Returns the logger of this connection
136+
*/
137+
Logger logger();
132138
}

driver/src/main/java/org/neo4j/driver/v1/GraphDatabase.java

Lines changed: 5 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -35,6 +35,7 @@
3535
import org.neo4j.driver.internal.util.Clock;
3636
import org.neo4j.driver.v1.exceptions.ClientException;
3737
import org.neo4j.driver.v1.util.BiFunction;
38+
import org.neo4j.driver.v1.util.Function;
3839

3940
import static java.lang.String.format;
4041
import static org.neo4j.driver.internal.security.SecurityPlan.insecure;
@@ -49,13 +50,13 @@
4950
public class GraphDatabase
5051
{
5152

52-
private static final BiFunction<Connection,Logger,Session>
53-
SESSION_PROVIDER = new BiFunction<Connection,Logger,Session>()
53+
private static final Function<Connection,Session>
54+
SESSION_PROVIDER = new Function<Connection,Session>()
5455
{
5556
@Override
56-
public Session apply( Connection connection, Logger logger )
57+
public Session apply( Connection connection )
5758
{
58-
return new NetworkSession( connection, logger );
59+
return new NetworkSession( connection );
5960
}
6061
};
6162

driver/src/main/java/org/neo4j/driver/v1/Session.java

Lines changed: 0 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -57,8 +57,6 @@
5757
*/
5858
public interface Session extends Resource, StatementRunner
5959
{
60-
String LOG_NAME = "session";
61-
6260
/**
6361
* Begin a new <em>explicit {@linkplain Transaction transaction}</em>. At
6462
* most one transaction may exist in a session at any point in time. To

driver/src/test/java/org/neo4j/driver/internal/NetworkSessionTest.java

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -42,14 +42,14 @@ public class NetworkSessionTest
4242
public ExpectedException exception = ExpectedException.none();
4343

4444
private final Connection mock = mock( Connection.class );
45-
private NetworkSession sess = new NetworkSession( mock, new DevNullLogger() );
45+
private NetworkSession sess = new NetworkSession( mock );
4646

4747
@Test
4848
public void shouldSendAllOnRun() throws Throwable
4949
{
5050
// Given
5151
when( mock.isOpen() ).thenReturn( true );
52-
NetworkSession sess = new NetworkSession( mock, new DevNullLogger() );
52+
NetworkSession sess = new NetworkSession( mock );
5353

5454
// When
5555
sess.run( "whatever" );
@@ -144,7 +144,7 @@ public void shouldNotAllowMoreTransactionsInSessionWhileConnectionClosed() throw
144144
public void shouldGetExceptionIfTryingToCloseSessionMoreThanOnce() throws Throwable
145145
{
146146
// Given
147-
NetworkSession sess = new NetworkSession( mock(Connection.class), mock(Logger.class) );
147+
NetworkSession sess = new NetworkSession( mock(Connection.class) );
148148
try
149149
{
150150
sess.close();

driver/src/test/java/org/neo4j/driver/internal/RoutingDriverTest.java

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -251,10 +251,10 @@ private RoutingDriver forSession( final Session session )
251251
private RoutingDriver forSession( final Session session, Clock clock )
252252
{
253253
return new RoutingDriver( SEED, pool, insecure(),
254-
new BiFunction<Connection,Logger,Session>()
254+
new Function<Connection,Session>()
255255
{
256256
@Override
257-
public Session apply( Connection connection, Logger ignore )
257+
public Session apply( Connection connection )
258258
{
259259
return session;
260260
}

driver/src/test/java/org/neo4j/driver/internal/RoutingNetworkSessionTest.java

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -68,7 +68,7 @@ public void shouldHandleConnectionFailures()
6868
when( connection ).run( anyString(), any( Map.class ), any( Collector.class ) );
6969

7070
RoutingNetworkSession result =
71-
new RoutingNetworkSession( AccessMode.WRITE, connection, onError, mock( Logger.class ) );
71+
new RoutingNetworkSession( AccessMode.WRITE, connection, onError );
7272

7373
// When
7474
try
@@ -94,7 +94,7 @@ public void shouldHandleWriteFailuresInWriteAccessMode()
9494
doThrow( new ClientException( "Neo.ClientError.Cluster.NotALeader", "oh no!" ) ).
9595
when( connection ).run( anyString(), any( Map.class ), any( Collector.class ) );
9696
RoutingNetworkSession session =
97-
new RoutingNetworkSession( AccessMode.WRITE, connection, onError, mock( Logger.class ) );
97+
new RoutingNetworkSession( AccessMode.WRITE, connection, onError );
9898

9999
// When
100100
try
@@ -120,7 +120,7 @@ public void shouldHandleWriteFailuresInReadAccessMode()
120120
doThrow( new ClientException( "Neo.ClientError.Cluster.NotALeader", "oh no!" ) ).
121121
when( connection ).run( anyString(), any( Map.class ), any( Collector.class ) );
122122
RoutingNetworkSession session =
123-
new RoutingNetworkSession( AccessMode.READ, connection, onError, mock( Logger.class ) );
123+
new RoutingNetworkSession( AccessMode.READ, connection, onError );
124124

125125
// When
126126
try
@@ -144,7 +144,7 @@ public void shouldRethrowNonWriteFailures()
144144
doThrow( toBeThrown ).
145145
when( connection ).run( anyString(), any( Map.class ), any( Collector.class ) );
146146
RoutingNetworkSession session =
147-
new RoutingNetworkSession( AccessMode.WRITE, connection, onError, mock( Logger.class ) );
147+
new RoutingNetworkSession( AccessMode.WRITE, connection, onError );
148148

149149
// When
150150
try
@@ -169,7 +169,7 @@ public void shouldHandleConnectionFailuresOnClose()
169169
when( connection ).sync();
170170

171171
RoutingNetworkSession session =
172-
new RoutingNetworkSession( AccessMode.WRITE, connection, onError, mock( Logger.class ) );
172+
new RoutingNetworkSession( AccessMode.WRITE, connection, onError );
173173

174174
// When
175175
try

0 commit comments

Comments
 (0)