Skip to content

Commit

Permalink
Faster CheckPointerIntegrationTest
Browse files Browse the repository at this point in the history
by not waiting unnecessarily for the job scheduling in neo4j,
but instead being more proactive.
  • Loading branch information
tinwelint committed Sep 19, 2016
1 parent 2dae86d commit 544d2c3
Show file tree
Hide file tree
Showing 2 changed files with 59 additions and 20 deletions.
Expand Up @@ -487,6 +487,7 @@ public void start() throws IOException
dependencies.satisfyDependency( storageEngine.storeReadLayer() ); dependencies.satisfyDependency( storageEngine.storeReadLayer() );
dependencies.satisfyDependency( logEntryReader ); dependencies.satisfyDependency( logEntryReader );
dependencies.satisfyDependency( storageEngine ); dependencies.satisfyDependency( storageEngine );
dependencies.satisfyDependency( transactionLogModule.checkPointing() );
satisfyDependencies( kernelModule ); satisfyDependencies( kernelModule );
} }
catch ( Throwable e ) catch ( Throwable e )
Expand Down
Expand Up @@ -27,30 +27,39 @@
import java.io.IOException; import java.io.IOException;
import java.util.ArrayList; import java.util.ArrayList;
import java.util.List; import java.util.List;
import java.util.concurrent.TimeUnit;

import org.neo4j.graphdb.GraphDatabaseService; import org.neo4j.graphdb.GraphDatabaseService;
import org.neo4j.graphdb.Transaction; import org.neo4j.graphdb.Transaction;
import org.neo4j.graphdb.factory.GraphDatabaseBuilder; import org.neo4j.graphdb.factory.GraphDatabaseBuilder;
import org.neo4j.graphdb.factory.GraphDatabaseSettings; import org.neo4j.graphdb.factory.GraphDatabaseSettings;
import org.neo4j.io.fs.FileSystemAbstraction; import org.neo4j.io.fs.FileSystemAbstraction;
import org.neo4j.kernel.impl.transaction.log.LogEntryCursor; 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.LogVersionedStoreChannel;
import org.neo4j.kernel.impl.transaction.log.PhysicalLogFile; import org.neo4j.kernel.impl.transaction.log.PhysicalLogFile;
import org.neo4j.kernel.impl.transaction.log.PhysicalLogFiles; import org.neo4j.kernel.impl.transaction.log.PhysicalLogFiles;
import org.neo4j.kernel.impl.transaction.log.ReadAheadLogChannel; import org.neo4j.kernel.impl.transaction.log.ReadAheadLogChannel;
import org.neo4j.kernel.impl.transaction.log.ReadableClosablePositionAwareChannel; 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.CheckPoint;
import org.neo4j.kernel.impl.transaction.log.entry.LogEntry; 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.LogEntryReader;
import org.neo4j.kernel.impl.transaction.log.entry.VersionAwareLogEntryReader; import org.neo4j.kernel.impl.transaction.log.entry.VersionAwareLogEntryReader;
import org.neo4j.kernel.internal.GraphDatabaseAPI;
import org.neo4j.test.TestGraphDatabaseFactory; import org.neo4j.test.TestGraphDatabaseFactory;
import org.neo4j.test.rule.fs.EphemeralFileSystemRule; import org.neo4j.test.rule.fs.EphemeralFileSystemRule;


import static java.lang.System.currentTimeMillis;
import static java.lang.System.getProperty; import static java.lang.System.getProperty;
import static java.util.concurrent.TimeUnit.SECONDS;

import static org.junit.Assert.assertEquals; 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.LogVersionBridge.NO_MORE_CHANNELS;
import static org.neo4j.kernel.impl.transaction.log.LogVersionRepository.INITIAL_LOG_VERSION; 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 public class CheckPointerIntegrationTest
{ {
Expand Down Expand Up @@ -92,9 +101,9 @@ public void databaseShutdownDuringConstantCheckPointing() throws
public void shouldCheckPointBasedOnTime() throws Throwable public void shouldCheckPointBasedOnTime() throws Throwable
{ {
// given // given
long seconds = 3; long millis = 200;
GraphDatabaseService db = builder 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.check_point_interval_tx, "10000" )
.setConfig( GraphDatabaseSettings.logical_log_rotation_threshold, "1g" ) .setConfig( GraphDatabaseSettings.logical_log_rotation_threshold, "1g" )
.newGraphDatabase(); .newGraphDatabase();
Expand All @@ -106,25 +115,48 @@ public void shouldCheckPointBasedOnTime() throws Throwable
tx.success(); tx.success();
} }


// trigger the check point // The scheduled job checking whether or not checkpoints are needed runs more frequently
TimeUnit.SECONDS.sleep( seconds ); // now that we've set the time interval so low, so we can simply wait for it here

long endTime = currentTimeMillis() + SECONDS.toMillis( 30 );
// give a chance to the check pointer to be scheduled and run... while ( !checkPointInTxLog( db ) )
TimeUnit.SECONDS.sleep( 1 ); {
Thread.sleep( millis );
assertTrue( "Took too long to produce a checkpoint", currentTimeMillis() < endTime );
}


db.shutdown(); db.shutdown();


// then - 2 check points have been written in the log // then - 2 check points have been written in the log
List<CheckPoint> checkPoints = new CheckPointCollector( storeDir, fs ).find( 0 ); List<CheckPoint> 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<ReadableClosablePositionAwareChannel> logEntryReader = new VersionAwareLogEntryReader<>();
LogEntry entry = null;
while ( (entry = logEntryReader.readLogEntry( reader )) != null )
{
if ( entry instanceof CheckPoint )
{
return true;
}
}
return false;
}
} }


@Test @Test
public void shouldCheckPointBasedOnTxCount() throws Throwable public void shouldCheckPointBasedOnTxCount() throws Throwable
{ {
// given // 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.check_point_interval_tx, "1" )
.setConfig( GraphDatabaseSettings.logical_log_rotation_threshold, "1g" ) .setConfig( GraphDatabaseSettings.logical_log_rotation_threshold, "1g" )
.newGraphDatabase(); .newGraphDatabase();
Expand All @@ -136,8 +168,10 @@ public void shouldCheckPointBasedOnTxCount() throws Throwable
tx.success(); tx.success();
} }


// give a chance to the check pointer to be scheduled and run... // Instead of waiting 10s for the background job to do this check, perform the check right here
TimeUnit.SECONDS.sleep( 11 ); triggerCheckPointAttempt( db );

assertTrue( checkPointInTxLog( db ) );


db.shutdown(); db.shutdown();


Expand All @@ -151,9 +185,8 @@ public void shouldCheckPointBasedOnTxCount() throws Throwable
public void shouldNotCheckPointWhenThereAreNoCommits() throws Throwable public void shouldNotCheckPointWhenThereAreNoCommits() throws Throwable
{ {
// given // given
long seconds = 1;
GraphDatabaseService db = builder 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.check_point_interval_tx, "10000" )
.setConfig( GraphDatabaseSettings.logical_log_rotation_threshold, "1g" ) .setConfig( GraphDatabaseSettings.logical_log_rotation_threshold, "1g" )
.newGraphDatabase(); .newGraphDatabase();
Expand All @@ -162,11 +195,8 @@ public void shouldNotCheckPointWhenThereAreNoCommits() throws Throwable


// nothing happens // nothing happens


// trigger the check point triggerCheckPointAttempt( db );
TimeUnit.SECONDS.sleep( seconds ); assertFalse( checkPointInTxLog( db ) );

// give a chance to the check pointer to be scheduled and run...
TimeUnit.SECONDS.sleep( 1 );


db.shutdown(); db.shutdown();


Expand Down Expand Up @@ -195,6 +225,14 @@ public void shouldBeAbleToStartAndShutdownMultipleTimesTheDBWithoutCommittingTra
assertEquals( 2, checkPoints.size() ); 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 static class CheckPointCollector
{ {
private final PhysicalLogFiles logFiles; private final PhysicalLogFiles logFiles;
Expand Down

0 comments on commit 544d2c3

Please sign in to comment.