Report tracing events on statement force close,

forcefully close statement after transaction commit or rollback only to catch all tracing events that can happen during transaction close.

community/io/src/main/java/org/neo4j/io/pagecache/impl/muninn/MuninnPageCursor.java

@@ -131,7 +131,6 @@ public final void close()
             if ( cursor.pagedFile != null )
             {
                 cursor.unpinCurrentPage();
-                cursor.tracer.reportEvents();
                 cursor.releaseCursor();
                 // We null out the pagedFile field to allow it and its (potentially big) translation table to be garbage
                 // collected when the file is unmapped, since the cursors can stick around in thread local caches, etc.

community/io/src/main/java/org/neo4j/io/pagecache/tracing/cursor/DefaultPageCursorTracer.java

@@ -31,15 +31,6 @@
 
 public class DefaultPageCursorTracer implements PageCursorTracer
 {
-    private long totalPins = 0L;
-    private long totalUnpins = 0L;
-    private long totalFaults = 0L;
-    private long totalBytesRead = 0L;
-    private long totalBytesWritten = 0L;
-    private long totalEvictions = 0L;
-    private long totalEvictionExceptions = 0L;
-    private long totalFlushes = 0L;
-
     private long pins;
     private long unpins;
     private long faults;
@@ -91,19 +82,11 @@ public void reportEvents()
         {
             pageCacheTracer.flushes( flushes );
         }
-        updateTotals();
+        reset();
     }
 
-    private void updateTotals()
+    private void reset()
     {
-        this.totalPins += pins;
-        this.totalUnpins += unpins;
-        this.totalFaults += faults;
-        this.totalBytesRead += bytesRead;
-        this.totalBytesWritten += bytesWritten;
-        this.totalEvictions += evictions;
-        this.totalEvictionExceptions += evictionExceptions;
-        this.totalFlushes += flushes;
         pins = 0;
         unpins = 0;
         faults = 0;
@@ -117,49 +100,49 @@ private void updateTotals()
     @Override
     public long faults()
     {
-        return totalFaults + faults;
+        return faults;
     }
 
     @Override
     public long pins()
     {
-        return totalPins + pins;
+        return pins;
     }
 
     @Override
     public long unpins()
     {
-        return totalUnpins + unpins;
+        return unpins;
     }
 
     @Override
     public long bytesRead()
     {
-        return totalBytesRead + bytesRead;
+        return bytesRead;
     }
 
     @Override
     public long evictions()
     {
-        return totalEvictions + evictions;
+        return evictions;
     }
 
     @Override
     public long evictionExceptions()
     {
-        return totalEvictionExceptions + evictionExceptions;
+        return evictionExceptions;
     }
 
     @Override
     public long bytesWritten()
     {
-        return totalBytesWritten + bytesWritten;
+        return bytesWritten;
     }
 
     @Override
     public long flushes()
     {
-        return totalFlushes + flushes;
+        return flushes;
     }
 
     @Override

community/io/src/test/java/org/neo4j/io/pagecache/PageCacheTest.java

@@ -2115,7 +2115,8 @@ public void tracerMustBeNotifiedAboutPinUnpinFaultAndEvictEventsWhenReading() th
         DefaultPageCacheTracer tracer = new DefaultPageCacheTracer();
         generateFileWithRecords( file( "a" ), recordCount, recordSize );
 
-        getPageCache( fs, maxPages, pageCachePageSize, tracer, DefaultPageCursorTracerSupplier.INSTANCE );
+        DefaultPageCursorTracerSupplier cursorTracerSupplier = DefaultPageCursorTracerSupplier.INSTANCE;
+        getPageCache( fs, maxPages, pageCachePageSize, tracer, cursorTracerSupplier );
 
         long countedPages = 0;
         long countedFaults = 0;
@@ -2145,6 +2146,8 @@ public void tracerMustBeNotifiedAboutPinUnpinFaultAndEvictEventsWhenReading() th
             }
         }
 
+        cursorTracerSupplier.get().reportEvents();
+
         assertThat( "wrong count of pins", tracer.pins(), is( countedPages ) );
         assertThat( "wrong count of unpins", tracer.unpins(), is( countedPages ) );
 
@@ -2172,7 +2175,8 @@ public void tracerMustBeNotifiedAboutPinUnpinFaultFlushAndEvictionEventsWhenWrit
         long pagesToGenerate = 142;
         DefaultPageCacheTracer tracer = new DefaultPageCacheTracer();
 
-        getPageCache( fs, maxPages, pageCachePageSize, tracer, DefaultPageCursorTracerSupplier.INSTANCE );
+        DefaultPageCursorTracerSupplier tracerSupplier = DefaultPageCursorTracerSupplier.INSTANCE;
+        getPageCache( fs, maxPages, pageCachePageSize, tracer, tracerSupplier );
 
         try ( PagedFile pagedFile = pageCache.map( file( "a" ), filePageSize );
               PageCursor cursor = pagedFile.io( 0, PF_SHARED_WRITE_LOCK ) )
@@ -2191,6 +2195,7 @@ public void tracerMustBeNotifiedAboutPinUnpinFaultFlushAndEvictionEventsWhenWrit
             assertTrue( cursor.next( 0 ) );
             assertTrue( cursor.next( 0 ) );
         }
+        tracerSupplier.get().reportEvents();
 
         assertThat( "wrong count of pins", tracer.pins(), is( pagesToGenerate + 1 ) );
         assertThat( "wrong count of unpins", tracer.unpins(), is( pagesToGenerate + 1 ) );

community/io/src/test/java/org/neo4j/io/pagecache/impl/muninn/MuninnPageCacheTest.java

@@ -103,6 +103,7 @@ public void mustEvictCleanPageWithoutFlushing() throws Exception
         {
             assertTrue( cursor.next() );
         }
+        cursorTracer.reportEvents();
         assertNotNull( cursorTracer.observe( Fault.class ) );
         assertEquals( 1, cursorTracer.faults() );
         assertEquals( 1, tracer.faults() );
@@ -140,6 +141,7 @@ public void mustFlushDirtyPagesOnEvictingFirstPage() throws Exception
             assertTrue( cursor.next() );
             cursor.putLong( 0L );
         }
+        cursorTracer.reportEvents();
         assertNotNull( cursorTracer.observe( Fault.class ) );
         assertEquals( 1, cursorTracer.faults() );
         assertEquals( 1, tracer.faults() );
@@ -173,6 +175,7 @@ public void mustFlushDirtyPagesOnEvictingLastPage() throws Exception
             assertTrue( cursor.next() );
             cursor.putLong( 0L );
         }
+        cursorTracer.reportEvents();
         assertNotNull( cursorTracer.observe( Fault.class ) );
         assertEquals( 1, cursorTracer.faults() );
         assertEquals( 1, tracer.faults() );
@@ -209,6 +212,7 @@ public void mustFlushDirtyPagesOnEvictingAllPages() throws Exception
             cursor.putLong( 0L );
             assertFalse( cursor.next() );
         }
+        cursorTracer.reportEvents();
         assertNotNull( cursorTracer.observe( Fault.class ) );
         assertNotNull( cursorTracer.observe( Fault.class ) );
         assertEquals( 2, cursorTracer.faults() );

community/kernel/src/main/java/org/neo4j/kernel/impl/api/KernelStatement.java

@@ -24,7 +24,7 @@
 
 import org.neo4j.graphdb.NotInTransactionException;
 import org.neo4j.graphdb.TransactionTerminatedException;
-import org.neo4j.io.pagecache.tracing.cursor.PageCursorCounters;
+import org.neo4j.io.pagecache.tracing.cursor.PageCursorTracer;
 import org.neo4j.kernel.api.DataWriteOperations;
 import org.neo4j.kernel.api.query.ExecutingQuery;
 import org.neo4j.kernel.api.ProcedureCallOperations;
@@ -53,14 +53,14 @@
  * <ol>
  * <li>Construct {@link KernelStatement} when {@link KernelTransactionImplementation} is constructed</li>
  * <li>For every transaction...</li>
- * <li>Call {@link #initialize(StatementLocks, StatementOperationParts, PageCursorCounters)} which makes this instance
+ * <li>Call {@link #initialize(StatementLocks, StatementOperationParts, PageCursorTracer)} which makes this instance
  * full available and ready to use. Call when the {@link KernelTransactionImplementation} is initialized.</li>
  * <li>Alternate {@link #acquire()} / {@link #close()} when acquiring / closing a statement for the transaction...
  * Temporarily asymmetric number of calls to {@link #acquire()} / {@link #close()} is supported, although in
  * the end an equal number of calls must have been issued.</li>
  * <li>To be safe call {@link #forceClose()} at the end of a transaction to force a close of the statement,
  * even if there are more than one current call to {@link #acquire()}. This instance is now again ready
- * to be {@link #initialize(StatementLocks, StatementOperationParts, PageCursorCounters)}  initialized} and used for the transaction
+ * to be {@link #initialize(StatementLocks, StatementOperationParts, PageCursorTracer)}  initialized} and used for the transaction
  * instance again, when it's initialized.</li>
  * </ol>
  */
@@ -72,7 +72,7 @@ public class KernelStatement implements TxStateHolder, Statement
     private final KernelTransactionImplementation transaction;
     private final OperationsFacade facade;
     private StatementLocks statementLocks;
-    private PageCursorCounters pageCursorCounters;
+    private PageCursorTracer pageCursorTracer = PageCursorTracer.NULL;
     private int referenceCount;
     private volatile ExecutingQueryList executingQueryList;
     private final LockTracer systemLockTracer;
@@ -186,10 +186,10 @@ void assertOpen()
     }
 
     public void initialize( StatementLocks statementLocks, StatementOperationParts operationParts,
-            PageCursorCounters pageCursorCounters )
+            PageCursorTracer pageCursorCounters )
     {
         this.statementLocks = statementLocks;
-        this.pageCursorCounters = pageCursorCounters;
+        this.pageCursorTracer = pageCursorCounters;
         facade.initialize( operationParts );
     }
 
@@ -204,9 +204,9 @@ public LockTracer lockTracer()
         return tracer == null ? systemLockTracer : systemLockTracer.combine( tracer );
     }
 
-    public PageCursorCounters getPageCursorCounters()
+    public PageCursorTracer getPageCursorTracer()
     {
-        return pageCursorCounters;
+        return pageCursorTracer;
     }
 
     public final void acquire()
@@ -229,6 +229,7 @@ final void forceClose()
             referenceCount = 0;
             cleanupResources();
         }
+        pageCursorTracer.reportEvents();
     }
 
     final String username()

community/kernel/src/main/java/org/neo4j/kernel/impl/api/KernelTransactionImplementation.java

@@ -445,7 +445,6 @@ public long closeTransaction() throws TransactionFailureException
     {
         assertTransactionOpen();
         assertTransactionNotClosing();
-        closeCurrentStatementIfAny();
         closing = true;
         try
         {

community/neo4j/src/test/java/org/neo4j/tracers/PageCacheCountersIT.java

@@ -49,7 +49,8 @@
 import org.neo4j.test.rule.RepeatRule;
 import org.neo4j.test.rule.TestDirectory;
 
-import static org.junit.Assert.assertEquals;
+import static org.hamcrest.Matchers.greaterThanOrEqualTo;
+import static org.junit.Assert.assertThat;
 
 public class PageCacheCountersIT
 {
@@ -92,23 +93,23 @@ public void pageCacheCountersAreSumOfPageCursorCounters() throws Exception
         long initialFlushes = pageCacheTracer.flushes();
 
         startNodeCreators( nodeCreators, nodeCreatorFutures );
-        TimeUnit.MILLISECONDS.sleep( 250 );
+        TimeUnit.MILLISECONDS.sleep( 50 );
         stopNodeCreators( nodeCreators, nodeCreatorFutures );
 
-        assertEquals( "Number of pins events in page cache tracer should equal to the sum of pin events in page " +
-                        "cursor tracers.", pageCacheTracer.pins(), sumCounters( nodeCreators, NodeCreator::getPins, initialPins ) );
-        assertEquals( "Number of unpins events in page cache tracer should equal to the sum of unpin events in page " +
-                        "cursor tracers.", pageCacheTracer.unpins(), sumCounters( nodeCreators, NodeCreator::getUnpins, initialUnpins ) );
-        assertEquals( "Number of initialBytesRead in page cache tracer should equal to the sum of initialBytesRead in page " +
-                        "cursor tracers.", pageCacheTracer.bytesRead(), sumCounters( nodeCreators, NodeCreator::getBytesRead, initialBytesRead ) );
-        assertEquals( "Number of bytesWritten in page cache tracer should equal to the sum of bytesWritten in " +
-                        "page cursor tracers.", pageCacheTracer.bytesWritten(), sumCounters( nodeCreators, NodeCreator::getBytesWritten, initialBytesWritten ) );
-        assertEquals( "Number of evictions in page cache tracer should equal to the sum of evictions in " +
-                        "page cursor tracers.", pageCacheTracer.evictions(), sumCounters( nodeCreators, NodeCreator::getEvictions, initialEvictions ) );
-        assertEquals( "Number of faults in page cache tracer should equal to the sum of faults in " + "page cursor tracers.",
-                pageCacheTracer.faults(), sumCounters( nodeCreators, NodeCreator::getFaults, initialFaults ) );
-        assertEquals( "Number of flushes in page cache tracer should equal to the sum of flushes in " +
-                        "page cursor tracers.", pageCacheTracer.flushes(), sumCounters( nodeCreators, NodeCreator::getFlushes, initialFlushes ) );
+        assertThat( "Number of pins events in page cache tracer should equal to the sum of pin events in page cursor tracers.",
+                    pageCacheTracer.pins(), greaterThanOrEqualTo( sumCounters( nodeCreators, NodeCreator::getPins, initialPins ) ) );
+        assertThat( "Number of unpins events in page cache tracer should equal to the sum of unpin events in page cursor tracers.",
+                pageCacheTracer.unpins(), greaterThanOrEqualTo( sumCounters( nodeCreators, NodeCreator::getUnpins, initialUnpins ) ) );
+        assertThat( "Number of initialBytesRead in page cache tracer should equal to the sum of initialBytesRead in page cursor tracers.",
+                pageCacheTracer.bytesRead(), greaterThanOrEqualTo( sumCounters( nodeCreators, NodeCreator::getBytesRead, initialBytesRead ) ) );
+        assertThat( "Number of bytesWritten in page cache tracer should equal to the sum of bytesWritten in page cursor tracers.",
+                pageCacheTracer.bytesWritten(), greaterThanOrEqualTo( sumCounters( nodeCreators, NodeCreator::getBytesWritten, initialBytesWritten ) ) );
+        assertThat( "Number of evictions in page cache tracer should equal to the sum of evictions in page cursor tracers.",
+                pageCacheTracer.evictions(), greaterThanOrEqualTo( sumCounters( nodeCreators, NodeCreator::getEvictions, initialEvictions ) ) );
+        assertThat( "Number of faults in page cache tracer should equal to the sum of faults in " + "page cursor tracers.",
+                pageCacheTracer.faults(), greaterThanOrEqualTo( sumCounters( nodeCreators, NodeCreator::getFaults, initialFaults ) ) );
+        assertThat( "Number of flushes in page cache tracer should equal to the sum of flushes in page cursor tracers.",
+                pageCacheTracer.flushes(), greaterThanOrEqualTo( sumCounters( nodeCreators, NodeCreator::getFlushes, initialFlushes ) ) );
     }
 
     private void stopNodeCreators( List<NodeCreator> nodeCreators, List<Future> nodeCreatorFutures )
@@ -133,7 +134,7 @@ private void startNodeCreators( List<NodeCreator> nodeCreators, List<Future> nod
 
     private long sumCounters(  List<NodeCreator> nodeCreators, ToLongFunction<NodeCreator> mapper, long initialValue )
     {
-        return nodeCreators.stream().mapToLong( mapper ).reduce( initialValue, Long::sum );
+        return nodeCreators.stream().mapToLong( mapper ).sum() + initialValue;
     }
 
     private PageCacheTracer getPageCacheTracer( GraphDatabaseService db )
@@ -169,27 +170,27 @@ public void run()
                 try ( Transaction transaction = db.beginTx() )
                 {
                     KernelStatement kernelStatement = getKernelStatement( (GraphDatabaseAPI) db );
-                    pageCursorCounters = kernelStatement.getPageCursorCounters();
+                    pageCursorCounters = kernelStatement.getPageCursorTracer();
                     Node node = db.createNode();
                     node.setProperty( "name", RandomStringUtils.random( localRandom.nextInt( 100 ) ) );
                     node.setProperty( "surname", RandomStringUtils.random( localRandom.nextInt( 100 ) ) );
                     node.setProperty( "age", localRandom.nextInt( 100 ) );
                     transaction.success();
+                    storeCounters( pageCursorCounters );
                 }
-                storeCounters( pageCursorCounters );
             }
         }
 
         private void storeCounters( PageCursorCounters pageCursorCounters )
         {
             Objects.nonNull( pageCursorCounters );
-            pins = pageCursorCounters.pins();
-            unpins = pageCursorCounters.unpins();
-            bytesRead = pageCursorCounters.bytesRead();
-            bytesWritten = pageCursorCounters.bytesWritten();
-            evictions = pageCursorCounters.evictions();
-            faults = pageCursorCounters.faults();
-            flushes = pageCursorCounters.flushes();
+            pins +=pageCursorCounters.pins();
+            unpins += pageCursorCounters.unpins();
+            bytesRead += pageCursorCounters.bytesRead();
+            bytesWritten += pageCursorCounters.bytesWritten();
+            evictions += pageCursorCounters.evictions();
+            faults += pageCursorCounters.faults();
+            flushes += pageCursorCounters.flushes();
         }
 
         @Override