diff --git a/community/kernel/src/main/java/org/neo4j/kernel/NeoStoreDataSource.java b/community/kernel/src/main/java/org/neo4j/kernel/NeoStoreDataSource.java index 754696141ab7b..8aedec9826219 100644 --- a/community/kernel/src/main/java/org/neo4j/kernel/NeoStoreDataSource.java +++ b/community/kernel/src/main/java/org/neo4j/kernel/NeoStoreDataSource.java @@ -487,6 +487,7 @@ public void start() throws IOException dependencies.satisfyDependency( storageEngine.storeReadLayer() ); dependencies.satisfyDependency( logEntryReader ); dependencies.satisfyDependency( storageEngine ); + dependencies.satisfyDependency( transactionLogModule.checkPointing() ); satisfyDependencies( kernelModule ); } catch ( Throwable e ) diff --git a/community/kernel/src/test/java/org/neo4j/kernel/impl/transaction/log/checkpoint/CheckPointerIntegrationTest.java b/community/kernel/src/test/java/org/neo4j/kernel/impl/transaction/log/checkpoint/CheckPointerIntegrationTest.java index f856e7e3e3acc..1a31670daa895 100644 --- a/community/kernel/src/test/java/org/neo4j/kernel/impl/transaction/log/checkpoint/CheckPointerIntegrationTest.java +++ b/community/kernel/src/test/java/org/neo4j/kernel/impl/transaction/log/checkpoint/CheckPointerIntegrationTest.java @@ -27,30 +27,39 @@ import java.io.IOException; import java.util.ArrayList; import java.util.List; -import java.util.concurrent.TimeUnit; - import org.neo4j.graphdb.GraphDatabaseService; import org.neo4j.graphdb.Transaction; import org.neo4j.graphdb.factory.GraphDatabaseBuilder; import org.neo4j.graphdb.factory.GraphDatabaseSettings; import org.neo4j.io.fs.FileSystemAbstraction; import org.neo4j.kernel.impl.transaction.log.LogEntryCursor; +import org.neo4j.kernel.impl.transaction.log.LogFile; +import org.neo4j.kernel.impl.transaction.log.LogPosition; import org.neo4j.kernel.impl.transaction.log.LogVersionedStoreChannel; import org.neo4j.kernel.impl.transaction.log.PhysicalLogFile; import org.neo4j.kernel.impl.transaction.log.PhysicalLogFiles; import org.neo4j.kernel.impl.transaction.log.ReadAheadLogChannel; import org.neo4j.kernel.impl.transaction.log.ReadableClosablePositionAwareChannel; +import org.neo4j.kernel.impl.transaction.log.ReadableLogChannel; import org.neo4j.kernel.impl.transaction.log.entry.CheckPoint; import org.neo4j.kernel.impl.transaction.log.entry.LogEntry; import org.neo4j.kernel.impl.transaction.log.entry.LogEntryReader; import org.neo4j.kernel.impl.transaction.log.entry.VersionAwareLogEntryReader; +import org.neo4j.kernel.internal.GraphDatabaseAPI; import org.neo4j.test.TestGraphDatabaseFactory; import org.neo4j.test.rule.fs.EphemeralFileSystemRule; +import static java.lang.System.currentTimeMillis; import static java.lang.System.getProperty; +import static java.util.concurrent.TimeUnit.SECONDS; + import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertTrue; + import static org.neo4j.kernel.impl.transaction.log.LogVersionBridge.NO_MORE_CHANNELS; import static org.neo4j.kernel.impl.transaction.log.LogVersionRepository.INITIAL_LOG_VERSION; +import static org.neo4j.kernel.impl.transaction.log.entry.LogHeader.LOG_HEADER_SIZE; public class CheckPointerIntegrationTest { @@ -92,9 +101,9 @@ public void databaseShutdownDuringConstantCheckPointing() throws public void shouldCheckPointBasedOnTime() throws Throwable { // given - long seconds = 3; + long millis = 200; GraphDatabaseService db = builder - .setConfig( GraphDatabaseSettings.check_point_interval_time, seconds + "s" ) + .setConfig( GraphDatabaseSettings.check_point_interval_time, millis + "ms" ) .setConfig( GraphDatabaseSettings.check_point_interval_tx, "10000" ) .setConfig( GraphDatabaseSettings.logical_log_rotation_threshold, "1g" ) .newGraphDatabase(); @@ -106,25 +115,48 @@ public void shouldCheckPointBasedOnTime() throws Throwable tx.success(); } - // trigger the check point - TimeUnit.SECONDS.sleep( seconds ); - - // give a chance to the check pointer to be scheduled and run... - TimeUnit.SECONDS.sleep( 1 ); + // The scheduled job checking whether or not checkpoints are needed runs more frequently + // now that we've set the time interval so low, so we can simply wait for it here + long endTime = currentTimeMillis() + SECONDS.toMillis( 30 ); + while ( !checkPointInTxLog( db ) ) + { + Thread.sleep( millis ); + assertTrue( "Took too long to produce a checkpoint", currentTimeMillis() < endTime ); + } db.shutdown(); // then - 2 check points have been written in the log List checkPoints = new CheckPointCollector( storeDir, fs ).find( 0 ); - assertEquals( 2, checkPoints.size() ); + assertTrue( "Expected at least two (at least one for time interval and one for shutdown), was " + + checkPoints.toString(), checkPoints.size() >= 2 ); + } + + private boolean checkPointInTxLog( GraphDatabaseService db ) throws IOException + { + LogFile logFile = ((GraphDatabaseAPI)db).getDependencyResolver().resolveDependency( LogFile.class ); + try ( ReadableLogChannel reader = logFile.getReader( new LogPosition( 0, LOG_HEADER_SIZE ) ) ) + { + LogEntryReader logEntryReader = new VersionAwareLogEntryReader<>(); + LogEntry entry = null; + while ( (entry = logEntryReader.readLogEntry( reader )) != null ) + { + if ( entry instanceof CheckPoint ) + { + return true; + } + } + return false; + } } @Test public void shouldCheckPointBasedOnTxCount() throws Throwable { // given - GraphDatabaseService db = builder.setConfig( GraphDatabaseSettings.check_point_interval_time, "300m" ) + GraphDatabaseService db = builder + .setConfig( GraphDatabaseSettings.check_point_interval_time, "300m" ) .setConfig( GraphDatabaseSettings.check_point_interval_tx, "1" ) .setConfig( GraphDatabaseSettings.logical_log_rotation_threshold, "1g" ) .newGraphDatabase(); @@ -136,8 +168,10 @@ public void shouldCheckPointBasedOnTxCount() throws Throwable tx.success(); } - // give a chance to the check pointer to be scheduled and run... - TimeUnit.SECONDS.sleep( 11 ); + // Instead of waiting 10s for the background job to do this check, perform the check right here + triggerCheckPointAttempt( db ); + + assertTrue( checkPointInTxLog( db ) ); db.shutdown(); @@ -151,9 +185,8 @@ public void shouldCheckPointBasedOnTxCount() throws Throwable public void shouldNotCheckPointWhenThereAreNoCommits() throws Throwable { // given - long seconds = 1; GraphDatabaseService db = builder - .setConfig( GraphDatabaseSettings.check_point_interval_time, seconds + "s" ) + .setConfig( GraphDatabaseSettings.check_point_interval_time, "1s" ) .setConfig( GraphDatabaseSettings.check_point_interval_tx, "10000" ) .setConfig( GraphDatabaseSettings.logical_log_rotation_threshold, "1g" ) .newGraphDatabase(); @@ -162,11 +195,8 @@ public void shouldNotCheckPointWhenThereAreNoCommits() throws Throwable // nothing happens - // trigger the check point - TimeUnit.SECONDS.sleep( seconds ); - - // give a chance to the check pointer to be scheduled and run... - TimeUnit.SECONDS.sleep( 1 ); + triggerCheckPointAttempt( db ); + assertFalse( checkPointInTxLog( db ) ); db.shutdown(); @@ -195,6 +225,14 @@ public void shouldBeAbleToStartAndShutdownMultipleTimesTheDBWithoutCommittingTra assertEquals( 2, checkPoints.size() ); } + private void triggerCheckPointAttempt( GraphDatabaseService db ) throws Exception + { + // Simulates triggering the checkpointer background job which runs now and then, checking whether + // or not there's a need to perform a checkpoint. + ((GraphDatabaseAPI)db).getDependencyResolver().resolveDependency( CheckPointer.class ).checkPointIfNeeded( + new SimpleTriggerInfo( "Test" ) ); + } + private static class CheckPointCollector { private final PhysicalLogFiles logFiles;