From 8794e1c819273526a26b89af6edbc2935a4653cb Mon Sep 17 00:00:00 2001 From: Mattias Persson Date: Tue, 10 Jan 2017 13:25:56 +0100 Subject: [PATCH] LSS logging happens in the monitor --- .../kernel/api/labelscan/LabelScanStore.java | 55 +++------ .../kernel/api/labelscan/LoggingMonitor.java | 84 ++++++++++++++ .../scan/NativeLabelScanStoreExtension.java | 8 ++ .../index/labelscan/NativeLabelScanStore.java | 109 +++++------------- .../lucene/LuceneLabelScanStoreBuilder.java | 5 +- .../impl/labelscan/LuceneLabelScanStore.java | 11 +- .../LuceneLabelScanStoreExtension.java | 9 +- .../labelscan/LuceneLabelScanStoreTest.java | 4 +- 8 files changed, 154 insertions(+), 131 deletions(-) create mode 100644 community/kernel/src/main/java/org/neo4j/kernel/api/labelscan/LoggingMonitor.java diff --git a/community/kernel/src/main/java/org/neo4j/kernel/api/labelscan/LabelScanStore.java b/community/kernel/src/main/java/org/neo4j/kernel/api/labelscan/LabelScanStore.java index 7a36e88c0976f..f46adb11b8334 100644 --- a/community/kernel/src/main/java/org/neo4j/kernel/api/labelscan/LabelScanStore.java +++ b/community/kernel/src/main/java/org/neo4j/kernel/api/labelscan/LabelScanStore.java @@ -37,49 +37,32 @@ public interface LabelScanStore extends Lifecycle interface Monitor { Monitor EMPTY = new Monitor() - { - @Override - public void init() - { - } - - @Override - public void noIndex() - { - } - - @Override - public void lockedIndex( Exception e ) - { - } - - @Override - public void notValidIndex() - { - } - - @Override - public void rebuilding() - { - } - - @Override - public void rebuilt( long roughNodeCount ) - { - } + { // empty }; - void init(); + default void init() + { // empty + } - void noIndex(); + default void noIndex() + { // empty + } - void lockedIndex( Exception e ); + default void lockedIndex( Exception e ) + { // empty + } - void notValidIndex(); + default void notValidIndex() + { // empty + } - void rebuilding(); + default void rebuilding() + { // empty + } - void rebuilt( long roughNodeCount ); + default void rebuilt( long roughNodeCount ) + { // empty + } } /** diff --git a/community/kernel/src/main/java/org/neo4j/kernel/api/labelscan/LoggingMonitor.java b/community/kernel/src/main/java/org/neo4j/kernel/api/labelscan/LoggingMonitor.java new file mode 100644 index 0000000000000..930144347ec55 --- /dev/null +++ b/community/kernel/src/main/java/org/neo4j/kernel/api/labelscan/LoggingMonitor.java @@ -0,0 +1,84 @@ +/* + * 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 . + */ +package org.neo4j.kernel.api.labelscan; + +import org.neo4j.kernel.api.labelscan.LabelScanStore.Monitor; +import org.neo4j.logging.Log; + +/** + * Logs about important events about {@link LabelScanStore} {@link Monitor}. + */ +public class LoggingMonitor implements Monitor +{ + private final Log log; + private final Monitor delegate; + + public LoggingMonitor( Log log ) + { + this( log, Monitor.EMPTY ); + } + + public LoggingMonitor( Log log, Monitor delegate ) + { + this.log = log; + this.delegate = delegate; + } + + @Override + public void init() + { + delegate.init(); + } + + @Override + public void noIndex() + { + log.info( "No scan store found, this might just be first use. Preparing to rebuild." ); + delegate.noIndex(); + } + + @Override + public void lockedIndex( Exception e ) + { + log.error( "Scan store is locked by another process or database", e ); + delegate.lockedIndex( e ); + } + + @Override + public void notValidIndex() + { + log.warn( "Scan store could not be read. Preparing to rebuild." ); + delegate.notValidIndex(); + } + + @Override + public void rebuilding() + { + log.info( "Rebuilding scan store, this may take a while" ); + delegate.rebuilding(); + } + + @Override + public void rebuilt( long roughNodeCount ) + { + log.info( "Scan store rebuilt (roughly " + roughNodeCount + " nodes)" ); + delegate.rebuilt( roughNodeCount ); + } +} diff --git a/community/kernel/src/main/java/org/neo4j/kernel/impl/api/scan/NativeLabelScanStoreExtension.java b/community/kernel/src/main/java/org/neo4j/kernel/impl/api/scan/NativeLabelScanStoreExtension.java index 8f5c32a9bf7ce..4ba641ede8498 100644 --- a/community/kernel/src/main/java/org/neo4j/kernel/impl/api/scan/NativeLabelScanStoreExtension.java +++ b/community/kernel/src/main/java/org/neo4j/kernel/impl/api/scan/NativeLabelScanStoreExtension.java @@ -23,13 +23,17 @@ import org.neo4j.graphdb.factory.GraphDatabaseSettings; import org.neo4j.io.pagecache.PageCache; +import org.neo4j.kernel.api.labelscan.LoggingMonitor; import org.neo4j.kernel.api.labelscan.LabelScanStore; +import org.neo4j.kernel.api.labelscan.LabelScanStore.Monitor; import org.neo4j.kernel.configuration.Config; import org.neo4j.kernel.extension.KernelExtensionFactory; import org.neo4j.kernel.impl.api.index.IndexStoreView; import org.neo4j.kernel.impl.index.labelscan.NativeLabelScanStore; +import org.neo4j.kernel.impl.logging.LogService; import org.neo4j.kernel.impl.spi.KernelContext; import org.neo4j.kernel.lifecycle.Lifecycle; +import org.neo4j.logging.Log; public class NativeLabelScanStoreExtension extends KernelExtensionFactory @@ -45,6 +49,8 @@ public interface Dependencies PageCache pageCache(); Supplier indexStoreView(); + + LogService getLogService(); } public NativeLabelScanStoreExtension() @@ -62,6 +68,8 @@ public NativeLabelScanStoreExtension( int priority, LabelScanStore.Monitor monit @Override public Lifecycle newInstance( KernelContext context, Dependencies dependencies ) throws Throwable { + Log log = dependencies.getLogService().getInternalLog( NativeLabelScanStore.class ); + Monitor monitor = new LoggingMonitor( log, this.monitor ); NativeLabelScanStore labelScanStore = new NativeLabelScanStore( dependencies.pageCache(), context.storeDir(), diff --git a/community/kernel/src/main/java/org/neo4j/kernel/impl/index/labelscan/NativeLabelScanStore.java b/community/kernel/src/main/java/org/neo4j/kernel/impl/index/labelscan/NativeLabelScanStore.java index 9aa35f86c6545..8b16a46fc0c40 100644 --- a/community/kernel/src/main/java/org/neo4j/kernel/impl/index/labelscan/NativeLabelScanStore.java +++ b/community/kernel/src/main/java/org/neo4j/kernel/impl/index/labelscan/NativeLabelScanStore.java @@ -24,7 +24,7 @@ import java.io.UncheckedIOException; import java.nio.file.NoSuchFileException; import java.util.function.IntFunction; -import java.util.stream.Stream; +import java.util.stream.Collectors; import org.neo4j.cursor.RawCursor; import org.neo4j.graphdb.ResourceIterator; @@ -43,6 +43,7 @@ import org.neo4j.kernel.impl.store.UnderlyingStorageException; import org.neo4j.storageengine.api.schema.LabelScanReader; +import static org.neo4j.helpers.collection.Iterables.single; import static org.neo4j.helpers.collection.Iterators.asResourceIterator; import static org.neo4j.helpers.collection.Iterators.iterator; import static org.neo4j.kernel.impl.store.MetaDataStore.DEFAULT_NAME; @@ -73,8 +74,15 @@ public class NativeLabelScanStore implements LabelScanStore { static final String FILE_NAME = DEFAULT_NAME + ".labelscanstore.db"; + /** + * Whether or not this label scan store is read-only. + */ private final boolean readOnly; - private final NativeLabelScanStoreMonitor monitor; + + /** + * Monitoring internal events. + */ + private final Monitor monitor; /** * {@link PageCache} to {@link PageCache#map(File, int, java.nio.file.OpenOption...)} @@ -117,6 +125,10 @@ public class NativeLabelScanStore implements LabelScanStore */ private boolean recoveryStarted; + /** + * Set during {@link #init()} if {@link #start()} will need to rebuild the whole label scan store from + * {@link FullStoreChangeStream}. + */ private boolean needsRebuild; private final NativeLabelScanWriter singleWriter; @@ -139,7 +151,7 @@ public NativeLabelScanStore( PageCache pageCache, File storeDir, this.storeFile = new File( storeDir, FILE_NAME ); this.singleWriter = new NativeLabelScanWriter( 1_000 ); this.readOnly = readOnly; - this.monitor = new NativeLabelScanStoreMonitor( monitor ); + this.monitor = monitor; } /** @@ -209,12 +221,6 @@ public void force( IOLimiter limiter ) throws UnderlyingStorageException } } - /** - * Unsupported by this implementation. - * - * @return nothing since {@link UnsupportedOperationException} will be thrown. - * @throws UnsupportedOperationException since not supported by this implementation. - */ @Override public AllEntriesLabelScanReader allNodeLabelRanges() { @@ -278,16 +284,20 @@ public void init() throws IOException try { - create( monitor ); needsRebuild = !storeExists; + if ( !storeExists ) + { + monitor.noIndex(); + } + + instantiateTree(); } catch ( MetadataMismatchException e ) { // GBPTree is corrupt. Try to rebuild. - // todo log monitor.notValidIndex(); drop(); - create( GBPTree.NO_MONITOR ); + instantiateTree(); needsRebuild = true; } } @@ -296,13 +306,8 @@ private boolean storeExists() throws IOException { try { - Stream stream = pageCache.streamFilesRecursive( storeFile ); - long count = stream.count(); - if ( count > 1 ) - { - throw new IllegalStateException( "Multiple " + storeFile + " existed" ); - } - return count == 1; + storeFileHandle(); + return true; } catch ( NoSuchFileException e ) { @@ -310,14 +315,19 @@ private boolean storeExists() throws IOException } } - private void create( GBPTree.Monitor monitor ) throws IOException + private FileHandle storeFileHandle() throws IOException + { + return single( pageCache.streamFilesRecursive( storeFile ).collect( Collectors.toList() ) ); + } + + private void instantiateTree() throws IOException { - index = new GBPTree<>( pageCache, storeFile, new LabelScanLayout(), pageSize, monitor ); + index = new GBPTree<>( pageCache, storeFile, new LabelScanLayout(), pageSize, GBPTree.NO_MONITOR ); } private void drop() throws IOException { - storeFile.delete(); + storeFileHandle().delete(); } /** @@ -336,10 +346,8 @@ public void start() throws IOException throw new IOException( "Tried to start label scan store " + storeFile + " as read-only and the index needs rebuild. This makes the label scan store unusable" ); } - // todo log monitor.rebuilding(); long numberOfNodes = LabelScanStoreProvider.rebuild( this, fullStoreChangeStream ); - // todo log monitor.rebuilt( numberOfNodes ); needsRebuild = false; } @@ -372,57 +380,4 @@ public void shutdown() throws IOException { index.close(); } - - // todo make this guy log the stuffs - private class NativeLabelScanStoreMonitor implements Monitor, GBPTree.Monitor - { - private final Monitor delegate; - - NativeLabelScanStoreMonitor( Monitor delegate ) - { - this.delegate = delegate; - } - - @Override - public void init() - { - delegate.init(); - } - - @Override - public void noIndex() - { - delegate.noIndex(); - } - - @Override - public void lockedIndex( Exception e ) - { - delegate.lockedIndex( e ); - } - - @Override - public void notValidIndex() - { - delegate.notValidIndex(); - } - - @Override - public void rebuilding() - { - delegate.rebuilding(); - } - - @Override - public void rebuilt( long roughNodeCount ) - { - delegate.rebuilt( roughNodeCount ); - } - - @Override - public void noStoreFile() - { - noIndex(); - } - } } diff --git a/community/lucene-index/src/main/java/org/neo4j/index/lucene/LuceneLabelScanStoreBuilder.java b/community/lucene-index/src/main/java/org/neo4j/index/lucene/LuceneLabelScanStoreBuilder.java index 5110cedd8a6bd..d756d7c9ebf48 100644 --- a/community/lucene-index/src/main/java/org/neo4j/index/lucene/LuceneLabelScanStoreBuilder.java +++ b/community/lucene-index/src/main/java/org/neo4j/index/lucene/LuceneLabelScanStoreBuilder.java @@ -28,6 +28,7 @@ import org.neo4j.kernel.api.impl.labelscan.LuceneLabelScanIndexBuilder; import org.neo4j.kernel.api.impl.labelscan.LuceneLabelScanStore; import org.neo4j.kernel.api.labelscan.LabelScanStore; +import org.neo4j.kernel.api.labelscan.LoggingMonitor; import org.neo4j.kernel.configuration.Config; import org.neo4j.kernel.impl.factory.OperationalMode; import org.neo4j.kernel.impl.api.index.IndexStoreView; @@ -76,14 +77,14 @@ public LabelScanStore build() if ( null == labelScanStore ) { // TODO: Replace with kernel extension based lookup + LabelScanStore.Monitor monitor = new LoggingMonitor( logProvider.getLog( LuceneLabelScanStore.class ) ); LabelScanIndex index = LuceneLabelScanIndexBuilder.create() .withFileSystem( fileSystem ) .withIndexRootFolder( getStoreDirectory( storeDir ) ) .withConfig( config ) .withOperationalMode( operationalMode ) .build(); - labelScanStore = new LuceneLabelScanStore( index, new FullLabelStream( storeViewSupplier ), - logProvider, LabelScanStore.Monitor.EMPTY ); + labelScanStore = new LuceneLabelScanStore( index, new FullLabelStream( storeViewSupplier ), monitor ); try { diff --git a/community/lucene-index/src/main/java/org/neo4j/kernel/api/impl/labelscan/LuceneLabelScanStore.java b/community/lucene-index/src/main/java/org/neo4j/kernel/api/impl/labelscan/LuceneLabelScanStore.java index 09ce87abbf10e..07d4e039a574f 100644 --- a/community/lucene-index/src/main/java/org/neo4j/kernel/api/impl/labelscan/LuceneLabelScanStore.java +++ b/community/lucene-index/src/main/java/org/neo4j/kernel/api/impl/labelscan/LuceneLabelScanStore.java @@ -32,8 +32,6 @@ import org.neo4j.kernel.impl.api.scan.FullStoreChangeStream; import org.neo4j.kernel.impl.api.scan.LabelScanStoreProvider; import org.neo4j.kernel.impl.store.UnderlyingStorageException; -import org.neo4j.logging.Log; -import org.neo4j.logging.LogProvider; import org.neo4j.storageengine.api.schema.LabelScanReader; public class LuceneLabelScanStore implements LabelScanStore @@ -41,16 +39,14 @@ public class LuceneLabelScanStore implements LabelScanStore private final LabelScanIndex luceneIndex; // We get in a full store stream here in case we need to fully rebuild the store if it's missing or corrupted. private final FullStoreChangeStream fullStoreStream; - private final Log log; private final Monitor monitor; private boolean needsRebuild; public LuceneLabelScanStore( LabelScanIndex luceneIndex, FullStoreChangeStream fullStoreStream, - LogProvider logProvider, Monitor monitor ) + Monitor monitor ) { this.luceneIndex = luceneIndex; this.fullStoreStream = fullStoreStream; - this.log = logProvider.getLog( getClass() ); this.monitor = monitor; } @@ -96,7 +92,6 @@ public void init() throws IOException { if ( !luceneIndex.exists() ) { - log.info( "No lucene scan store index found, this might just be first use. Preparing to rebuild." ); monitor.noIndex(); luceneIndex.create(); @@ -104,7 +99,6 @@ public void init() throws IOException } else if ( !luceneIndex.isValid() ) { - log.warn( "Lucene scan store index could not be read. Preparing to rebuild." ); monitor.notValidIndex(); luceneIndex.drop(); luceneIndex.create(); @@ -115,7 +109,6 @@ else if ( !luceneIndex.isValid() ) catch ( LockObtainFailedException e ) { luceneIndex.close(); - log.error( "Index is locked by another process or database", e ); monitor.lockedIndex( e ); throw e; } @@ -128,10 +121,8 @@ public void start() throws IOException { // we saw in init() that we need to rebuild the index, so do it here after the // neostore has been properly started. monitor.rebuilding(); - log.info( "Rebuilding lucene scan store, this may take a while" ); long numberOfNodes = LabelScanStoreProvider.rebuild( this, fullStoreStream ); monitor.rebuilt( numberOfNodes ); - log.info( "Lucene scan store rebuilt (roughly " + numberOfNodes + " nodes)" ); needsRebuild = false; } } diff --git a/community/lucene-index/src/main/java/org/neo4j/kernel/api/impl/labelscan/LuceneLabelScanStoreExtension.java b/community/lucene-index/src/main/java/org/neo4j/kernel/api/impl/labelscan/LuceneLabelScanStoreExtension.java index cbb7d00886747..61bbe5db15866 100644 --- a/community/lucene-index/src/main/java/org/neo4j/kernel/api/impl/labelscan/LuceneLabelScanStoreExtension.java +++ b/community/lucene-index/src/main/java/org/neo4j/kernel/api/impl/labelscan/LuceneLabelScanStoreExtension.java @@ -24,6 +24,8 @@ import org.neo4j.helpers.Service; import org.neo4j.kernel.NeoStoreDataSource; import org.neo4j.kernel.api.impl.index.storage.DirectoryFactory; +import org.neo4j.kernel.api.labelscan.LabelScanStore.Monitor; +import org.neo4j.kernel.api.labelscan.LoggingMonitor; import org.neo4j.kernel.configuration.Config; import org.neo4j.kernel.extension.KernelExtensionFactory; import org.neo4j.kernel.impl.api.index.IndexStoreView; @@ -33,9 +35,9 @@ import org.neo4j.kernel.impl.logging.LogService; import org.neo4j.kernel.impl.spi.KernelContext; import org.neo4j.kernel.lifecycle.Lifecycle; +import org.neo4j.logging.LogProvider; import static org.neo4j.kernel.api.impl.index.LuceneKernelExtensions.directoryFactory; -import static org.neo4j.kernel.api.labelscan.LabelScanStore.Monitor; @Service.Implementation(KernelExtensionFactory.class) public class LuceneLabelScanStoreExtension extends KernelExtensionFactory @@ -79,9 +81,10 @@ public LabelScanStoreProvider newInstance( KernelContext context, Dependencies d DirectoryFactory directoryFactory = directoryFactory( ephemeral, context.fileSystem() ); LabelScanIndex index = getLuceneIndex( context, directoryFactory ); + LogProvider logger = dependencies.getLogService().getInternalLogProvider(); + Monitor loggingMonitor = new LoggingMonitor( logger.getLog( LuceneLabelScanStore.class ), monitor ); LuceneLabelScanStore scanStore = new LuceneLabelScanStore( index, - new FullLabelStream( dependencies.indexStoreView() ), - dependencies.getLogService().getInternalLogProvider(), monitor ); + new FullLabelStream( dependencies.indexStoreView() ), loggingMonitor ); return new LabelScanStoreProvider( LABEL_SCAN_STORE_NAME, scanStore, priority ); } diff --git a/community/lucene-index/src/test/java/org/neo4j/kernel/api/impl/labelscan/LuceneLabelScanStoreTest.java b/community/lucene-index/src/test/java/org/neo4j/kernel/api/impl/labelscan/LuceneLabelScanStoreTest.java index b24e99b45fd21..049db273b1337 100644 --- a/community/lucene-index/src/test/java/org/neo4j/kernel/api/impl/labelscan/LuceneLabelScanStoreTest.java +++ b/community/lucene-index/src/test/java/org/neo4j/kernel/api/impl/labelscan/LuceneLabelScanStoreTest.java @@ -38,8 +38,6 @@ import org.neo4j.kernel.api.labelscan.NodeLabelUpdate; import org.neo4j.kernel.configuration.Config; import org.neo4j.kernel.impl.factory.OperationalMode; -import org.neo4j.logging.NullLogProvider; - import static java.util.Arrays.asList; import static org.hamcrest.Matchers.startsWith; import static org.hamcrest.core.IsCollectionContaining.hasItem; @@ -78,7 +76,7 @@ protected LabelScanStore createLabelScanStore( FileSystemAbstraction fs, File ro .withDocumentFormat( documentFormat ) .build(); - return new LuceneLabelScanStore( index, asStream( existingData ), NullLogProvider.getInstance(), monitor ); + return new LuceneLabelScanStore( index, asStream( existingData ), monitor ); } @Override