NonUniqueTokenException. Can't launch database. Can't use cypher-shell to fix it

[malik]

Hello friends,

I stumbled upon yet another roadblock. I'm running Neo4j 4.0.0 CE.
I was running the following query using the official python Neo4j Bolt driver:

session.run(
  "MATCH (u:User), (p:Podcast) WHERE p.podcastId = $podcastId AND u.uuid = $sub "
  "MERGE (u)-[eo:EDITOR_OF]->(p) "
  "ON CREATE SET eo.isActive = false, eo.lastVerificationRequestOnDT = datetime() "
  "ON MATCH SET eo.lastVerificationRequestOnDT = datetime() "
  "RETURN eo;",
  {'podcastId':podcast_id, 'sub': sub}
).single()

I was constantly getting the following error:

[ERROR] DatabaseError: Newly created token should be unique.

I've stoped the database and tried to restart but couldn't because of the following error I could identify by running neo4j-admin consistency-check:

org.neo4j.token.api.NonUniqueTokenException: The PropertyKey NamedToken[name:lastVerificationRequestedOnDT, id:91, internal:false] is not unique, it existed as null.

Now I'm not even able fix it through cypher-shell because of the following:

Unable to get a routing table for database 'graph.db' because this database is unavailable

And so I'm stuck!
Can anyone suggest the way to restore it without running a full backup?

---

Also, can anyone tell me why it was considered necessary for this relationship's property to be unique? There's no such constraint specified in my schema and there's nothing in the query that might indicate any need for uniqueness.

---

Thank you in advance.

[malik]

OK, here's what I've found out:

The query above works like a charm in Neo4j 3.5.14 but not always in Neo4j 4.0.0. When I run it the first time after a full backup I get the aforementioned error:

[ERROR] DatabaseError: Newly created token should be unique.

be it in Neo4j browser or anything else. Then I'd tweak the query a bit just to change the format a bit, for example:

MATCH (u:User {uuid: "randomuuidhere"})
MATCH (p:Podcast {podcastId: "randompodcastidhere")
MERGE (u)-[eo:EDITOR_OF]->(p)
SET eo.isActive = false, eo.lastVerificationRequestOnDT = datetime()
RETURN eo

or

MATCH (u:User {uuid: "randomuuidhere"})
MATCH (p:Podcast {podcastId: "randompodcastidhere")
WITH u, p, datetime() AS dt
MERGE (u)-[eo:EDITOR_OF]->(p)
SET eo.isActive = false, eo.lastVerificationRequestOnDT = dt
RETURN eo

It would complain a couple of times but then start working.
If I then run the initial query, it'll work.

However, I can't leave it at this as, in the meantime, I've introduced a severe inconsistency in my DB that will prevent it from starting up next time and the check-consistency command will yield the result I described at the beginning of this thread.

So, somehow, a new property key of null is being created on a relationship when used in conjunction with datetime() in Neo4j 4.0.0 CE. This is not the case in Neo4j 3.5.14.

Is there any way for me to remove the null property key once it has been created and go on with my life?

[andrew_bowman]

Can you provide a means to replicate this, either with a query to create a small data set, or with a zipped graph?

Also any additional details about your case would be helpful, such as if you're seeing this after a migration from 3.5.14 (and if you've run a consistency check before upgrading, if this is the case), or if you can replicate this with a fresh 4.0.0 graph.

Also if this was a migration, can you confirm if this is from 3.5.14 community or enterprise edition, and if you can let us know the exact version of 4.0.0 you're using, and where and when you downloaded it, to make sure you're referring to the current release candidate or to MR3 or some earlier release.

[chrisdostert]

@andrew.bowman also hitting this after upgrading from 3.5.12 to 4.0 (enterprise) last month and running in prod since. It took down our entire cluster and i'm not sure what we can do to fix it. Please assist ASAP; we're currently having a prod outage due to this.
"Caused by: org.neo4j.token.api.NonUniqueTokenException: The PropertyKey NamedToken[name:stripeBankAccountId, id:611, internal:false] is not unique, it existed as NamedToken[name:__org.neo4j.SchemaRule.IndexConfig.spatial.wgs-84.max, id:611, internal:true]. at org.neo4j.token.TokenRegistry.put(TokenRegistry.java:73) at org.neo4j.token.AbstractTokenHolderBase.addToken(AbstractTokenHolderBase.java:52) at org.neo4j.internal.recordstorage.BridgingCacheAccess.addPropertyKeyToken(BridgingCacheAccess.java:68) at org.neo4j.internal.recordstorage.CacheInvalidationTransactionApplier.visitPropertyKeyTokenCommand(CacheInvalidationTransactionApplier.java:69) at org.neo4j.internal.recordstorage.Command$PropertyKeyTokenCommand.handle(Command.java:537) at org.neo4j.internal.recordstorage.TransactionApplierFacade.visit(TransactionApplierFacade.java:57) at org.neo4j.internal.recordstorage.TransactionApplierFacade.visit(TransactionApplierFacade.java:32) at org.neo4j.kernel.impl.transaction.log.PhysicalTransactionRepresentation.accept(PhysicalTransactionRepresentation.java:76) at org.neo4j.kernel.impl.api.TransactionToApply.accept(TransactionToApply.java:130) at org.neo4j.internal.recordstorage.RecordStorageEngine.apply(RecordStorageEngine.java:294) ... 14 more"

[chrisdostert]

Figured I would try restarting the masters. Here's what the outcome is (same as original poster seemingly) "java.lang.IllegalStateException: Encountered error when attempting to reconcile database neo4j from state 'EnterpriseDatabaseState{databaseId=DatabaseId{name='neo4j', databaseId=DatabaseIdWithoutName{uuid=9f35bdfb-46ba-40f8-a292-88b0ba533c55}}, operatorState=STOPPED, failed=false}' to state 'online' at com.neo4j.dbms.DbmsReconciler.reportErrorAndPanicDatabase(DbmsReconciler.java:435) at com.neo4j.dbms.DbmsReconciler.handleReconciliationErrors(DbmsReconciler.java:420) at com.neo4j.dbms.DbmsReconciler.lambda$postReconcile$14(DbmsReconciler.java:369) at java.base/java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1947) at com.neo4j.dbms.DbmsReconciler.postReconcile(DbmsReconciler.java:367) at com.neo4j.dbms.DbmsReconciler.lambda$scheduleReconciliationJob$7(DbmsReconciler.java:234) at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859) at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837) at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1705) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:834) Caused by: org.neo4j.dbms.api.DatabaseManagementException: Unable to start database DatabaseId{name='neo4j', databaseId=DatabaseIdWithoutName{uuid=9f35bdfb-46ba-40f8-a292-88b0ba533c55}} at com.neo4j.dbms.database.ClusteredMultiDatabaseManager.startDatabase(ClusteredMultiDatabaseManager.java:83) at com.neo4j.dbms.database.ClusteredMultiDatabaseManager.startDatabase(ClusteredMultiDatabaseManager.java:37) at com.neo4j.dbms.database.MultiDatabaseManager.forSingleDatabase(MultiDatabaseManager.java:112) at com.neo4j.dbms.database.MultiDatabaseManager.startDatabase(MultiDatabaseManager.java:98) at com.neo4j.dbms.DbmsReconciler.start(DbmsReconciler.java:537) at com.neo4j.dbms.Transitions$TransitionFunction.lambda$prepare$0(Transitions.java:219) at com.neo4j.dbms.DbmsReconciler.doTransitionStep(DbmsReconciler.java:335) at com.neo4j.dbms.DbmsReconciler.doTransitionStep(DbmsReconciler.java:336) at com.neo4j.dbms.DbmsReconciler.doTransitions(DbmsReconciler.java:318) at com.neo4j.dbms.DbmsReconciler.lambda$doTransitions$9(DbmsReconciler.java:308) at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700) ... 3 more Caused by: org.neo4j.kernel.lifecycle.LifecycleException: Component 'org.neo4j.kernel.recovery.TransactionLogsRecovery@6ab5a355' failed to initialize. Please see the attached cause exception "Internal token for id 611 not found.". at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.init(LifeSupport.java:426) at org.neo4j.kernel.lifecycle.LifeSupport.init(LifeSupport.java:66) at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:102) at org.neo4j.kernel.recovery.Recovery.performRecovery(Recovery.java:364) at org.neo4j.kernel.recovery.Recovery.performRecovery(Recovery.java:246) at org.neo4j.kernel.recovery.RecoveryFacade.recovery(RecoveryFacade.java:49) at com.neo4j.causalclustering.core.CoreDatabase.lambda$new$0(CoreDatabase.java:42) at org.neo4j.kernel.lifecycle.LifecycleAdapter$3.start(LifecycleAdapter.java:86) at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:444) at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:111) at com.neo4j.causalclustering.common.ClusteredDatabase.start(ClusteredDatabase.java:39) at com.neo4j.dbms.database.ClusteredMultiDatabaseManager.startDatabase(ClusteredMultiDatabaseManager.java:79) ... 13 more Caused by: java.lang.RuntimeException: Error reading transaction logs, recovery not possible. To force the database to start anyway, you can specify 'unsupported.dbms.tx_log.fail_on_corrupted_log_files=false'. This will try to recover as much as possible and then truncate the corrupt part of the transaction log. Doing this means your database integrity might be compromised, please consider restoring from a consistent backup instead. at org.neo4j.kernel.recovery.Recovery.throwUnableToCleanRecover(Recovery.java:464) at org.neo4j.kernel.recovery.TransactionLogsRecovery.init(TransactionLogsRecovery.java:147) at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.init(LifeSupport.java:405) ... 24 more Caused by: org.neo4j.kernel.lifecycle.LifecycleException: Component 'org.neo4j.internal.recordstorage.RecordStorageEngine$2@24103d56' failed to initialize. Please see the attached cause exception "Internal token for id 611 not found.". at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.init(LifeSupport.java:426) at org.neo4j.kernel.lifecycle.LifeSupport.init(LifeSupport.java:66) at org.neo4j.kernel.recovery.TransactionLogsRecovery.init(TransactionLogsRecovery.java:117) ... 25 more Caused by: java.lang.RuntimeException: org.neo4j.internal.kernel.api.exceptions.schema.MalformedSchemaRuleException: Cannot read schema rule because it is referring to a property key token (id 611) that does not exist. at org.neo4j.internal.recordstorage.SchemaStorage.readSchemaRuleThrowingRuntimeException(SchemaStorage.java:266) at org.neo4j.internal.recordstorage.SchemaStorage.lambda$streamAllSchemaRules$5(SchemaStorage.java:238) at java.base/java.util.stream.ReferencePipeline$7$1.accept(ReferencePipeline.java:271) at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:177) at java.base/java.util.stream.LongPipeline$1$1.accept(LongPipeline.java:177) at java.base/java.util.stream.Streams$RangeLongSpliterator.tryAdvance(Streams.java:207) at java.base/java.util.Spliterator$OfLong.tryAdvance(Spliterator.java:740) at java.base/java.util.stream.StreamSpliterators$WrappingSpliterator.lambda$initPartialTraversalState$0(StreamSpliterators.java:294) at java.base/java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.fillBuffer(StreamSpliterators.java:206) at java.base/java.util.stream.StreamSpliterators$AbstractWrappingSpliterator.doAdvance(StreamSpliterators.java:161) at java.base/java.util.stream.StreamSpliterators$WrappingSpliterator.tryAdvance(StreamSpliterators.java:300) at java.base/java.util.Spliterators$1Adapter.hasNext(Spliterators.java:681) at org.neo4j.internal.recordstorage.SchemaCache$SchemaCacheState.load(SchemaCache.java:298) at org.neo4j.internal.recordstorage.SchemaCache$SchemaCacheState.(SchemaCache.java:264) at org.neo4j.internal.recordstorage.SchemaCache.load(SchemaCache.java:134) at org.neo4j.internal.recordstorage.RecordStorageEngine.loadSchemaCache(RecordStorageEngine.java:368) at org.neo4j.internal.recordstorage.RecordStorageEngine$2.init(RecordStorageEngine.java:459) at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.init(LifeSupport.java:405) ... 27 more Caused by: org.neo4j.internal.kernel.api.exceptions.schema.MalformedSchemaRuleException: Cannot read schema rule because it is referring to a property key token (id 611) that does not exist. at org.neo4j.kernel.impl.store.SchemaStore.insertPropertyIntoMap(SchemaStore.java:463) at org.neo4j.kernel.impl.store.SchemaStore.schemaRecordToMap(SchemaStore.java:445) at org.neo4j.kernel.impl.store.SchemaStore.readSchemaRule(SchemaStore.java:326) at org.neo4j.internal.recordstorage.SchemaStorage.readSchemaRule(SchemaStorage.java:274) at org.neo4j.internal.recordstorage.SchemaStorage.readSchemaRuleThrowingRuntimeException(SchemaStorage.java:259) ... 44 more Caused by: org.neo4j.token.api.TokenNotFoundException: Internal token for id 611 not found. at org.neo4j.token.AbstractTokenHolderBase.getInternalTokenById(AbstractTokenHolderBase.java:121) at org.neo4j.kernel.impl.store.SchemaStore.insertPropertyIntoMap(SchemaStore.java:457) ... 48 more"

[chrisdostert]

I tried repairing to no avail.. neo4j errored out fatally no matter what.

Had to fallback to data loss by restoring from latest backup but it's not transient. I can reproduce all over via the original cypher statement.

This is a p0 bug in v 4.0 for you guys I think. A cypher statement that was working in 3.5 irreparably corrupts the entire cluster. I'm happy to work with you to provide any details you need.

this is what version returns:
"

neo4j version

neo4j 4.0.0
"

[andrew_bowman]

I doubt the Cypher is at fault here. My guess is that this has to do with the state of your store before and after the upgrade, so information about your upgrade process would be helpful (order of steps especially with regard to backup and restore with respect to when the upgrade was performed), and if you're able to share your store file that would also help.

Also was a consistency check run before the upgrade?

You seem to be running Enterprise version, do you have a support account with us? If so creating a support ticket would be the recommended way to get immediate enterprise support.

[chrisdostert]

@andrew.bowman thanks for the response. I also just started tracking this here https://github.com/neo4j/neo4j/issues/12402

The upgrade instructions from v3.5 to v4.0 were followed verbatim.
We have a startup license so according to your support site, don't qualify for enterprise support.

Further information so far gathered: If I run the same statement without clustering enabled it succeeds without issue.

[andrew_bowman]

Thanks, we'll shift focus to the github issue for this.