DB stuck in offline state, can't get it to start

Neo4j Graph Platform
1

Hello, I'm using Neo4j Desktop 4.4.3.

Created a DB and work with it for a while without any problem.

Yesterday, I started copying that DB into a new one, using the "neo4j-admin copy" shell command.

While doing the copy, I had to stop my source DB (Neo4j default DB) using the cypher command.

  1. STOP DATABASE neo4j

The copy succeeded but I wanted to change my new copied DB's name so I deleted it and retried to copy, this time after I stopped the source DB, I got an error message:

"Database 'neo4j' is unavailable. Run :sysinfo for more info".

Trying to run :sysinfo got me this message: "Complete sysinfo is only available in Neo4j Enterprise Edition" (although it should be included in Desktop version).

Since then, I can't start the DB again using the "Start DATABASE Neo4j" command" - I receive the same "Database 'neo4j' is unavailable" message mentioned above each time, so it's stuck offline.

  • Tried to restart Neo4j - didn't help.

  • Tried even removing DBMS and creating it again (it's just a toy DB so i don't mind) - didn't help (when I stop the db I get the same error).

  • An important note is that somehow, I was able to run the :sysinfo command once (I don't realy understood how, and can't do it again), and didn't see any significant info except at the bottom of the screen I saw the following error: Call to dbms.queryJmx failed

  • Here are the last lines from the log:

    new instances found, were recorded in graph: [ServerId{bc1a378b}]
    2022-06-18 12:30:29.928+0000 INFO [o.n.k.i.a.s.ConstraintIndexCreator] [neo4j/cbf915ea] Starting constraint creation: Constraint( name='EventKey', type='NODE KEY', schema=(:Event {eventID}) ).
    2022-06-18 12:30:29.937+0000 INFO [o.n.k.i.a.i.IndexPopulationJob] [neo4j/cbf915ea] Index population started: [Index( id=3, name='EventKey', type='UNIQUE BTREE', schema=(:Event {eventID}), indexProvider='native-btree-1.0' )]
    2022-06-18 12:30:30.004+0000 INFO [o.n.k.i.a.i.IndexPopulationJob] [neo4j/cbf915ea] Completed node store scan. Flushing all pending updates.
    MultipleIndexPopulator{activeTasks=0, batchedUpdatesFromScan = [org.neo4j.kernel.impl.api.index.MultipleIndexPopulator$IndexPopulation@2d1a9986], concurrentUpdateQueue = 0}
    2022-06-18 12:30:30.017+0000 INFO [o.n.k.i.a.i.IndexPopulationJob] [neo4j/cbf915ea] Index creation finished for index [Index( id=3, name='EventKey', type='UNIQUE BTREE', schema=(:Event {eventID}), indexProvider='native-btree-1.0' )].
    2022-06-18 12:30:30.034+0000 INFO [o.n.k.i.a.i.IndexPopulationJob] [neo4j/cbf915ea] TIME/PHASE Final: SCAN[totalTime=0ns], MERGE[totalTime=0ns], BUILD[totalTime=0ns], APPLY_EXTERNAL[totalTime=4ms], FLIP[totalTime=25ms]
    2022-06-18 12:30:30.035+0000 INFO [o.n.k.i.a.s.ConstraintIndexCreator] [neo4j/cbf915ea] Constraint Constraint( name='EventKey', type='NODE KEY', schema=(:Event {eventID}) ) populated, starting verification.
    2022-06-18 12:30:30.035+0000 INFO [o.n.k.i.a.s.ConstraintIndexCreator] [neo4j/cbf915ea] Constraint Constraint( name='EventKey', type='NODE KEY', schema=(:Event {eventID}) ) verified.
    2022-06-18 12:30:30.052+0000 INFO [o.n.k.i.a.i.IndexingService] [neo4j/cbf915ea] Constraint Index( id=3, name='EventKey', type='UNIQUE BTREE', schema=(:Label[0] {PropertyKey[10]}), indexProvider='native-btree-1.0' ) is ONLINE.
    2022-06-18 12:30:30.103+0000 INFO [o.n.k.i.a.s.ConstraintIndexCreator] [neo4j/cbf915ea] Starting constraint creation: Constraint( name='ObjectKey', type='NODE KEY', schema=(:Object {objectID, objectType}) ).
    2022-06-18 12:30:30.112+0000 INFO [o.n.k.i.a.i.IndexPopulationJob] [neo4j/cbf915ea] Index population started: [Index( id=5, name='ObjectKey', type='UNIQUE BTREE', schema=(:Object {objectID, objectType}), indexProvider='native-btree-1.0' )]
    2022-06-18 12:30:30.152+0000 INFO [o.n.k.i.a.i.IndexPopulationJob] [neo4j/cbf915ea] Completed node store scan. Flushing all pending updates.
    MultipleIndexPopulator{activeTasks=0, batchedUpdatesFromScan = [org.neo4j.kernel.impl.api.index.MultipleIndexPopulator$IndexPopulation@602c3b60], concurrentUpdateQueue = 0}
    2022-06-18 12:30:30.163+0000 INFO [o.n.k.i.a.i.IndexPopulationJob] [neo4j/cbf915ea] Index creation finished for index [Index( id=5, name='ObjectKey', type='UNIQUE BTREE', schema=(:Object {objectID, objectType}), indexProvider='native-btree-1.0' )].
    2022-06-18 12:30:30.193+0000 INFO [o.n.k.i.a.i.IndexPopulationJob] [neo4j/cbf915ea] TIME/PHASE Final: SCAN[totalTime=0ns], MERGE[totalTime=0ns], BUILD[totalTime=0ns], APPLY_EXTERNAL[totalTime=5ms], FLIP[totalTime=36ms]
    2022-06-18 12:30:30.194+0000 INFO [o.n.k.i.a.s.ConstraintIndexCreator] [neo4j/cbf915ea] Constraint Constraint( name='ObjectKey', type='NODE KEY', schema=(:Object {objectID, objectType}) ) populated, starting verification.
    2022-06-18 12:30:30.195+0000 INFO [o.n.k.i.a.s.ConstraintIndexCreator] [neo4j/cbf915ea] Constraint Constraint( name='ObjectKey', type='NODE KEY', schema=(:Object {objectID, objectType}) ) verified.
    2022-06-18 12:30:30.212+0000 INFO [o.n.k.i.a.i.IndexingService] [neo4j/cbf915ea] Constraint Index( id=5, name='ObjectKey', type='UNIQUE BTREE', schema=(:Label[1] {PropertyKey[22], PropertyKey[23]}), indexProvider='native-btree-1.0' ) is ONLINE.
    2022-06-18 12:30:30.293+0000 INFO [o.n.k.i.a.s.ConstraintIndexCreator] [neo4j/cbf915ea] Starting constraint creation: Constraint( name='LogKey', type='NODE KEY', schema=(:Log {logID}) ).
    2022-06-18 12:30:30.298+0000 INFO [o.n.k.i.a.i.IndexPopulationJob] [neo4j/cbf915ea] Index population started: [Index( id=7, name='LogKey', type='UNIQUE BTREE', schema=(:Log {logID}), indexProvider='native-btree-1.0' )]
    2022-06-18 12:30:30.375+0000 INFO [o.n.k.i.a.i.IndexPopulationJob] [neo4j/cbf915ea] Completed node store scan. Flushing all pending updates.
    MultipleIndexPopulator{activeTasks=0, batchedUpdatesFromScan = [org.neo4j.kernel.impl.api.index.MultipleIndexPopulator$IndexPopulation@703e6b93], concurrentUpdateQueue = 0}
    2022-06-18 12:30:30.400+0000 INFO [o.n.k.i.a.i.IndexPopulationJob] [neo4j/cbf915ea] Index creation finished for index [Index( id=7, name='LogKey', type='UNIQUE BTREE', schema=(:Log {logID}), indexProvider='native-btree-1.0' )].
    2022-06-18 12:30:30.425+0000 INFO [o.n.k.i.a.i.IndexPopulationJob] [neo4j/cbf915ea] TIME/PHASE Final: SCAN[totalTime=0ns], MERGE[totalTime=0ns], BUILD[totalTime=1ms], APPLY_EXTERNAL[totalTime=19ms], FLIP[totalTime=30ms]
    2022-06-18 12:30:30.426+0000 INFO [o.n.k.i.a.s.ConstraintIndexCreator] [neo4j/cbf915ea] Constraint Constraint( name='LogKey', type='NODE KEY', schema=(:Log {logID}) ) populated, starting verification.
    2022-06-18 12:30:30.427+0000 INFO [o.n.k.i.a.s.ConstraintIndexCreator] [neo4j/cbf915ea] Constraint Constraint( name='LogKey', type='NODE KEY', schema=(:Log {logID}) ) verified.
    2022-06-18 12:30:30.451+0000 INFO [o.n.k.i.a.i.IndexingService] [neo4j/cbf915ea] Constraint Index( id=7, name='LogKey', type='UNIQUE BTREE', schema=(:Label[2] {PropertyKey[24]}), indexProvider='native-btree-1.0' ) is ONLINE.
    2022-06-18 12:31:17.368+0000 INFO [o.n.c.i.ExecutionEngine] [neo4j/cbf915ea] Discarded stale query from the query cache after 40 seconds. Reason: NodesAllCardinality changed from 10.0 to 780.0, which is a divergence of 0.9871794871794872 which is greater than threshold 0.7442257653028063. Query id: 67
    2022-06-18 12:31:17.368+0000 INFO [o.n.c.i.ExecutionEngine] [neo4j/cbf915ea] Discarded stale query from the query cache after 39 seconds. Reason: NodesAllCardinality changed from 10.0 to 780.0, which is a divergence of 0.9871794871794872 which is greater than threshold 0.7442425350218457. Query id: 68
    2022-06-18 12:31:17.368+0000 INFO [o.n.c.i.ExecutionEngine] [neo4j/cbf915ea] Discarded stale query from the query cache after 40 seconds. Reason: NodesAllCardinality changed from 10.0 to 780.0, which is a divergence of 0.9871794871794872 which is greater than threshold 0.7442257653028063. Query id: 69
    2022-06-18 12:33:57.656+0000 INFO [o.n.c.i.ExecutionEngine] [neo4j/cbf915ea] Discarded stale query from the query cache after 160 seconds. Reason: CardinalityByLabelsAndRelationshipType(None,None,None) changed from 1.0 to 1671.0, which is a divergence of 0.9994015559545183 which is greater than threshold 0.7220188185028134. Query id: 125
    2022-06-18 12:34:25.093+0000 INFO [c.n.d.DbmsReconciler] Database 'neo4j' is requested to transition from STARTED{db=neo4j/cbf915ea} to STOPPED{db=neo4j/cbf915ea} by SystemGraph:2
    2022-06-18 12:34:25.094+0000 INFO [c.n.d.d.EnterpriseMultiDatabaseManager] Stopping 'DatabaseId{cbf915ea[neo4j]}'.
    2022-06-18 12:34:25.094+0000 INFO [o.n.k.a.DatabaseAvailabilityGuard] [neo4j/cbf915ea] Requirement `Database unavailable` makes database neo4j unavailable.
    2022-06-18 12:34:25.094+0000 INFO [o.n.k.a.DatabaseAvailabilityGuard] [neo4j/cbf915ea] DatabaseId{cbf915ea[neo4j]} is unavailable.
    2022-06-18 12:34:25.101+0000 INFO [o.n.k.d.Database] [neo4j/cbf915ea] Waiting for closing transactions.
    2022-06-18 12:34:25.102+0000 INFO [o.n.k.d.Database] [neo4j/cbf915ea] All transactions are closed.
    2022-06-18 12:34:25.105+0000 INFO [o.n.k.i.t.l.c.CheckPointerImpl] [neo4j/cbf915ea] Checkpoint triggered by "Database shutdown" @ txId: 40 checkpoint started...
    2022-06-18 12:34:25.191+0000 INFO [o.n.k.i.t.l.c.CheckPointerImpl] [neo4j/cbf915ea] Checkpoint triggered by "Database shutdown" @ txId: 40 checkpoint completed in 85ms
    2022-06-18 12:34:25.197+0000 INFO [o.n.k.i.t.l.p.LogPruningImpl] [neo4j/cbf915ea] No log version pruned. The strategy used was '7 days'.
    2022-06-18 12:34:25.262+0000 INFO [c.n.d.DbmsReconciler] Database 'neo4j' transition is complete from STARTED{db=neo4j/cbf915ea} to STOPPED{db=neo4j/cbf915ea} (request by SystemGraph:2)
    2022-06-18 12:35:15.302+0000 INFO [o.n.c.i.ExecutionEngine] [system/00000000] Discarded stale query from the query cache after 471 seconds. Reason: IndexSelectivity(IndexDescriptor(Btree,Node(LabelId(0)),List(PropertyKeyId(10)),Set(),org.neo4j.cypher.internal.planner.spi.IndexDescriptor$$$Lambda$3667/0x0000000102064840@75e953a,org.neo4j.cypher.internal.planner.spi.IndexDescriptor$$$Lambda$3668/0x0000000102065040@3afa1799,false)) changed from 0.0 to 0.5, which is a divergence of 1.0 which is greater than threshold 0.6702321325088926. Query id: 148

2

Hmm, what do you mean when you say you removed it?

DROP DATABASE neo4j ?

Or did you delete things on disk? (you should avoid that as you have to delete stuff in multiple places i.e both in data/databases/ and data/transactions/ )

There are rename commands and aliases, so no need to delete the database just to give it a new name.

You can start/stop a database from the system db.

For neo4j-admin copy and load both you might need to create the db name in the system db after adding the db on disk.

Hope this helped a bit.

Your log is unfortunately not complete, so there is only the info on stopping the db but no error on starting.

If you use SHOW DATABASES it should show the error message if the database is not online, otherwise look into debug.log for more details.