JonoMac
JonoMac

Reputation: 313

Neo4j Index error causing database to not restart

My VPS was upgraded to change to a different type of SSD last night, however I did not take a backup of the database prior to the shut down and restart.

After this point in time I have been unable to restart the database. The error log begins to show a failure when attempting to open a specific index as shown below.

I have attempted to bypass this index by renaming the directory it is stored in but this was not effective. Is there any other way of removing the offending index so that I can restart the database in the browser and then re-add the index later?

[neo4j/21dafb04]                                [ Store versions ]
[neo4j/21dafb04] --------------------------------------------------------------------------------
[neo4j/21dafb04] ArrayPropertyStore[neostore.nodestore.db.labels] AF4.3.0
[neo4j/21dafb04] NodeStore[neostore.nodestore.db] AF4.3.0
[neo4j/21dafb04] StringPropertyStore[neostore.propertystore.db.index.keys] AF4.3.0
[neo4j/21dafb04] PropertyIndexStore[neostore.propertystore.db.index] AF4.3.0
[neo4j/21dafb04] StringPropertyStore[neostore.propertystore.db.strings] AF4.3.0
[neo4j/21dafb04] ArrayPropertyStore[neostore.propertystore.db.arrays] AF4.3.0
[neo4j/21dafb04] PropertyStore[neostore.propertystore.db] AF4.3.0
[neo4j/21dafb04] RelationshipStore[neostore.relationshipstore.db] AF4.3.0
[neo4j/21dafb04] StringPropertyStore[neostore.relationshiptypestore.db.names] AF4.3.0
[neo4j/21dafb04] RelationshipTypeStore[neostore.relationshiptypestore.db] AF4.3.0
[neo4j/21dafb04] StringPropertyStore[neostore.labeltokenstore.db.names] AF4.3.0
[neo4j/21dafb04] LabelTokenStore[neostore.labeltokenstore.db] AF4.3.0
[neo4j/21dafb04] SchemaStore[neostore.schemastore.db] AF4.3.0
[neo4j/21dafb04] RelationshipGroupStore[neostore.relationshipgroupstore.db] AF4.3.0
[neo4j/21dafb04] NeoStore[neostore] AF4.3.0
[neo4j/21dafb04]
    2022-01-24 14:34:34.901+0000 WARN  [o.n.k.i.i.s.GenericNativeIndexProvider] [neo4j/21dafb04] Failed to open index:13. Requesting re-population. Cause: /var/lib/neo4j/data/databases/neo4j/schema/index/native-btree-1.0/13/index-13: /var/lib/neo4j/data/databases/neo4j/schema/index/native-btree-1.0/13/index-13 | GBPTree[file:/var/lib/neo4j/data/databases/neo4j/schema/index/native-btree-1.0/13/index-13]
    2022-01-24 14:34:34.903+0000 INFO  [o.n.k.i.a.i.IndexingService] [neo4j/21dafb04] IndexingService.init: index 13 on (:Role {roleId}) is POPULATING
    2022-01-24 14:34:34.903+0000 INFO  [o.n.k.i.a.i.IndexingService] [neo4j/21dafb04] IndexingService.init: indexes not specifically mentioned above are ONLINE
    2022-01-24 14:34:34.904+0000 INFO  [o.n.k.a.DatabaseAvailabilityGuard] [neo4j/21dafb04] Requirement `Database unavailable` makes database neo4j unavailable.
    2022-01-24 14:34:34.905+0000 INFO  [o.n.k.a.DatabaseAvailabilityGuard] [neo4j/21dafb04] DatabaseId{21dafb04[neo4j]} is unavailable.
    2022-01-24 14:34:35.045+0000 WARN  [o.n.k.d.Database] [neo4j/21dafb04] Exception occurred while starting the database. Trying to stop already started components.
    org.neo4j.kernel.lifecycle.LifecycleException: Component 'org.neo4j.kernel.impl.transaction.log.files.TransactionLogFile@74aaf34e' was successfully initialized, but failed to start. Please see the attached cause exception "/var/lib/neo4j/data/transactions/neo4j/neostore.transaction.db.7".
            at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:463) ~[neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:110) ~[neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.impl.transaction.log.files.TransactionLogFiles.start(TransactionLogFiles.java:66) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:442) ~[neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:110) ~[neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.database.Database.start(Database.java:514) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.dbms.database.AbstractDatabaseManager.startDatabase(AbstractDatabaseManager.java:197) ~[neo4j-4.4.0.jar:4.4.0]
            at org.neo4j.dbms.database.DefaultDatabaseManager.startDatabase(DefaultDatabaseManager.java:153) ~[neo4j-4.4.0.jar:4.4.0]
            at org.neo4j.dbms.database.DefaultDatabaseManager.initialiseDefaultDatabase(DefaultDatabaseManager.java:64) ~[neo4j-4.4.0.jar:4.4.0]
            at org.neo4j.dbms.database.DefaultDatabaseInitializer.start0(DefaultDatabaseInitializer.java:39) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.SafeLifecycle.transition(SafeLifecycle.java:124) [neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.SafeLifecycle.start(SafeLifecycle.java:138) [neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:442) [neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:110) [neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.graphdb.facade.DatabaseManagementServiceFactory.startDatabaseServer(DatabaseManagementServiceFactory.java:219) [neo4j-4.4.0.jar:4.4.0]
            at org.neo4j.graphdb.facade.DatabaseManagementServiceFactory.build(DatabaseManagementServiceFactory.java:181) [neo4j-4.4.0.jar:4.4.0]
            at org.neo4j.server.CommunityBootstrapper.createNeo(CommunityBootstrapper.java:36) [neo4j-4.4.0.jar:4.4.0]
            at org.neo4j.server.NeoBootstrapper.start(NeoBootstrapper.java:142) [neo4j-4.4.0.jar:4.4.0]
            at org.neo4j.server.NeoBootstrapper.start(NeoBootstrapper.java:95) [neo4j-4.4.0.jar:4.4.0]
            at org.neo4j.server.CommunityEntryPoint.main(CommunityEntryPoint.java:34) [neo4j-4.4.0.jar:4.4.0]
    Caused by: java.nio.file.AccessDeniedException: /var/lib/neo4j/data/transactions/neo4j/neostore.transaction.db.7
            at sun.nio.fs.UnixException.translateToIOException(UnixException.java:90) ~[?:?]
            at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111) ~[?:?]
            at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:116) ~[?:?]
            at sun.nio.fs.UnixFileSystemProvider.newFileChannel(UnixFileSystemProvider.java:182) ~[?:?]
            at java.nio.channels.FileChannel.open(FileChannel.java:292) ~[?:?]
            at org.neo4j.io.fs.DefaultFileSystemAbstraction.open(DefaultFileSystemAbstraction.java:76) ~[neo4j-io-4.4.0.jar:4.4.0]
            at org.neo4j.io.fs.DefaultFileSystemAbstraction.write(DefaultFileSystemAbstraction.java:107) ~[neo4j-io-4.4.0.jar:4.4.0]
            at org.neo4j.io.fs.DefaultFileSystemAbstraction.write(DefaultFileSystemAbstraction.java:58) ~[neo4j-io-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.impl.transaction.log.files.TransactionLogChannelAllocator.allocateFile(TransactionLogChannelAllocator.java:151) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.impl.transaction.log.files.TransactionLogChannelAllocator.createLogChannel(TransactionLogChannelAllocator.java:64) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.impl.transaction.log.files.TransactionLogFile.createLogChannelForVersion(TransactionLogFile.java:186) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.impl.transaction.log.files.TransactionLogFile.start(TransactionLogFile.java:140) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:442) ~[neo4j-common-4.4.0.jar:4.4.0]
            ... 19 more
    2022-01-24 14:34:35.051+0000 INFO  [o.n.k.i.t.l.c.CheckPointerImpl] [neo4j/21dafb04] Checkpoint triggered by "Database shutdown" @ txId: 719312 checkpoint started...
    2022-01-24 14:34:35.085+0000 WARN  [o.n.k.i.t.l.c.DetachedCheckpointAppender] [neo4j/21dafb04] Checkpoint was attempted while appender is not started. No checkpoint record will be appended.
    2022-01-24 14:34:35.087+0000 INFO  [o.n.k.i.t.l.c.CheckPointerImpl] [neo4j/21dafb04] Checkpoint triggered by "Database shutdown" @ txId: 719312 checkpoint completed in 33ms
    2022-01-24 14:34:35.093+0000 INFO  [o.n.k.i.t.l.p.LogPruningImpl] [neo4j/21dafb04] No log version pruned. The strategy used was '1 days'.
    2022-01-24 14:34:35.115+0000 ERROR [o.n.d.d.DefaultDatabaseManager] Failed to start DatabaseId{21dafb04[neo4j]}
    org.neo4j.dbms.api.DatabaseManagementException: An error occurred! Unable to start `DatabaseId{21dafb04[neo4j]}`.
            at org.neo4j.dbms.database.AbstractDatabaseManager.startDatabase(AbstractDatabaseManager.java:201) ~[neo4j-4.4.0.jar:4.4.0]
            at org.neo4j.dbms.database.DefaultDatabaseManager.startDatabase(DefaultDatabaseManager.java:153) ~[neo4j-4.4.0.jar:4.4.0]
            at org.neo4j.dbms.database.DefaultDatabaseManager.initialiseDefaultDatabase(DefaultDatabaseManager.java:64) ~[neo4j-4.4.0.jar:4.4.0]
            at org.neo4j.dbms.database.DefaultDatabaseInitializer.start0(DefaultDatabaseInitializer.java:39) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.SafeLifecycle.transition(SafeLifecycle.java:124) [neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.SafeLifecycle.start(SafeLifecycle.java:138) [neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:442) [neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:110) [neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.graphdb.facade.DatabaseManagementServiceFactory.startDatabaseServer(DatabaseManagementServiceFactory.java:219) [neo4j-4.4.0.jar:4.4.0]
            at org.neo4j.graphdb.facade.DatabaseManagementServiceFactory.build(DatabaseManagementServiceFactory.java:181) [neo4j-4.4.0.jar:4.4.0]
            at org.neo4j.server.CommunityBootstrapper.createNeo(CommunityBootstrapper.java:36) [neo4j-4.4.0.jar:4.4.0]
            at org.neo4j.server.NeoBootstrapper.start(NeoBootstrapper.java:142) [neo4j-4.4.0.jar:4.4.0]
            at org.neo4j.server.NeoBootstrapper.start(NeoBootstrapper.java:95) [neo4j-4.4.0.jar:4.4.0]
            at org.neo4j.server.CommunityEntryPoint.main(CommunityEntryPoint.java:34) [neo4j-4.4.0.jar:4.4.0]
    Caused by: java.lang.RuntimeException: org.neo4j.kernel.lifecycle.LifecycleException: Component 'org.neo4j.kernel.impl.transaction.log.files.TransactionLogFile@74aaf34e' was successfully initialized, but failed to start. Please see the attached cause exception "/var/lib/neo4j/data/transactions/neo4j/neostore.transaction.db.7".
            at org.neo4j.kernel.database.Database.handleStartupFailure(Database.java:638) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.database.Database.start(Database.java:532) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.dbms.database.AbstractDatabaseManager.startDatabase(AbstractDatabaseManager.java:197) ~[neo4j-4.4.0.jar:4.4.0]
            ... 13 more
    Caused by: org.neo4j.kernel.lifecycle.LifecycleException: Component 'org.neo4j.kernel.impl.transaction.log.files.TransactionLogFile@74aaf34e' was successfully initialized, but failed to start. Please see the attached cause exception "/var/lib/neo4j/data/transactions/neo4j/neostore.transaction.db.7".
            at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:463) ~[neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:110) ~[neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.impl.transaction.log.files.TransactionLogFiles.start(TransactionLogFiles.java:66) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:442) ~[neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:110) ~[neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.database.Database.start(Database.java:514) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.dbms.database.AbstractDatabaseManager.startDatabase(AbstractDatabaseManager.java:197) ~[neo4j-4.4.0.jar:4.4.0]
            ... 13 more
    Caused by: java.nio.file.AccessDeniedException: /var/lib/neo4j/data/transactions/neo4j/neostore.transaction.db.7
            at sun.nio.fs.UnixException.translateToIOException(UnixException.java:90) ~[?:?]
            at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111) ~[?:?]
            at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:116) ~[?:?]
            at sun.nio.fs.UnixFileSystemProvider.newFileChannel(UnixFileSystemProvider.java:182) ~[?:?]
            at java.nio.channels.FileChannel.open(FileChannel.java:292) ~[?:?]
            at org.neo4j.io.fs.DefaultFileSystemAbstraction.open(DefaultFileSystemAbstraction.java:76) ~[neo4j-io-4.4.0.jar:4.4.0]
            at org.neo4j.io.fs.DefaultFileSystemAbstraction.write(DefaultFileSystemAbstraction.java:107) ~[neo4j-io-4.4.0.jar:4.4.0]
            at org.neo4j.io.fs.DefaultFileSystemAbstraction.write(DefaultFileSystemAbstraction.java:58) ~[neo4j-io-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.impl.transaction.log.files.TransactionLogChannelAllocator.allocateFile(TransactionLogChannelAllocator.java:151) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.impl.transaction.log.files.TransactionLogChannelAllocator.createLogChannel(TransactionLogChannelAllocator.java:64) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.impl.transaction.log.files.TransactionLogFile.createLogChannelForVersion(TransactionLogFile.java:186) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.impl.transaction.log.files.TransactionLogFile.start(TransactionLogFile.java:140) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:442) ~[neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:110) ~[neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.impl.transaction.log.files.TransactionLogFiles.start(TransactionLogFiles.java:66) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:442) ~[neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:110) ~[neo4j-common-4.4.0.jar:4.4.0]
            at org.neo4j.kernel.database.Database.start(Database.java:514) ~[neo4j-kernel-4.4.0.jar:4.4.0]
            at org.neo4j.dbms.database.AbstractDatabaseManager.startDatabase(AbstractDatabaseManager.java:197) ~[neo4j-4.4.0.jar:4.4.0]
            ... 13 more
    2022-01-24 14:34:35.186+0000 INFO  [o.n.b.BoltServer] Bolt enabled on [0:0:0:0:0:0:0:0%0]:7687.
    2022-01-24 14:34:35.187+0000 INFO  [o.n.s.AbstractNeoWebServer$ServerComponentsLifecycleAdapter] Starting web server
    2022-01-24 14:34:36.091+0000 INFO  [o.n.s.CommunityNeoWebServer] Remote interface available at http://localhost:7474/
    2022-01-24 14:34:36.091+0000 INFO  [o.n.s.AbstractNeoWebServer$ServerComponentsLifecycleAdapter] Web server started.
    2022-01-24 14:34:36.095+0000 INFO  [o.n.g.f.DatabaseManagementServiceFactory] id: E5F568A8DED63307B74CB58935A9D6A6E1F7EADD2CF22433E0040FED4ECBEC2E
    2022-01-24 14:34:36.095+0000 INFO  [o.n.g.f.DatabaseManagementServiceFactory] name: system
    2022-01-24 14:34:36.095+0000 INFO  [o.n.g.f.DatabaseManagementServiceFactory] creationDate: 2021-03-12T13:08:07.119Z

I have run the following:

sudo neo4j-admin check-consistency --database=neo4j --check-indexes=true

and can see the indexes appear fine (if this is what is being checked?)

Selecting JVM - Version:11.0.13+8-Ubuntu-0ubuntu1.20.04, Name:OpenJDK 64-Bit Server VM, Vendor:Ubuntu
2022-01-24 22:17:20.020+0000 INFO  [o.n.k.i.s.f.RecordFormatSelector] Selected RecordFormat:PageAlignedV4_3[AF4.3.0] record format from store /var/lib/neo4j/data/databases/neo4j
2022-01-24 22:17:20.022+0000 INFO  [o.n.k.i.s.f.RecordFormatSelector] Format not configured for store /var/lib/neo4j/data/databases/neo4j. Selected format from the store files: RecordFormat:PageAlignedV4_3[AF4.3.0]
Index structure consistency check
....................  10%
....................  20%
....................  30%
....................  40%
....................  50%
....................  60%
....................  70%
....................  80%
....................  90%
.................... 100%
Consistency check
....................  10%
....................  20%
....................  30%
....................  40%
....................  50%
....................  60%
....................  70%
....................  80%
....................  90%
.................... 100%

Upvotes: 0

Views: 1179

Answers (1)

JonoMac
JonoMac

Reputation: 313

Answer found here: https://community.neo4j.com/t/database-offline-and-will-not-restart/27914/5

The index issue seems to have disappeared as part of this solution. For some reason the neo4j system account no longer had access to write to the log files or anything else in the data folder. This was resolved using:

sudo chown neo4j -R /var/lib/neo4j/data/

Upvotes: 2

Related Questions