Schema index logging with monitor

community/kernel/src/main/java/org/neo4j/kernel/api/index/LoggingMonitor.java

@@ -0,0 +1,53 @@
+/*
+ * Copyright (c) 2002-2017 "Neo Technology,"
+ * Network Engine for Objects in Lund AB [http://neotechnology.com]
+ *
+ * This file is part of Neo4j.
+ *
+ * Neo4j is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation, either version 3 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program.  If not, see <http://www.gnu.org/licenses/>.
+ */
+package org.neo4j.kernel.api.index;
+
+import java.util.Map;
+
+import org.neo4j.kernel.api.schema.index.IndexDescriptor;
+import org.neo4j.logging.Log;
+
+import static java.lang.String.format;
+
+public class LoggingMonitor implements SchemaIndexProvider.Monitor
+{
+    private final Log log;
+
+    public LoggingMonitor( Log log )
+    {
+        this.log = log;
+    }
+
+    @Override
+    public void failedToOpenIndex( long indexId, IndexDescriptor indexDescriptor, String action, Exception cause )
+    {
+        log.error( "Failed to open index:" + indexId + ". " + action, cause );
+    }
+
+    @Override
+    public void recoveryCompleted( long indexId, IndexDescriptor indexDescriptor, Map<String,Object> data )
+    {
+        StringBuilder builder =
+                new StringBuilder(
+                        "Schema index recovery completed: indexId: " + indexId + " descriptor: " + indexDescriptor.toString() );
+        data.forEach( ( key, value ) -> builder.append( format( " %s: %s", key, value ) ) );
+        log.info( builder.toString() );
+    }
+}

community/kernel/src/main/java/org/neo4j/kernel/api/index/SchemaIndexProvider.java

@@ -21,6 +21,7 @@
 
 import java.io.File;
 import java.io.IOException;
+import java.util.Map;
 
 import org.neo4j.graphdb.ResourceIterator;
 import org.neo4j.helpers.collection.Iterators;
@@ -92,6 +93,28 @@
  */
 public abstract class SchemaIndexProvider extends LifecycleAdapter implements Comparable<SchemaIndexProvider>
 {
+    public interface Monitor
+    {
+        Monitor EMPTY = new Monitor.Adaptor();
+
+        class Adaptor implements Monitor
+        {
+            @Override
+            public void failedToOpenIndex( long indexId, IndexDescriptor indexDescriptor, String action, Exception cause )
+            {   // no-op
+            }
+
+            @Override
+            public void recoveryCompleted( long indexId, IndexDescriptor indexDescriptor, Map<String,Object> data )
+            {   // no-op
+            }
+        }
+
+        void failedToOpenIndex( long indexId, IndexDescriptor indexDescriptor, String action, Exception cause );
+
+        void recoveryCompleted( long indexId, IndexDescriptor indexDescriptor, Map<String,Object> data );
+    }
+
     public static final SchemaIndexProvider NO_INDEX_PROVIDER =
             new SchemaIndexProvider( new Descriptor( "no-index-provider", "1.0" ), -1, IndexDirectoryStructure.NONE )
             {

community/kernel/src/main/java/org/neo4j/kernel/impl/index/schema/NativeNonUniqueSchemaNumberIndexPopulator.java

@@ -27,11 +27,11 @@
 import org.neo4j.io.fs.FileSystemAbstraction;
 import org.neo4j.io.pagecache.PageCache;
 import org.neo4j.kernel.api.index.IndexEntryUpdate;
+import org.neo4j.kernel.api.index.SchemaIndexProvider;
 import org.neo4j.kernel.api.schema.index.IndexDescriptor;
 import org.neo4j.kernel.impl.api.index.sampling.DefaultNonUniqueIndexSampler;
 import org.neo4j.kernel.impl.api.index.sampling.IndexSamplingConfig;
 import org.neo4j.kernel.impl.api.index.sampling.NonUniqueIndexSampler;
-import org.neo4j.logging.Log;
 import org.neo4j.storageengine.api.schema.IndexSample;
 
 /**
@@ -45,9 +45,9 @@ class NativeNonUniqueSchemaNumberIndexPopulator<KEY extends SchemaNumberKey, VAL
     private NonUniqueIndexSampler sampler;
 
     NativeNonUniqueSchemaNumberIndexPopulator( PageCache pageCache, FileSystemAbstraction fs, File storeFile, Layout<KEY,VALUE> layout,
-            IndexSamplingConfig samplingConfig, Log log, IndexDescriptor descriptor, long indexId )
+            IndexSamplingConfig samplingConfig, SchemaIndexProvider.Monitor monitor, IndexDescriptor descriptor, long indexId )
     {
-        super( pageCache, fs, storeFile, layout, log, descriptor, indexId );
+        super( pageCache, fs, storeFile, layout, monitor, descriptor, indexId );
         this.samplingConfig = samplingConfig;
         this.sampler = new DefaultNonUniqueIndexSampler( samplingConfig.sampleSizeLimit() );
     }

community/kernel/src/main/java/org/neo4j/kernel/impl/index/schema/NativeSchemaNumberIndex.java

@@ -30,11 +30,12 @@
 import org.neo4j.io.fs.FileSystemAbstraction;
 import org.neo4j.io.pagecache.PageCache;
 import org.neo4j.io.pagecache.PageCursor;
+import org.neo4j.kernel.api.index.SchemaIndexProvider;
 import org.neo4j.kernel.api.schema.index.IndexDescriptor;
 import org.neo4j.kernel.impl.index.GBPTreeFileUtil;
-import org.neo4j.logging.Log;
 
 import static org.neo4j.helpers.Format.duration;
+import static org.neo4j.helpers.collection.MapUtil.map;
 import static org.neo4j.index.internal.gbptree.GBPTree.NO_HEADER_READER;
 
 class NativeSchemaNumberIndex<KEY extends SchemaNumberKey, VALUE extends SchemaNumberValue>
@@ -43,22 +44,22 @@ class NativeSchemaNumberIndex<KEY extends SchemaNumberKey, VALUE extends SchemaN
     final File storeFile;
     final Layout<KEY,VALUE> layout;
     final GBPTreeFileUtil gbpTreeFileUtil;
-    private final Log log;
     private final IndexDescriptor descriptor;
     private final long indexId;
+    private final SchemaIndexProvider.Monitor monitor;
 
     GBPTree<KEY,VALUE> tree;
 
-    NativeSchemaNumberIndex( PageCache pageCache, FileSystemAbstraction fs, File storeFile, Layout<KEY,VALUE> layout, Log log,
-            IndexDescriptor descriptor, long indexId )
+    NativeSchemaNumberIndex( PageCache pageCache, FileSystemAbstraction fs, File storeFile, Layout<KEY,VALUE> layout,
+            SchemaIndexProvider.Monitor monitor, IndexDescriptor descriptor, long indexId )
     {
         this.pageCache = pageCache;
         this.storeFile = storeFile;
         this.layout = layout;
         this.gbpTreeFileUtil = new GBPTreeFileSystemFileUtil( fs );
-        this.log = log;
         this.descriptor = descriptor;
         this.indexId = indexId;
+        this.monitor = monitor;
     }
 
     void instantiateTree( RecoveryCleanupWorkCollector recoveryCleanupWorkCollector, Consumer<PageCursor> headerWriter )
@@ -76,19 +77,14 @@ private GBPTree.Monitor treeMonitor( )
             @Override
             public void cleanupFinished( long numberOfPagesVisited, long numberOfCleanedCrashPointers, long durationMillis )
             {
-                log.info( String.format(
-                        "%s Schema index recovery completed. Number of pages visited: %d. Number of cleaned crashed pointers: %d. Time " +
-                                "spent: %s.",
-                        indexDescription(), numberOfPagesVisited, numberOfCleanedCrashPointers, duration( durationMillis ) ) );
+                monitor.recoveryCompleted( indexId, descriptor, map(
+                        "Number of pages visited", numberOfPagesVisited,
+                        "Number of cleaned crashed pointers", numberOfCleanedCrashPointers,
+                        "Time spent", duration( durationMillis ) ) );
             }
         };
     }
 
-    private String indexDescription()
-    {
-        return String.format( "[indexId:%d, descriptor:'%s']", indexId, descriptor );
-    }
-
     private void ensureDirectoryExist() throws IOException
     {
         // This will create the directory on the "normal" file system.

community/kernel/src/main/java/org/neo4j/kernel/impl/index/schema/NativeSchemaNumberIndexAccessor.java

@@ -34,9 +34,9 @@
 import org.neo4j.kernel.api.index.IndexAccessor;
 import org.neo4j.kernel.api.index.IndexUpdater;
 import org.neo4j.kernel.api.index.PropertyAccessor;
+import org.neo4j.kernel.api.index.SchemaIndexProvider;
 import org.neo4j.kernel.api.schema.index.IndexDescriptor;
 import org.neo4j.kernel.impl.api.index.IndexUpdateMode;
-import org.neo4j.logging.Log;
 import org.neo4j.storageengine.api.schema.IndexReader;
 
 import static org.neo4j.helpers.collection.Iterators.asResourceIterator;
@@ -49,10 +49,10 @@ public class NativeSchemaNumberIndexAccessor<KEY extends SchemaNumberKey, VALUE
     private final NativeSchemaNumberIndexUpdater<KEY,VALUE> singleUpdater;
 
     NativeSchemaNumberIndexAccessor( PageCache pageCache, FileSystemAbstraction fs, File storeFile,
-            Layout<KEY,VALUE> layout, RecoveryCleanupWorkCollector recoveryCleanupWorkCollector, Log log, IndexDescriptor descriptor,
-            long indexId ) throws IOException
+            Layout<KEY,VALUE> layout, RecoveryCleanupWorkCollector recoveryCleanupWorkCollector, SchemaIndexProvider.Monitor monitor,
+            IndexDescriptor descriptor, long indexId ) throws IOException
     {
-        super( pageCache, fs, storeFile, layout, log, descriptor, indexId );
+        super( pageCache, fs, storeFile, layout, monitor, descriptor, indexId );
         singleUpdater = new NativeSchemaNumberIndexUpdater<>( layout.newKey(), layout.newValue() );
         instantiateTree( recoveryCleanupWorkCollector, NO_HEADER_WRITER );
     }

community/kernel/src/main/java/org/neo4j/kernel/impl/index/schema/NativeSchemaNumberIndexPopulator.java

@@ -41,8 +41,8 @@
 import org.neo4j.kernel.api.index.IndexPopulator;
 import org.neo4j.kernel.api.index.IndexUpdater;
 import org.neo4j.kernel.api.index.PropertyAccessor;
+import org.neo4j.kernel.api.index.SchemaIndexProvider;
 import org.neo4j.kernel.api.schema.index.IndexDescriptor;
-import org.neo4j.logging.Log;
 
 import static org.neo4j.index.internal.gbptree.GBPTree.NO_HEADER_WRITER;
 
@@ -68,10 +68,10 @@ public abstract class NativeSchemaNumberIndexPopulator<KEY extends SchemaNumberK
     private byte[] failureBytes;
     private boolean dropped;
 
-    NativeSchemaNumberIndexPopulator( PageCache pageCache, FileSystemAbstraction fs, File storeFile, Layout<KEY,VALUE> layout, Log log,
-            IndexDescriptor descriptor, long indexId )
+    NativeSchemaNumberIndexPopulator( PageCache pageCache, FileSystemAbstraction fs, File storeFile, Layout<KEY,VALUE> layout,
+            SchemaIndexProvider.Monitor monitor, IndexDescriptor descriptor, long indexId )
     {
-        super( pageCache, fs, storeFile, layout, log, descriptor, indexId );
+        super( pageCache, fs, storeFile, layout, monitor, descriptor, indexId );
         this.treeKey = layout.newKey();
         this.treeValue = layout.newValue();
         this.conflictDetectingValueMerger = new ConflictDetectingValueMerger<>();

community/kernel/src/main/java/org/neo4j/kernel/impl/index/schema/NativeSchemaNumberIndexProvider.java

@@ -35,8 +35,6 @@
 import org.neo4j.kernel.api.schema.index.IndexDescriptor;
 import org.neo4j.kernel.impl.api.index.sampling.IndexSamplingConfig;
 import org.neo4j.kernel.impl.storemigration.StoreMigrationParticipant;
-import org.neo4j.logging.Log;
-import org.neo4j.logging.LogProvider;
 
 import static org.neo4j.kernel.impl.index.schema.NativeSchemaNumberIndexPopulator.BYTE_FAILED;
 import static org.neo4j.kernel.impl.index.schema.NativeSchemaNumberIndexPopulator.BYTE_ONLINE;
@@ -52,17 +50,18 @@ public class NativeSchemaNumberIndexProvider extends SchemaIndexProvider
 
     private final PageCache pageCache;
     private final FileSystemAbstraction fs;
-    private final Log log;
+    private final Monitor monitor;
     private final RecoveryCleanupWorkCollector recoveryCleanupWorkCollector;
     private final boolean readOnly;
 
-    public NativeSchemaNumberIndexProvider( PageCache pageCache, FileSystemAbstraction fs, IndexDirectoryStructure.Factory directoryStructure,
-            LogProvider logging, RecoveryCleanupWorkCollector recoveryCleanupWorkCollector, boolean readOnly )
+    public NativeSchemaNumberIndexProvider( PageCache pageCache, FileSystemAbstraction fs,
+            IndexDirectoryStructure.Factory directoryStructure, Monitor monitor, RecoveryCleanupWorkCollector recoveryCleanupWorkCollector,
+            boolean readOnly )
     {
         super( NATIVE_PROVIDER_DESCRIPTOR, 0, directoryStructure );
         this.pageCache = pageCache;
         this.fs = fs;
-        this.log = logging.getLog( getClass() );
+        this.monitor = monitor;
         this.recoveryCleanupWorkCollector = recoveryCleanupWorkCollector;
         this.readOnly = readOnly;
     }
@@ -80,9 +79,9 @@ public IndexPopulator getPopulator( long indexId, IndexDescriptor descriptor, In
         {
         case GENERAL:
             return new NativeNonUniqueSchemaNumberIndexPopulator<>( pageCache, fs, storeFile, new NonUniqueNumberLayout(), samplingConfig,
-                    log, descriptor, indexId );
+                    monitor, descriptor, indexId );
         case UNIQUE:
-            return new NativeUniqueSchemaNumberIndexPopulator<>( pageCache, fs, storeFile, new UniqueNumberLayout(), log, descriptor,
+            return new NativeUniqueSchemaNumberIndexPopulator<>( pageCache, fs, storeFile, new UniqueNumberLayout(), monitor, descriptor,
                     indexId );
         default:
             throw new UnsupportedOperationException( "Can not create index populator of type " + descriptor.type() );
@@ -106,7 +105,7 @@ public IndexAccessor getOnlineAccessor( long indexId, IndexDescriptor descriptor
         default:
             throw new UnsupportedOperationException( "Can not create index accessor of type " + descriptor.type() );
         }
-        return new NativeSchemaNumberIndexAccessor<>( pageCache, fs, storeFile, layout, recoveryCleanupWorkCollector, log, descriptor,
+        return new NativeSchemaNumberIndexAccessor<>( pageCache, fs, storeFile, layout, recoveryCleanupWorkCollector, monitor, descriptor,
                 indexId );
     }
 
@@ -158,7 +157,7 @@ public InternalIndexState getInitialState( long indexId, IndexDescriptor descrip
         }
         catch ( IOException e )
         {
-            log.error( "Failed to open index:" + indexId + ", requesting re-population.", e );
+            monitor.failedToOpenIndex( indexId, descriptor, "Requesting re-population.", e );
             return InternalIndexState.POPULATING;
         }
     }

community/kernel/src/main/java/org/neo4j/kernel/impl/index/schema/NativeUniqueSchemaNumberIndexPopulator.java

@@ -25,9 +25,9 @@
 import org.neo4j.io.fs.FileSystemAbstraction;
 import org.neo4j.io.pagecache.PageCache;
 import org.neo4j.kernel.api.index.IndexEntryUpdate;
+import org.neo4j.kernel.api.index.SchemaIndexProvider;
 import org.neo4j.kernel.api.schema.index.IndexDescriptor;
 import org.neo4j.kernel.impl.api.index.sampling.UniqueIndexSampler;
-import org.neo4j.logging.Log;
 import org.neo4j.storageengine.api.schema.IndexSample;
 
 /**
@@ -39,9 +39,9 @@ class NativeUniqueSchemaNumberIndexPopulator<KEY extends SchemaNumberKey, VALUE
     private final UniqueIndexSampler sampler;
 
     NativeUniqueSchemaNumberIndexPopulator( PageCache pageCache, FileSystemAbstraction fs, File storeFile, Layout<KEY,VALUE> layout,
-            Log log, IndexDescriptor descriptor, long indexId )
+            SchemaIndexProvider.Monitor monitor, IndexDescriptor descriptor, long indexId )
     {
-        super( pageCache, fs, storeFile, layout, log, descriptor, indexId );
+        super( pageCache, fs, storeFile, layout, monitor, descriptor, indexId );
         this.sampler = new UniqueIndexSampler();
     }
 

community/kernel/src/test/java/org/neo4j/kernel/impl/index/schema/NativeNonUniqueSchemaNumberIndexPopulatorTest.java

@@ -45,7 +45,7 @@ public class NativeNonUniqueSchemaNumberIndexPopulatorTest
     NativeSchemaNumberIndexPopulator<SchemaNumberKey,SchemaNumberValue> createPopulator( PageCache pageCache, FileSystemAbstraction fs,
             File indexFile, Layout<SchemaNumberKey,SchemaNumberValue> layout, IndexSamplingConfig samplingConfig )
     {
-        return new NativeNonUniqueSchemaNumberIndexPopulator<>( pageCache, fs, indexFile, layout, samplingConfig, log, indexDescriptor,
+        return new NativeNonUniqueSchemaNumberIndexPopulator<>( pageCache, fs, indexFile, layout, samplingConfig, monitor, indexDescriptor,
                 indexId );
     }
 

community/kernel/src/test/java/org/neo4j/kernel/impl/index/schema/NativeSchemaNumberIndexAccessorTest.java

@@ -83,7 +83,7 @@ public abstract class NativeSchemaNumberIndexAccessorTest<KEY extends SchemaNumb
     @Before
     public void setupAccessor() throws IOException
     {
-        accessor = new NativeSchemaNumberIndexAccessor<>( pageCache, fs, indexFile, layout, IMMEDIATE, log, indexDescriptor, indexId );
+        accessor = new NativeSchemaNumberIndexAccessor<>( pageCache, fs, indexFile, layout, IMMEDIATE, monitor, indexDescriptor, indexId );
     }
 
     @After

community/kernel/src/test/java/org/neo4j/kernel/impl/index/schema/NativeSchemaNumberIndexProviderTest.java

@@ -35,6 +35,8 @@
 import org.neo4j.kernel.api.index.IndexPopulator;
 import org.neo4j.kernel.api.index.IndexUpdater;
 import org.neo4j.kernel.api.index.InternalIndexState;
+import org.neo4j.kernel.api.index.LoggingMonitor;
+import org.neo4j.kernel.api.index.SchemaIndexProvider;
 import org.neo4j.kernel.api.schema.index.IndexDescriptor;
 import org.neo4j.kernel.api.schema.index.IndexDescriptorFactory;
 import org.neo4j.kernel.configuration.Config;
@@ -50,7 +52,6 @@
 import static org.junit.Assert.assertThat;
 import static org.junit.Assert.assertTrue;
 import static org.junit.Assert.fail;
-
 import static org.neo4j.index.internal.gbptree.RecoveryCleanupWorkCollector.IMMEDIATE;
 import static org.neo4j.kernel.api.index.IndexDirectoryStructure.directoriesByProvider;
 
@@ -64,6 +65,7 @@ public class NativeSchemaNumberIndexProviderTest
     private static final int propId = 1;
     private NativeSchemaNumberIndexProvider provider;
     private final AssertableLogProvider logging = new AssertableLogProvider();
+    private SchemaIndexProvider.Monitor monitor = new LoggingMonitor( logging.getLog( "test" ) );
 
     @Before
     public void setup() throws IOException
@@ -387,12 +389,12 @@ private IndexDescriptor descriptorUnique()
 
     private NativeSchemaNumberIndexProvider newProvider()
     {
-        return new NativeSchemaNumberIndexProvider( pageCache(), fs(), directoriesByProvider( baseDir() ), logging, IMMEDIATE, false );
+        return new NativeSchemaNumberIndexProvider( pageCache(), fs(), directoriesByProvider( baseDir() ), monitor, IMMEDIATE, false );
     }
 
     private NativeSchemaNumberIndexProvider newReadOnlyProvider()
     {
-        return new NativeSchemaNumberIndexProvider( pageCache(), fs(), directoriesByProvider( baseDir() ), logging, IMMEDIATE, true );
+        return new NativeSchemaNumberIndexProvider( pageCache(), fs(), directoriesByProvider( baseDir() ), monitor, IMMEDIATE, true );
     }
 
     private PageCache pageCache()

community/kernel/src/test/java/org/neo4j/kernel/impl/index/schema/NativeUniqueSchemaNumberIndexPopulatorTest.java

@@ -47,7 +47,7 @@ NativeSchemaNumberIndexPopulator<SchemaNumberKey,SchemaNumberValue> createPopula
             PageCache pageCache, FileSystemAbstraction fs, File indexFile,
             Layout<SchemaNumberKey,SchemaNumberValue> layout, IndexSamplingConfig samplingConfig )
     {
-        return new NativeUniqueSchemaNumberIndexPopulator<>( pageCache, fs, indexFile, layout, log, indexDescriptor, indexId );
+        return new NativeUniqueSchemaNumberIndexPopulator<>( pageCache, fs, indexFile, layout, monitor, indexDescriptor, indexId );
     }
 
     @Override