From af6cb3e964a9225e6a7b40ef6e6a7c5633d71717 Mon Sep 17 00:00:00 2001 From: Jonas Kalderstam Date: Wed, 1 Jun 2016 16:48:24 +0200 Subject: [PATCH] Log on server when backup store copy is made --- .../java/org/neo4j/backup/BackupImpl.java | 21 ++++++-- .../backup/OnlineBackupKernelExtension.java | 6 +-- .../org/neo4j/backup/BackupServiceIT.java | 54 ++++++++++++++++++- 3 files changed, 73 insertions(+), 8 deletions(-) diff --git a/enterprise/backup/src/main/java/org/neo4j/backup/BackupImpl.java b/enterprise/backup/src/main/java/org/neo4j/backup/BackupImpl.java index 80f0589d7c84d..4899eaf14447a 100644 --- a/enterprise/backup/src/main/java/org/neo4j/backup/BackupImpl.java +++ b/enterprise/backup/src/main/java/org/neo4j/backup/BackupImpl.java @@ -29,6 +29,8 @@ import org.neo4j.kernel.impl.transaction.log.LogFileInformation; import org.neo4j.kernel.impl.transaction.log.LogicalTransactionStore; import org.neo4j.kernel.impl.transaction.log.TransactionIdStore; +import org.neo4j.kernel.logging.ConsoleLogger; +import org.neo4j.kernel.logging.Logging; import org.neo4j.kernel.monitoring.Monitors; import static org.neo4j.com.RequestContext.anonymous; @@ -41,16 +43,18 @@ class BackupImpl implements TheBackupInterface private final Provider storeId; private final TransactionIdStore transactionIdStore; private final LogFileInformation logFileInformation; + private final ConsoleLogger logger; public BackupImpl( StoreCopyServer storeCopyServer, Monitors monitors, - LogicalTransactionStore logicalTransactionStore, TransactionIdStore transactionIdStore, - LogFileInformation logFileInformation, Provider storeId ) + LogicalTransactionStore logicalTransactionStore, TransactionIdStore transactionIdStore, + LogFileInformation logFileInformation, Provider storeId, Logging logging ) { this.storeCopyServer = storeCopyServer; this.logicalTransactionStore = logicalTransactionStore; this.transactionIdStore = transactionIdStore; this.logFileInformation = logFileInformation; this.storeId = storeId; + this.logger = logging.getConsoleLog( getClass() ); this.incrementalResponsePacker = new ResponsePacker( logicalTransactionStore, transactionIdStore, storeId ); } @@ -59,6 +63,7 @@ public Response fullBackup( StoreWriter writer, boolean forensics ) { try ( StoreWriter storeWriter = writer ) { + logger.log( "Full backup started..." ); RequestContext copyStartContext = storeCopyServer.flushStoresAndStreamStoreFiles( storeWriter, forensics ); ResponsePacker responsePacker = new StoreCopyResponsePacker( logicalTransactionStore, transactionIdStore, logFileInformation, storeId, @@ -66,11 +71,21 @@ public Response fullBackup( StoreWriter writer, boolean forensics ) long optionalTransactionId = copyStartContext.lastAppliedTransaction(); return responsePacker.packTransactionStreamResponse( anonymous( optionalTransactionId ), null/*no response object*/ ); } + finally + { + logger.log( "Full backup finished." ); + } } @Override public Response incrementalBackup( RequestContext context ) { - return incrementalResponsePacker.packTransactionStreamResponse( context, null ); + try + { + logger.log("Incremental backup started..."); + return incrementalResponsePacker.packTransactionStreamResponse( context, null ); + } finally { + logger.log("Incremental backup finished."); + } } } diff --git a/enterprise/backup/src/main/java/org/neo4j/backup/OnlineBackupKernelExtension.java b/enterprise/backup/src/main/java/org/neo4j/backup/OnlineBackupKernelExtension.java index 3e8ec5625de67..0d08e393f2629 100644 --- a/enterprise/backup/src/main/java/org/neo4j/backup/OnlineBackupKernelExtension.java +++ b/enterprise/backup/src/main/java/org/neo4j/backup/OnlineBackupKernelExtension.java @@ -91,15 +91,15 @@ public TheBackupInterface newBackup() monitors.newMonitor( StoreCopyServer.Monitor.class ) ); LogicalTransactionStore logicalTransactionStore = resolver.resolveDependency( LogicalTransactionStore.class ); LogFileInformation logFileInformation = resolver.resolveDependency( LogFileInformation.class ); - return new BackupImpl( copier, monitors, - logicalTransactionStore, transactionIdStore, logFileInformation, new Provider() + return new BackupImpl( copier, monitors, logicalTransactionStore, transactionIdStore, + logFileInformation, new Provider() { @Override public StoreId instance() { return graphDatabaseAPI.storeId(); } - } ); + }, logging ); } }, monitors, logging ); } diff --git a/enterprise/backup/src/test/java/org/neo4j/backup/BackupServiceIT.java b/enterprise/backup/src/test/java/org/neo4j/backup/BackupServiceIT.java index 84872bf66f498..884dec2cf09ab 100644 --- a/enterprise/backup/src/test/java/org/neo4j/backup/BackupServiceIT.java +++ b/enterprise/backup/src/test/java/org/neo4j/backup/BackupServiceIT.java @@ -74,8 +74,10 @@ import org.neo4j.kernel.impl.transaction.state.NeoStoreProvider; import org.neo4j.kernel.impl.util.StringLogger; import org.neo4j.kernel.lifecycle.LifeSupport; +import org.neo4j.kernel.logging.ConsoleLogger; import org.neo4j.kernel.logging.DevNullLoggingService; import org.neo4j.kernel.logging.Logging; +import org.neo4j.kernel.logging.SingleLoggingService; import org.neo4j.kernel.logging.SystemOutLogging; import org.neo4j.kernel.monitoring.Monitors; import org.neo4j.test.Barrier; @@ -697,7 +699,7 @@ public void shouldContainTransactionsThatHappenDuringBackupProcess() throws Thro defaultBackupPortHostParams(); Config defaultConfig = dbRule.getConfigCopy(); dbRule.setConfig( OnlineBackupSettings.online_backup_enabled, "false" ); - Config withOnlineBackupEnabled = dbRule.getConfigCopy(); + Config withOnlineBackupDisabled = dbRule.getConfigCopy(); final Barrier.Control barrier = new Barrier.Control(); final GraphDatabaseAPI db = dbRule.getGraphDatabaseAPI(); @@ -737,7 +739,7 @@ public void run() } ); BackupService.BackupOutcome backupOutcome = backupService.doFullBackup( BACKUP_HOST, backupPort, - backupDir.getAbsolutePath(), true, withOnlineBackupEnabled, BackupClient.BIG_READ_TIMEOUT, false ); + backupDir.getAbsolutePath(), true, withOnlineBackupDisabled, BackupClient.BIG_READ_TIMEOUT, false ); backup.stop(); executor.shutdown(); @@ -750,6 +752,54 @@ public void run() assertTrue( backupOutcome.isConsistent() ); } + @Test + public void backupsShouldBeMentionedInServerConsoleLog() throws Throwable + { + // given + defaultBackupPortHostParams(); + Config config = dbRule.getConfigCopy(); + dbRule.setConfig( OnlineBackupSettings.online_backup_enabled, "false" ); + Config withOnlineBackupDisabled = dbRule.getConfigCopy(); + createAndIndexNode( dbRule, 1 ); + + final StringLogger msgLog = mock( StringLogger.class ); + final ConsoleLogger console = mock( ConsoleLogger.class ); + Logging logging = new SingleLoggingService( msgLog ) + { + @Override + public ConsoleLogger getConsoleLog( Class loggingClass ) + { + return console; + } + }; + + OnlineBackupKernelExtension backup = new OnlineBackupKernelExtension( config, dbRule, + dbRule.getDependencyResolver().resolveDependency( KernelPanicEventGenerator.class ), logging, + // ... so that it's used by StoreCopyServer + monitors ); + backup.start(); + + // when + backupService().doFullBackup( BACKUP_HOST, backupPort, backupDir.getAbsolutePath(), false, + withOnlineBackupDisabled, BackupClient.BIG_READ_TIMEOUT, false ); + + // then + verify( console ).log( "Full backup started..." ); + verify( console ).log( "Full backup finished." ); + + // when + createAndIndexNode( dbRule, 2 ); + + backupService().doIncrementalBackupOrFallbackToFull( BACKUP_HOST, backupPort, backupDir.getAbsolutePath(), + false, withOnlineBackupDisabled, BackupClient.BIG_READ_TIMEOUT, false ); + + backup.stop(); + + // then + verify( console ).log( "Incremental backup started..." ); + verify( console ).log( "Incremental backup finished." ); + } + @Test public void incrementalBackupShouldFailWhenTargetDirContainsDifferentStore() throws IOException {