Log on server when backup store copy is made

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> 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> storeId )
+            LogicalTransactionStore logicalTransactionStore, TransactionIdStore transactionIdStore,
+            LogFileInformation logFileInformation, Provider<StoreId> 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,18 +63,29 @@ public Response<Void> 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,
                     copyStartContext.lastAppliedTransaction() + 1, storeCopyServer.monitor() ); // mandatory transaction id
             long optionalTransactionId = copyStartContext.lastAppliedTransaction();
             return responsePacker.packTransactionStreamResponse( anonymous( optionalTransactionId ), null/*no response object*/ );
         }
+        finally
+        {
+            logger.log( "Full backup finished." );
+        }
     }
 
     @Override
     public Response<Void> 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.");
+        }
     }
 }

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<StoreId>()
+                return new BackupImpl( copier, monitors, logicalTransactionStore, transactionIdStore,
+                        logFileInformation, new Provider<StoreId>()
                         {
                             @Override
                             public StoreId instance()
                             {
                                 return graphDatabaseAPI.storeId();
                             }
-                        } );
+                        }, logging );
             }
         }, monitors, logging );
     }

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
     {