structr / neo4j Database corrupted

0
votes

I'm playing around with Structr in a Linux VM w/2G of RAM. I executed a query and crashed the system. Attempts to restart the platform have failed, and the embedded db has the following error so I'm looking for hints as what might've happened. 

2016-03-07 05:19:19.235+0000 INFO  [org.neo4j]: Recovery required for log with version 0
2016-03-07 05:19:36.119+0000 ERROR [org.neo4j]: setting TM not OK. Kernel has encountered some problem, please perform necessary action (tx recovery/restart) null
java.lang.NullPointerException
        at org.neo4j.index.impl.lucene.IndexType.instantiateField(IndexType.java:318)
        at org.neo4j.index.impl.lucene.IndexType$1.addToDocument(IndexType.java:63)
        at org.neo4j.index.impl.lucene.LuceneCommandApplier.visitIndexAddRelationshipCommand(LuceneCommandApplier.java:79)
        at org.neo4j.kernel.impl.api.LegacyIndexApplier.visitIndexAddRelationshipCommand(LegacyIndexApplier.java:143)
        at org.neo4j.kernel.impl.api.CommandApplierFacade.visitIndexAddRelationshipCommand(CommandApplierFacade.java:246)
        at org.neo4j.kernel.impl.index.IndexCommand$AddRelationshipCommand.handle(IndexCommand.java:236)
        at org.neo4j.kernel.impl.api.CommandApplierFacade.visit(CommandApplierFacade.java:82)
        at org.neo4j.kernel.impl.api.CommandApplierFacade.visit(CommandApplierFacade.java:45)
        at org.neo4j.kernel.impl.transaction.log.PhysicalTransactionRepresentation.accept(PhysicalTransactionRepresentation.java:69)
        at org.neo4j.kernel.impl.api.TransactionRepresentationStoreApplier.apply(TransactionRepresentationStoreApplier.java:111)
        at org.neo4j.kernel.impl.transaction.state.RecoveryVisitor.visit(RecoveryVisitor.java:70)
        at org.neo4j.kernel.impl.transaction.state.RecoveryVisitor.visit(RecoveryVisitor.java:36)
        at org.neo4j.kernel.impl.transaction.log.LogFileRecoverer.visit(LogFileRecoverer.java:54)
        at org.neo4j.kernel.impl.transaction.log.LogFileRecoverer.visit(LogFileRecoverer.java:32)
        at org.neo4j.kernel.Recovery.init(Recovery.java:78)
        at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.init(LifeSupport.java:502)
        at org.neo4j.kernel.lifecycle.LifeSupport.init(LifeSupport.java:72)
        at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:106)
        at org.neo4j.kernel.NeoStoreDataSource.start(NeoStoreDataSource.java:579)
        at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:526)
        at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:115)
        at org.neo4j.kernel.impl.transaction.state.DataSourceManager.start(DataSourceManager.java:117)
        at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:526)
        at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:115)
        at org.neo4j.kernel.InternalAbstractGraphDatabase.run(InternalAbstractGraphDatabase.java:330)
        at org.neo4j.kernel.EmbeddedGraphDatabase.(EmbeddedGraphDatabase.java:59)
        at org.neo4j.graphdb.factory.GraphDatabaseFactory.newDatabase(GraphDatabaseFactory.java:108)
        at org.neo4j.graphdb.factory.GraphDatabaseFactory$1.newDatabase(GraphDatabaseFactory.java:95)
        at org.neo4j.graphdb.factory.GraphDatabaseBuilder.newGraphDatabase(GraphDatabaseBuilder.java:185)
        at org.structr.neo4j.Neo4jDatabaseService.initialize(Neo4jDatabaseService.java:130)
        at org.structr.core.graph.NodeService.initialize(NodeService.java:115)
        at org.structr.core.Services.createService(Services.java:550)
        at org.structr.core.Services.initialize(Services.java:325)
        at org.structr.core.Services.initialize(Services.java:297)
        at org.structr.core.Services.getInstance(Services.java:145)
        at org.structr.Server.main(Server.java:36)
2016-03-07 05:19:36.300+0000 ERROR [org.neo4j]: Exception occurred while starting the datasource. Attempting to close things down. Component 'org.neo4j.kernel.Recovery@245b6b85' failed to initialize. Please see attached cause exception.
org.neo4j.kernel.lifecycle.LifecycleException: Component 'org.neo4j.kernel.Recovery@245b6b85' failed to initialize. Please see attached cause exception.
        at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.init(LifeSupport.java:508)
        at org.neo4j.kernel.lifecycle.LifeSupport.init(LifeSupport.java:72)
        at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:106)
        at org.neo4j.kernel.NeoStoreDataSource.start(NeoStoreDataSource.java:579)
        at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:526)
        at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:115)
        at org.neo4j.kernel.impl.transaction.state.DataSourceManager.start(DataSourceManager.java:117)
        at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:526)
        at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:115)
        at org.neo4j.kernel.InternalAbstractGraphDatabase.run(InternalAbstractGraphDatabase.java:330)
        at org.neo4j.kernel.EmbeddedGraphDatabase.(EmbeddedGraphDatabase.java:59)
        at org.neo4j.graphdb.factory.GraphDatabaseFactory.newDatabase(GraphDatabaseFactory.java:108)
        at org.neo4j.graphdb.factory.GraphDatabaseFactory$1.newDatabase(GraphDatabaseFactory.java:95)
        at org.neo4j.graphdb.factory.GraphDatabaseBuilder.newGraphDatabase(GraphDatabaseBuilder.java:185)
        at org.structr.neo4j.Neo4jDatabaseService.initialize(Neo4jDatabaseService.java:130)
        at org.structr.core.graph.NodeService.initialize(NodeService.java:115)
        at org.structr.core.Services.createService(Services.java:550)
        at org.structr.core.Services.initialize(Services.java:325)
        at org.structr.core.Services.initialize(Services.java:297)
        at org.structr.core.Services.getInstance(Services.java:145)
        at org.structr.Server.main(Server.java:36)
Caused by: java.lang.NullPointerException
        at org.neo4j.index.impl.lucene.IndexType.instantiateField(IndexType.java:318)
        at org.neo4j.index.impl.lucene.IndexType$1.addToDocument(IndexType.java:63)
        at org.neo4j.index.impl.lucene.LuceneCommandApplier.visitIndexAddRelationshipCommand(LuceneCommandApplier.java:79)
        at org.neo4j.kernel.impl.api.LegacyIndexApplier.visitIndexAddRelationshipCommand(LegacyIndexApplier.java:143)
        at org.neo4j.kernel.impl.api.CommandApplierFacade.visitIndexAddRelationshipCommand(CommandApplierFacade.java:246)
        at org.neo4j.kernel.impl.index.IndexCommand$AddRelationshipCommand.handle(IndexCommand.java:236)
        at org.neo4j.kernel.impl.api.CommandApplierFacade.visit(CommandApplierFacade.java:82)
        at org.neo4j.kernel.impl.api.CommandApplierFacade.visit(CommandApplierFacade.java:45)
        at org.neo4j.kernel.impl.transaction.log.PhysicalTransactionRepresentation.accept(PhysicalTransactionRepresentation.java:69)
        at org.neo5j.kernel.impl.api.TransactionRepresentationStoreApplier.apply(TransactionRepresentationStoreApplier.java:111)

the structr log has this:

Mar 07, 2016 12:19:16 AM org.structr.core.Services initialize
INFO: Starting services
Mar 07, 2016 12:19:16 AM org.structr.neo4j.Neo4jDatabaseService initialize
INFO: Relationship cache size set to 10,000
Mar 07, 2016 12:19:16 AM org.structr.neo4j.Neo4jDatabaseService initialize
INFO: Node cache size set to 10,000
Mar 07, 2016 12:19:16 AM org.structr.neo4j.Neo4jDatabaseService initialize
INFO: Initializing database (./db) ...
java.lang.RuntimeException: Error starting org.neo4j.kernel.EmbeddedGraphDatabase, /usr/local/download/structr/binaries/structr-ui-2.0-SNAPSHOT-201603060822.5403e4/./db
    at org.neo4j.kernel.InternalAbstractGraphDatabase.run(InternalAbstractGraphDatabase.java:334)
    at org.neo4j.kernel.EmbeddedGraphDatabase.(EmbeddedGraphDatabase.java:59)
    at org.neo4j.graphdb.factory.GraphDatabaseFactory.newDatabase(GraphDatabaseFactory.java:108)
    at org.neo4j.graphdb.factory.GraphDatabaseFactory$1.newDatabase(GraphDatabaseFactory.java:95)
    at org.neo4j.graphdb.factory.GraphDatabaseBuilder.newGraphDatabase(GraphDatabaseBuilder.java:185)
    at org.structr.neo4j.Neo4jDatabaseService.initialize(Neo4jDatabaseService.java:130)
    at org.structr.core.graph.NodeService.initialize(NodeService.java:115)
    at org.structr.core.Services.createService(Services.java:550)
    at org.structr.core.Services.initialize(Services.java:325)
    at org.structr.core.Services.initialize(Services.java:297)
    at org.structr.core.Services.getInstance(Services.java:145)
    at org.structr.Server.main(Server.java:36)
Caused by: org.neo4j.kernel.lifecycle.LifecycleException: Component 'org.neo4j.kernel.impl.transaction.state.DataSourceManager@162be846' was successfully initialized, but failed to start. Please see attached cause exception.
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:532)
    at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:115)
    at org.neo4j.kernel.InternalAbstractGraphDatabase.run(InternalAbstractGraphDatabase.java:330)
    ... 11 more
Caused by: org.neo4j.kernel.lifecycle.LifecycleException: Component 'org.neo4j.kernel.NeoStoreDataSource@191a8997' was successfully initialized, but failed to start. Please see attached cause exception.
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:532)
    at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:115)
    at org.neo4j.kernel.impl.transaction.state.DataSourceManager.start(DataSourceManager.java:117)
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:526)
    ... 13 more
Caused by: org.neo4j.kernel.lifecycle.LifecycleException: Component 'org.neo4j.kernel.Recovery@245b6b85' failed to initialize. Please see attached cause exception.
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.init(LifeSupport.java:508)
    at org.neo4j.kernel.lifecycle.LifeSupport.init(LifeSupport.java:72)
    at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:106)
    at org.neo4j.kernel.NeoStoreDataSource.start(NeoStoreDataSource.java:579)
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:526)
    ... 16 more
Caused by: java.lang.NullPointerException
    at org.neo4j.index.impl.lucene.IndexType.instantiateField(IndexType.java:318)
    at org.neo4j.index.impl.lucene.IndexType$1.addToDocument(IndexType.java:63)
    at org.neo4j.index.impl.lucene.LuceneCommandApplier.visitIndexAddRelationshipCommand(LuceneCommandApplier.java:79)
    at org.neo4j.kernel.impl.api.LegacyIndexApplier.visitIndexAddRelationshipCommand(LegacyIndexApplier.java:143)
    at org.neo4j.kernel.impl.api.CommandApplierFacade.visitIndexAddRelationshipCommand(CommandApplierFacade.java:246)
    at org.neo4j.kernel.impl.index.IndexCommand$AddRelationshipCommand.handle(IndexCommand.java:236)
    at org.neo4j.kernel.impl.api.CommandApplierFacade.visit(CommandApplierFacade.java:82)
    at org.neo4j.kernel.impl.api.CommandApplierFacade.visit(CommandApplierFacade.java:45)
    at org.neo4j.kernel.impl.transaction.log.PhysicalTransactionRepresentation.accept(PhysicalTransactionRepresentation.java:69)
    at org.neo4j.kernel.impl.api.TransactionRepresentationStoreApplier.apply(TransactionRepresentationStoreApplier.java:111)
    at org.neo4j.kernel.impl.transaction.state.RecoveryVisitor.visit(RecoveryVisitor.java:70)
    at org.neo4j.kernel.impl.transaction.state.RecoveryVisitor.visit(RecoveryVisitor.java:36)
    at org.neo4j.kernel.impl.transaction.log.LogFileRecoverer.visit(LogFileRecoverer.java:54)
    at org.neo4j.kernel.impl.transaction.log.LogFileRecoverer.visit(LogFileRecoverer.java:32)
    at org.neo4j.kernel.Recovery.init(Recovery.java:78)
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.init(LifeSupport.java:502)
    ... 20 more
Mar 07, 2016 12:19:36 AM org.structr.core.Services createService
SEVERE: Vital service NodeService failed to start: Error starting org.neo4j.kernel.EmbeddedGraphDatabase, /usr/local/download/structr/binaries/structr-ui-2.0-SNAPSHOT-201603060822.5403e4/./db. Aborting

This is what I get when I try to start the db using the 2.2.8 Neo4j community program. In both cases its failing on a 'null pointer' of some sort. 

Starting Neo4j Server console-mode...
Using additional JVM arguments:  -server -XX:+DisableExplicitGC -Dorg.neo4j.server.properties=conf/neo4j-server.properties -Djava.util.logging.config.file=conf/logging.properties -XX:+UseConcMarkSweepGC -XX:+CMSClassUnloadingEnabled -XX:-OmitStackTraceInFastThrow -XX:hashCode=5 -Dneo4j.ext.udc.source=tarball
2016-03-07 13:18:44.618+0000 INFO  [API] Setting startup timeout to: 120000ms based on 120000
Detected incorrectly shut down database, performing recovery..
2016-03-07 13:19:01.274+0000 INFO  [API] Successfully shutdown Neo4j Server.
2016-03-07 13:19:01.275+0000 ERROR [API] Failed to start Neo Server on port [7474]
org.neo4j.server.ServerStartupException: Starting Neo4j Server failed: Error starting org.neo4j.kernel.EmbeddedGraphDatabase, /usr/local/download/structr/binaries/structr-ui-2.0-SNAPSHOT-201603060822.5403e4/db
    at org.neo4j.server.AbstractNeoServer.start(AbstractNeoServer.java:258) ~[neo4j-server-2.2.8.jar:2.2.8]
    at org.neo4j.server.Bootstrapper.start(Bootstrapper.java:117) [neo4j-server-2.2.8.jar:2.2.8]
    at org.neo4j.server.Bootstrapper.main(Bootstrapper.java:69) [neo4j-server-2.2.8.jar:2.2.8]
Caused by: java.lang.RuntimeException: Error starting org.neo4j.kernel.EmbeddedGraphDatabase, /usr/local/download/structr/binaries/structr-ui-2.0-SNAPSHOT-201603060822.5403e4/db
    at org.neo4j.kernel.InternalAbstractGraphDatabase.run(InternalAbstractGraphDatabase.java:334) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.EmbeddedGraphDatabase.(EmbeddedGraphDatabase.java:59) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.impl.recovery.StoreRecoverer.recover(StoreRecoverer.java:96) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.server.preflight.PerformRecoveryIfNecessary.run(PerformRecoveryIfNecessary.java:65) ~[neo4j-server-2.2.8.jar:2.2.8]
    at org.neo4j.server.preflight.PreFlightTasks.run(PreFlightTasks.java:71) ~[neo4j-server-2.2.8.jar:2.2.8]
    at org.neo4j.server.AbstractNeoServer.runPreflightTasks(AbstractNeoServer.java:399) ~[neo4j-server-2.2.8.jar:2.2.8]
    at org.neo4j.server.AbstractNeoServer.start(AbstractNeoServer.java:195) ~[neo4j-server-2.2.8.jar:2.2.8]
    ... 2 common frames omitted
Caused by: org.neo4j.kernel.lifecycle.LifecycleException: Component 'org.neo4j.kernel.impl.transaction.state.DataSourceManager@2de4d378' was successfully initialized, but failed to start. Please see attached cause exception.
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:532) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:115) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.InternalAbstractGraphDatabase.run(InternalAbstractGraphDatabase.java:330) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    ... 8 common frames omitted
Caused by: org.neo4j.kernel.lifecycle.LifecycleException: Component 'org.neo4j.kernel.NeoStoreDataSource@4b9b15' was successfully initialized, but failed to start. Please see attached cause exception.
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:532) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:115) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.impl.transaction.state.DataSourceManager.start(DataSourceManager.java:117) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:526) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    ... 10 common frames omitted
Caused by: org.neo4j.kernel.lifecycle.LifecycleException: Component 'org.neo4j.kernel.Recovery@3016120' failed to initialize. Please see attached cause exception.
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.init(LifeSupport.java:508) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.lifecycle.LifeSupport.init(LifeSupport.java:72) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:106) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.NeoStoreDataSource.start(NeoStoreDataSource.java:579) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:526) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    ... 13 common frames omitted
Caused by: java.lang.NullPointerException: null
    at org.neo4j.index.impl.lucene.IndexType.instantiateField(IndexType.java:318) ~[neo4j-lucene-index-2.2.8.jar:2.2.8]
    at org.neo4j.index.impl.lucene.IndexType$1.addToDocument(IndexType.java:63) ~[neo4j-lucene-index-2.2.8.jar:2.2.8]
    at org.neo4j.index.impl.lucene.LuceneCommandApplier.visitIndexAddRelationshipCommand(LuceneCommandApplier.java:79) ~[neo4j-lucene-index-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.impl.api.LegacyIndexApplier.visitIndexAddRelationshipCommand(LegacyIndexApplier.java:143) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.impl.api.CommandApplierFacade.visitIndexAddRelationshipCommand(CommandApplierFacade.java:246) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.impl.index.IndexCommand$AddRelationshipCommand.handle(IndexCommand.java:236) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.impl.api.CommandApplierFacade.visit(CommandApplierFacade.java:82) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.impl.api.CommandApplierFacade.visit(CommandApplierFacade.java:45) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.impl.transaction.log.PhysicalTransactionRepresentation.accept(PhysicalTransactionRepresentation.java:69) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.impl.api.TransactionRepresentationStoreApplier.apply(TransactionRepresentationStoreApplier.java:111) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.impl.transaction.state.RecoveryVisitor.visit(RecoveryVisitor.java:70) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.impl.transaction.state.RecoveryVisitor.visit(RecoveryVisitor.java:36) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.impl.transaction.log.LogFileRecoverer.visit(LogFileRecoverer.java:54) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.impl.transaction.log.LogFileRecoverer.visit(LogFileRecoverer.java:32) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.Recovery.init(Recovery.java:78) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.init(LifeSupport.java:502) ~[neo4j-kernel-2.2.8.jar:2.2.8]
    ... 17 common frames omitted
1
neo4jstructr
Can you try starting this database with a Neo4j server? Just download Neo4j 2.2.8 and change org.neo4j.server.database.location to point to the structr/db folder. – Axel Morgner
I've attached the result of that attempt to the end of this question. – Tim Kuehn
From what I can see its hitting a null pointer in both the embedded and downloaded community editions. – Tim Kuehn
Also, this is being run on a 2G Linux/Centos VM. – Tim Kuehn
We can reproduce it now on another instance and will try to fix it. – Axel Morgner

1 Answers

2
votes

The root cause is that Structr tries to index an object whose toString() method returns null. As there's no filter for such objects in neither Lucene nor Neo4j, this leads to the a database crash and unrecoverable database store.

We'll provide a fix for Structr as soon as possible, and I filed an issue with Neo4j: https://github.com/neo4j/neo4j/issues/6685