From b0bd061fdbade0fbc094574b11c8bd9fd832f9ad Mon Sep 17 00:00:00 2001 From: Mats Rydberg Date: Tue, 23 Aug 2016 15:56:57 +0200 Subject: [PATCH] Make the query log include username The query log will now include the name of the access mode (the username) as part of the log message. This is solved by making all `QuerySession` implementors use their provided transactional context to acquire the username and put it in the `toString()`, which is already printed to the query log. --- .../runtime/cypher/CypherStatementRunner.java | 11 +- .../runtime/cypher/BoltQuerySessionTest.java | 43 ++++++ .../impl/query/QueryEngineProvider.java | 4 +- .../impl/query/EmbeddedQuerySessionTest.java | 45 +++++++ .../impl/query/FakeTransactionalContext.java | 123 ++++++++++++++++++ .../server/rest/web/ServerQuerySession.java | 6 +- .../rest/web/ServerQuerySessionTest.java | 58 +++++++++ .../neo4j/shell/kernel/apps/cypher/Start.java | 6 +- .../apps/cypher/ShellQuerySessionTest.java | 47 +++++++ .../kernel/impl/query/QueryLoggerIT.java | 13 +- .../kernel/impl/query/QueryLoggerTest.java | 73 +++++++---- 11 files changed, 393 insertions(+), 36 deletions(-) create mode 100644 community/bolt/src/test/java/org/neo4j/bolt/v1/runtime/cypher/BoltQuerySessionTest.java create mode 100644 community/kernel/src/test/java/org/neo4j/kernel/impl/query/EmbeddedQuerySessionTest.java create mode 100644 community/kernel/src/test/java/org/neo4j/kernel/impl/query/FakeTransactionalContext.java create mode 100644 community/server/src/test/java/org/neo4j/server/rest/web/ServerQuerySessionTest.java create mode 100644 community/shell/src/test/java/org/neo4j/shell/kernel/apps/cypher/ShellQuerySessionTest.java diff --git a/community/bolt/src/main/java/org/neo4j/bolt/v1/runtime/cypher/CypherStatementRunner.java b/community/bolt/src/main/java/org/neo4j/bolt/v1/runtime/cypher/CypherStatementRunner.java index cbc753ffc2f96..27e41fa2b2041 100644 --- a/community/bolt/src/main/java/org/neo4j/bolt/v1/runtime/cypher/CypherStatementRunner.java +++ b/community/bolt/src/main/java/org/neo4j/bolt/v1/runtime/cypher/CypherStatementRunner.java @@ -33,6 +33,7 @@ import org.neo4j.kernel.impl.query.Neo4jTransactionalContext; import org.neo4j.kernel.impl.query.QueryExecutionEngine; import org.neo4j.kernel.impl.query.QuerySession; +import org.neo4j.kernel.impl.query.TransactionalContext; import static java.lang.String.format; import static org.neo4j.kernel.api.KernelTransaction.Type.implicit; @@ -58,26 +59,28 @@ public Result run( final String querySource, final AuthSubject authSubject, fina throws KernelException { InternalTransaction transaction = queryService.beginTransaction( implicit, authSubject ); - Neo4jTransactionalContext transactionalContext = + TransactionalContext transactionalContext = new Neo4jTransactionalContext( queryService, transaction, txBridge.get(), locker ); QuerySession session = new BoltQuerySession( transactionalContext, querySource ); return queryExecutionEngine.executeQuery( statement, params, session ); } - private static class BoltQuerySession extends QuerySession + static class BoltQuerySession extends QuerySession { private final String querySource; + private final String username; - BoltQuerySession( Neo4jTransactionalContext transactionalContext, String querySource ) + BoltQuerySession( TransactionalContext transactionalContext, String querySource ) { super( transactionalContext ); + this.username = transactionalContext.accessMode().name(); this.querySource = querySource; } @Override public String toString() { - return format( "bolt-session\t%s", querySource ); + return format( "bolt-session\t%s\t%s", querySource, username ); } } } diff --git a/community/bolt/src/test/java/org/neo4j/bolt/v1/runtime/cypher/BoltQuerySessionTest.java b/community/bolt/src/test/java/org/neo4j/bolt/v1/runtime/cypher/BoltQuerySessionTest.java new file mode 100644 index 0000000000000..19e65b7659b9d --- /dev/null +++ b/community/bolt/src/test/java/org/neo4j/bolt/v1/runtime/cypher/BoltQuerySessionTest.java @@ -0,0 +1,43 @@ +/* + * Copyright (c) 2002-2016 "Neo Technology," + * Network Engine for Objects in Lund AB [http://neotechnology.com] + * + * This file is part of Neo4j. + * + * Neo4j is free software: you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program. If not, see . + */ +package org.neo4j.bolt.v1.runtime.cypher; + +import org.junit.Test; + +import org.neo4j.bolt.v1.runtime.cypher.CypherStatementRunner.BoltQuerySession; +import org.neo4j.kernel.api.security.AccessMode; +import org.neo4j.kernel.impl.query.FakeTransactionalContext; +import org.neo4j.kernel.impl.query.QuerySession; + +import static org.hamcrest.core.IsEqual.equalTo; +import static org.junit.Assert.*; + +public class BoltQuerySessionTest +{ + @Test + public void shouldIncludeUsernameInToString() + { + QuerySession session = new BoltQuerySession( + new FakeTransactionalContext( AccessMode.Static.READ ), "fakeSource" ); + + assertThat( session.toString(), equalTo( String.format( "bolt-session\t%s\t%s", "fakeSource", "READ" ) ) ); + } + +} diff --git a/community/kernel/src/main/java/org/neo4j/kernel/impl/query/QueryEngineProvider.java b/community/kernel/src/main/java/org/neo4j/kernel/impl/query/QueryEngineProvider.java index ef1cb1d140631..ed91acfdf8d42 100644 --- a/community/kernel/src/main/java/org/neo4j/kernel/impl/query/QueryEngineProvider.java +++ b/community/kernel/src/main/java/org/neo4j/kernel/impl/query/QueryEngineProvider.java @@ -67,10 +67,12 @@ public static QuerySession embeddedSession( TransactionalContext transactionalCo final Thread thread = Thread.currentThread(); return new QuerySession( transactionalContext ) { + private final String username = transactionalContext.accessMode().name(); + @Override public String toString() { - return format( "embedded-session\tthread\t%s", thread.getName() ); + return format( "embedded-session\tthread\t%s\t%s", thread.getName(), username ); } }; } diff --git a/community/kernel/src/test/java/org/neo4j/kernel/impl/query/EmbeddedQuerySessionTest.java b/community/kernel/src/test/java/org/neo4j/kernel/impl/query/EmbeddedQuerySessionTest.java new file mode 100644 index 0000000000000..d11733f6e12ef --- /dev/null +++ b/community/kernel/src/test/java/org/neo4j/kernel/impl/query/EmbeddedQuerySessionTest.java @@ -0,0 +1,45 @@ +/* + * Copyright (c) 2002-2016 "Neo Technology," + * Network Engine for Objects in Lund AB [http://neotechnology.com] + * + * This file is part of Neo4j. + * + * Neo4j is free software: you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program. If not, see . + */ +package org.neo4j.kernel.impl.query; + +import org.junit.Test; + +import static org.hamcrest.CoreMatchers.equalTo; +import static org.junit.Assert.assertThat; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.when; + +import static org.neo4j.kernel.api.security.AccessMode.Static.WRITE_ONLY; + +public class EmbeddedQuerySessionTest +{ + + @Test + public void shouldIncludeUserNameInToString() + { + TransactionalContext mock = mock( TransactionalContext.class ); + when( mock.accessMode() ).thenReturn( WRITE_ONLY ); + QuerySession session = QueryEngineProvider.embeddedSession( mock ); + + assertThat( session.toString(), + equalTo( String.format( "embedded-session\tthread\t%s\t%s", + Thread.currentThread().getName(), WRITE_ONLY.name() ) ) ); + } +} diff --git a/community/kernel/src/test/java/org/neo4j/kernel/impl/query/FakeTransactionalContext.java b/community/kernel/src/test/java/org/neo4j/kernel/impl/query/FakeTransactionalContext.java new file mode 100644 index 0000000000000..06edbb118c470 --- /dev/null +++ b/community/kernel/src/test/java/org/neo4j/kernel/impl/query/FakeTransactionalContext.java @@ -0,0 +1,123 @@ +/* + * Copyright (c) 2002-2016 "Neo Technology," + * Network Engine for Objects in Lund AB [http://neotechnology.com] + * + * This file is part of Neo4j. + * + * Neo4j is free software: you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program. If not, see . + */ +package org.neo4j.kernel.impl.query; + +import org.neo4j.graphdb.Lock; +import org.neo4j.graphdb.PropertyContainer; +import org.neo4j.kernel.GraphDatabaseQueryService; +import org.neo4j.kernel.api.KernelTransaction; +import org.neo4j.kernel.api.ReadOperations; +import org.neo4j.kernel.api.Statement; +import org.neo4j.kernel.api.dbms.DbmsOperations; +import org.neo4j.kernel.api.security.AccessMode; +import org.neo4j.kernel.api.txstate.TxStateHolder; + +public class FakeTransactionalContext implements TransactionalContext +{ + private final AccessMode mode; + + public FakeTransactionalContext( AccessMode mode ) { + this.mode = mode; + } + + @Override + public ReadOperations readOperations() + { + throw new UnsupportedOperationException( "fake test class" ); + } + + @Override + public DbmsOperations dbmsOperations() + { + throw new UnsupportedOperationException( "fake test class" ); + } + + @Override + public boolean isTopLevelTx() + { + throw new UnsupportedOperationException( "fake test class" ); + } + + @Override + public void close( boolean success ) + { + throw new UnsupportedOperationException( "fake test class" ); + } + + @Override + public void commitAndRestartTx() + { + throw new UnsupportedOperationException( "fake test class" ); + } + + @Override + public void cleanForReuse() + { + throw new UnsupportedOperationException( "fake test class" ); + } + + @Override + public TransactionalContext provideContext() + { + throw new UnsupportedOperationException( "fake test class" ); + } + + @Override + public boolean isOpen() + { + throw new UnsupportedOperationException( "fake test class" ); + } + + @Override + public GraphDatabaseQueryService graph() + { + throw new UnsupportedOperationException( "fake test class" ); + } + + @Override + public Statement statement() + { + throw new UnsupportedOperationException( "fake test class" ); + } + + @Override + public TxStateHolder stateView() + { + throw new UnsupportedOperationException( "fake test class" ); + } + + @Override + public Lock acquireWriteLock( PropertyContainer p ) + { + throw new UnsupportedOperationException( "fake test class" ); + } + + @Override + public AccessMode accessMode() + { + return mode; + } + + @Override + public KernelTransaction.Revertable restrictCurrentTransaction( AccessMode accessMode ) + { + throw new UnsupportedOperationException( "fake test class" ); + } +} diff --git a/community/server/src/main/java/org/neo4j/server/rest/web/ServerQuerySession.java b/community/server/src/main/java/org/neo4j/server/rest/web/ServerQuerySession.java index 91e89dee170cb..02934e59386b7 100644 --- a/community/server/src/main/java/org/neo4j/server/rest/web/ServerQuerySession.java +++ b/community/server/src/main/java/org/neo4j/server/rest/web/ServerQuerySession.java @@ -29,10 +29,12 @@ public class ServerQuerySession extends QuerySession { private final HttpServletRequest request; + private final String username; public ServerQuerySession( HttpServletRequest request, TransactionalContext transactionalContext ) { super( transactionalContext ); + this.username = transactionalContext.accessMode().name(); this.request = request; } @@ -40,7 +42,7 @@ public ServerQuerySession( HttpServletRequest request, TransactionalContext tran public String toString() { return request == null ? - "server-session" : - format("server-session\thttp\t%s\t%s", request.getRemoteAddr(), request.getRequestURI() ); + format("server-session\t%s", username) : + format("server-session\thttp\t%s\t%s\t%s", request.getRemoteAddr(), request.getRequestURI(), username ); } } diff --git a/community/server/src/test/java/org/neo4j/server/rest/web/ServerQuerySessionTest.java b/community/server/src/test/java/org/neo4j/server/rest/web/ServerQuerySessionTest.java new file mode 100644 index 0000000000000..09d062a789137 --- /dev/null +++ b/community/server/src/test/java/org/neo4j/server/rest/web/ServerQuerySessionTest.java @@ -0,0 +1,58 @@ +/* + * Copyright (c) 2002-2016 "Neo Technology," + * Network Engine for Objects in Lund AB [http://neotechnology.com] + * + * This file is part of Neo4j. + * + * Neo4j is free software: you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program. If not, see . + */ +package org.neo4j.server.rest.web; + +import javax.servlet.http.HttpServletRequest; + +import org.junit.Test; + +import org.neo4j.kernel.api.security.AccessMode; +import org.neo4j.kernel.impl.query.FakeTransactionalContext; +import org.neo4j.kernel.impl.query.QuerySession; + +import static org.hamcrest.core.IsEqual.equalTo; +import static org.junit.Assert.*; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.when; + +public class ServerQuerySessionTest +{ + + @Test + public void shouldIncludeUsernameInToString() + { + QuerySession session = new ServerQuerySession( null, new FakeTransactionalContext( AccessMode.Static.READ ) ); + + assertThat( session.toString(), equalTo( String.format( "server-session\t%s", "READ" ) ) ); + } + + @Test + public void shouldIncludeUsernameInToStringWithHttp() + { + HttpServletRequest mock = mock( HttpServletRequest.class ); + when(mock.getRemoteAddr()).thenReturn( "remote-addr" ); + when(mock.getRequestURI()).thenReturn( "req-uri" ); + + QuerySession session = new ServerQuerySession( mock, new FakeTransactionalContext( AccessMode.Static.READ ) ); + + assertThat( session.toString(), equalTo( String.format( "server-session\thttp\t%s\t%s\t%s", "remote-addr", "req-uri", "READ" ) ) ); + } + +} diff --git a/community/shell/src/main/java/org/neo4j/shell/kernel/apps/cypher/Start.java b/community/shell/src/main/java/org/neo4j/shell/kernel/apps/cypher/Start.java index 8d0deea11ba56..b08e1a4574565 100644 --- a/community/shell/src/main/java/org/neo4j/shell/kernel/apps/cypher/Start.java +++ b/community/shell/src/main/java/org/neo4j/shell/kernel/apps/cypher/Start.java @@ -199,20 +199,22 @@ private QuerySession shellSession( Session session ) return new ShellQuerySession( session, context ); } - private static class ShellQuerySession extends QuerySession + static class ShellQuerySession extends QuerySession { private final Session session; + private final String username; ShellQuerySession( Session session, TransactionalContext transactionalContext ) { super( transactionalContext ); + this.username = transactionalContext.accessMode().name(); this.session = session; } @Override public String toString() { - return String.format( "shell-session\tshell\t%s", session.getId() ); + return String.format( "shell-session\tshell\t%s\t%s", session.getId(), username ); } } } diff --git a/community/shell/src/test/java/org/neo4j/shell/kernel/apps/cypher/ShellQuerySessionTest.java b/community/shell/src/test/java/org/neo4j/shell/kernel/apps/cypher/ShellQuerySessionTest.java new file mode 100644 index 0000000000000..11ed9454bb729 --- /dev/null +++ b/community/shell/src/test/java/org/neo4j/shell/kernel/apps/cypher/ShellQuerySessionTest.java @@ -0,0 +1,47 @@ +/* + * Copyright (c) 2002-2016 "Neo Technology," + * Network Engine for Objects in Lund AB [http://neotechnology.com] + * + * This file is part of Neo4j. + * + * Neo4j is free software: you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program. If not, see . + */ +package org.neo4j.shell.kernel.apps.cypher; + +import org.junit.Test; + +import org.neo4j.kernel.api.security.AccessMode; +import org.neo4j.kernel.impl.query.FakeTransactionalContext; +import org.neo4j.kernel.impl.query.QuerySession; +import org.neo4j.shell.Session; + +import static org.hamcrest.CoreMatchers.equalTo; +import static org.junit.Assert.*; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.when; + +public class ShellQuerySessionTest +{ + + @Test + public void shouldPutUsernameInToString() + { + Session mock = mock( Session.class ); + when( mock.getId() ).thenReturn( "serializable" ); + QuerySession session = new Start.ShellQuerySession( mock, new FakeTransactionalContext( AccessMode.Static.NONE ) ); + + assertThat(session.toString(), equalTo(String.format( "shell-session\tshell\t%s\t%s", "serializable", "NONE" ))); + } + +} diff --git a/enterprise/query-logging/src/test/java/org/neo4j/kernel/impl/query/QueryLoggerIT.java b/enterprise/query-logging/src/test/java/org/neo4j/kernel/impl/query/QueryLoggerIT.java index 9e74bf1be2763..e096f65da4a11 100644 --- a/enterprise/query-logging/src/test/java/org/neo4j/kernel/impl/query/QueryLoggerIT.java +++ b/enterprise/query-logging/src/test/java/org/neo4j/kernel/impl/query/QueryLoggerIT.java @@ -46,11 +46,15 @@ import org.neo4j.test.rule.TestDirectory; import org.neo4j.test.rule.fs.EphemeralFileSystemRule; +import static org.hamcrest.Matchers.containsString; import static org.hamcrest.Matchers.endsWith; import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertThat; import static org.junit.Assert.assertTrue; +import static org.neo4j.kernel.api.security.AccessMode.Static.FULL; +import static org.neo4j.kernel.impl.query.QueryEngineProvider.embeddedSession; + public class QueryLoggerIT { @@ -85,7 +89,8 @@ public void shouldLogQuerySlowerThanThreshold() throws Exception List logLines = readAllLines( logFilename ); assertEquals( 1, logLines.size() ); assertThat( logLines.get( 0 ), endsWith( String.format( " ms: %s - %s", - QueryEngineProvider.embeddedSession( null ), QUERY ) ) ); + embeddedSession( new FakeTransactionalContext( FULL ) ), QUERY ) ) ); + assertThat( logLines.get( 0 ), containsString( FULL.name() ) ); } @Test @@ -113,7 +118,8 @@ public void shouldLogParametersWhenNestedMap() throws Exception assertEquals( 1, logLines.size() ); assertThat( logLines.get( 0 ), endsWith( String.format( " ms: %s - %s - {props: {name: Roland, position: Gunslinger, followers: [Jake, Eddie, Susannah]}}", - QueryEngineProvider.embeddedSession( null ), query) ) ); + embeddedSession( new FakeTransactionalContext( FULL ) ), query) ) ); + assertThat( logLines.get( 0 ), containsString( FULL.name() ) ); } @Test @@ -135,7 +141,8 @@ public void shouldLogParametersWhenList() throws Exception assertThat( logLines.get( 0 ), endsWith( String.format( " ms: %s - %s - {ids: [0, 1, 2]}", - QueryEngineProvider.embeddedSession( null ), query) ) ); + embeddedSession( new FakeTransactionalContext( FULL ) ), query) ) ); + assertThat( logLines.get( 0 ), containsString( FULL.name() ) ); } @Test diff --git a/enterprise/query-logging/src/test/java/org/neo4j/kernel/impl/query/QueryLoggerTest.java b/enterprise/query-logging/src/test/java/org/neo4j/kernel/impl/query/QueryLoggerTest.java index 131888ed88dd2..f930d48feae3f 100644 --- a/enterprise/query-logging/src/test/java/org/neo4j/kernel/impl/query/QueryLoggerTest.java +++ b/enterprise/query-logging/src/test/java/org/neo4j/kernel/impl/query/QueryLoggerTest.java @@ -53,8 +53,8 @@ public void shouldLogQuerySlowerThanThreshold() throws Exception { // given final AssertableLogProvider logProvider = new AssertableLogProvider(); - QuerySession session = session( SESSION_1_NAME ); - FakeClock clock = getFaceClock(); + QuerySession session = session( SESSION_1_NAME, "TestUser" ); + FakeClock clock = Clocks.fakeClock(); QueryLogger queryLogger = queryLoggerWithoutParams( logProvider, clock ); // when @@ -63,8 +63,9 @@ public void shouldLogQuerySlowerThanThreshold() throws Exception queryLogger.endSuccess( session ); // then + String expectedSessionString = String.format( "%s [%s]", SESSION_1_NAME, "TestUser" ); logProvider.assertExactly( - inLog( getClass() ).info( "%d ms: %s - %s", 11L, SESSION_1_NAME, QUERY_1 ) + inLog( getClass() ).info( "%d ms: %s - %s", 11L, expectedSessionString, QUERY_1 ) ); } @@ -73,8 +74,8 @@ public void shouldNotLogQueryFasterThanThreshold() throws Exception { // given final AssertableLogProvider logProvider = new AssertableLogProvider(); - QuerySession session = session( SESSION_1_NAME ); - FakeClock clock = getFaceClock(); + QuerySession session = session( SESSION_1_NAME, "TestUser" ); + FakeClock clock = Clocks.fakeClock(); QueryLogger queryLogger = queryLoggerWithoutParams( logProvider, clock ); // when @@ -91,10 +92,10 @@ public void shouldKeepTrackOfDifferentSessions() throws Exception { // given final AssertableLogProvider logProvider = new AssertableLogProvider(); - QuerySession session1 = session( SESSION_1_NAME ); - QuerySession session2 = session( SESSION_2_NAME ); - QuerySession session3 = session( SESSION_3_NAME ); - FakeClock clock = getFaceClock(); + QuerySession session1 = session( SESSION_1_NAME, "TestUser1" ); + QuerySession session2 = session( SESSION_2_NAME, "TestUser2" ); + QuerySession session3 = session( SESSION_3_NAME, "TestUser3" ); + FakeClock clock = Clocks.fakeClock(); QueryLogger queryLogger = queryLoggerWithoutParams( logProvider, clock ); // when @@ -111,9 +112,11 @@ public void shouldKeepTrackOfDifferentSessions() throws Exception queryLogger.endSuccess( session1 ); // then + String expectedSession1String = String.format( "%s [%s]", SESSION_1_NAME, "TestUser1" ); + String expectedSession2String = String.format( "%s [%s]", SESSION_2_NAME, "TestUser2" ); logProvider.assertExactly( - inLog( getClass() ).info( "%d ms: %s - %s", 15L, SESSION_2_NAME, QUERY_2 ), - inLog( getClass() ).info( "%d ms: %s - %s", 23L, SESSION_1_NAME, QUERY_1 ) + inLog( getClass() ).info( "%d ms: %s - %s", 15L, expectedSession2String, QUERY_2 ), + inLog( getClass() ).info( "%d ms: %s - %s", 23L, expectedSession1String, QUERY_1 ) ); } @@ -122,8 +125,8 @@ public void shouldLogQueryOnFailureEvenIfFasterThanThreshold() throws Exception { // given final AssertableLogProvider logProvider = new AssertableLogProvider(); - QuerySession session = session( SESSION_1_NAME ); - FakeClock clock = getFaceClock(); + QuerySession session = session( SESSION_1_NAME, "TestUser" ); + FakeClock clock = Clocks.fakeClock(); QueryLogger queryLogger = queryLoggerWithoutParams( logProvider, clock ); RuntimeException failure = new RuntimeException(); @@ -135,7 +138,7 @@ public void shouldLogQueryOnFailureEvenIfFasterThanThreshold() throws Exception // then logProvider.assertExactly( inLog( getClass() ) - .error( is( "1 ms: {session one} - MATCH (n) RETURN n" ), sameInstance( failure ) ) + .error( is( "1 ms: {session one} [TestUser] - MATCH (n) RETURN n" ), sameInstance( failure ) ) ); } @@ -144,8 +147,8 @@ public void shouldLogQueryParameters() throws Exception { // given final AssertableLogProvider logProvider = new AssertableLogProvider(); - QuerySession session = session( SESSION_1_NAME ); - FakeClock clock = getFaceClock(); + QuerySession session = session( SESSION_1_NAME, "TestUser" ); + FakeClock clock = Clocks.fakeClock(); QueryLogger queryLogger = queryLoggerWithParams( logProvider, clock ); // when @@ -156,8 +159,9 @@ public void shouldLogQueryParameters() throws Exception queryLogger.endSuccess( session ); // then + String expectedSessionString = String.format( "%s [%s]", SESSION_1_NAME, "TestUser" ); logProvider.assertExactly( - inLog( getClass() ).info( "%d ms: %s - %s - %s", 11L, SESSION_1_NAME, QUERY_4, "{ages: [41, 42, 43]}" ) + inLog( getClass() ).info( "%d ms: %s - %s - %s", 11L, expectedSessionString, QUERY_4, "{ages: [41, 42, 43]}" ) ); } @@ -166,8 +170,8 @@ public void shouldLogQueryParametersOnFailure() throws Exception { // given final AssertableLogProvider logProvider = new AssertableLogProvider(); - QuerySession session = session( SESSION_1_NAME ); - FakeClock clock = getFaceClock(); + QuerySession session = session( SESSION_1_NAME, "TestUser" ); + FakeClock clock = Clocks.fakeClock(); QueryLogger queryLogger = queryLoggerWithParams( logProvider, clock ); RuntimeException failure = new RuntimeException(); @@ -181,14 +185,35 @@ public void shouldLogQueryParametersOnFailure() throws Exception // then logProvider.assertExactly( inLog( getClass() ).error( - is( "1 ms: {session one} - MATCH (n) WHERE n.age IN {ages} RETURN n - {ages: [41, 42, 43]}" ), + is( "1 ms: {session one} [TestUser] - MATCH (n) WHERE n.age IN {ages} RETURN n - {ages: [41, 42, 43]}" ), sameInstance( failure ) ) ); } - private FakeClock getFaceClock() + @Test + public void shouldLogUserName() throws Exception { - return Clocks.fakeClock(); + // given + final AssertableLogProvider logProvider = new AssertableLogProvider(); + FakeClock clock = Clocks.fakeClock(); + QueryLogger queryLogger = queryLoggerWithoutParams( logProvider, clock ); + + // when + QuerySession session = session( SESSION_1_NAME, "TestUser" ); + queryLogger.startQueryExecution( session, QUERY_1, Collections.emptyMap() ); + clock.forward( 10, TimeUnit.MILLISECONDS ); + queryLogger.endSuccess( session ); + + QuerySession anotherSession = session( SESSION_1_NAME, "AnotherUser" ); + queryLogger.startQueryExecution( anotherSession, QUERY_1, Collections.emptyMap() ); + clock.forward( 10, TimeUnit.MILLISECONDS ); + queryLogger.endSuccess( anotherSession ); + + // then + logProvider.assertExactly( + inLog( getClass() ).info( "%d ms: %s - %s", 10L, "{session one} [TestUser]", QUERY_1 ), + inLog( getClass() ).info( "%d ms: %s - %s", 10L, "{session one} [AnotherUser]", QUERY_1 ) + ); } private QueryLogger queryLoggerWithoutParams( LogProvider logProvider, Clock clock ) @@ -201,14 +226,14 @@ private QueryLogger queryLoggerWithParams( LogProvider logProvider, Clock clock return new QueryLogger( clock, logProvider.getLog( getClass() ), 10/*ms*/, true ); } - private static QuerySession session( final String data ) + private static QuerySession session( final String data, final String username ) { return new QuerySession( null ) { @Override public String toString() { - return data; + return String.format( "%s [%s]", data, username ); } }; }