search

neo4j-contrib / neo4j-apoc-procedures

Awesome Procedures On Cypher for Neo4j - codenamed "apoc"                     If you like it, please ★ above ⇧            
https://neo4j.com/labs/apoc
Apache License 2.0
1.71k stars 494 forks source link

apoc.custom.function error on startup #1871

Closed dfgitn4j closed 9 months ago

dfgitn4j commented 3 years ago

Expected Behavior (Mandatory)

No error on startup for apoc.custom.*. The function does not show up with a call to apoc.custom.list()

Actual Behavior (Mandatory)

Don't error.

How to Reproduce the Problem

  1. Take attached dump, unzip and load into a 4.2.5 Neo4j EE database (I used Neo4j Desktop to create this db)
  2. Install apoc
  3. Start db

Simple Dataset (where it's possibile)

contract-tracing-name-idx-neo4j-2021-04-26T214357.dump.zip

Steps (Mandatory)

  1. Start db
  2. Review logs/neo4j.log

Screenshots (where it's possibile)

Initial relevant section of neo4j.log

2021-04-26 21:39:02.627+0000 INFO  Starting...
2021-04-26 21:39:05.482+0000 INFO  ======== Neo4j 4.2.5 ========
2021-04-26 21:39:10.533+0000 ERROR [neo4j/99376483] Could not register function: custom.debugQry(level = OFF :: STRING?, threshold = 0s :: STRING?, logsLogLevel = NONE :: STRING?) :: (STRING?)
with: CALL dbms.setConfigValue('dbms.logs.query.enabled', $level)
 CALL dbms.setConfigValue('dbms.logs.query.page_logging_enabled', 'TRUE')
 CALL dbms.setConfigValue('dbms.logs.query.threshold', $threshold)
 CALL dbms.setConfigValue('dbms.logs.query.allocation_logging_enabled', 'TRUE')
 CALL dbms.setConfigValue('dbms.logs.query.runtime_logging_enabled', 'TRUE')
 CALL dbms.setConfigValue('dbms.logs.query.parameter_logging_enabled', 'TRUE')
 CALL dbms.setConfigValue('dbms.logs.query.time_logging_enabled', 'TRUE')

 CALL dbms.setConfigValue('dbms.logs.debug.level', $logsLogLevel)

 CALL dbms.setConfigValue('dbms.track_query_allocation', 'TRUE')
 CALL dbms.setConfigValue('dbms.track_query_cpu_time', 'TRUE')
 RETURN [{level: $level}, {threshold: $threshold}, {logsLogLevel: $logsLogLevel}] AS res
 single result true
java.lang.UnsupportedOperationException: null
    at java.util.AbstractCollection.add(AbstractCollection.java:267) ~[?:?]
    at apoc.custom.CypherProceduresHandler.registerFunction(CypherProceduresHandler.java:410) ~[apoc-4.2.0.0.jar:4.2.0.0]
    at apoc.custom.CypherProceduresHandler$UserFunctionDescriptor.register(CypherProceduresHandler.java:686) ~[apoc-4.2.0.0.jar:4.2.0.0]
    at apoc.custom.CypherProceduresHandler.lambda$restoreProceduresAndFunctions$2(CypherProceduresHandler.java:212) ~[apoc-4.2.0.0.jar:4.2.0.0]
    at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1655) ~[?:?]
    at java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:658) ~[?:?]
    at apoc.custom.CypherProceduresHandler.restoreProceduresAndFunctions(CypherProceduresHandler.java:211) ~[apoc-4.2.0.0.jar:4.2.0.0]
    at apoc.custom.CypherProceduresHandler.available(CypherProceduresHandler.java:120) ~[apoc-4.2.0.0.jar:4.2.0.0]
    at org.neo4j.internal.helpers.Listeners.notifySingleListener(Listeners.java:126) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.internal.helpers.Listeners.notify(Listeners.java:83) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.availability.DatabaseAvailabilityGuard.fulfill(DatabaseAvailabilityGuard.java:119) ~[neo4j-kernel-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.availability.DatabaseAvailability.start(DatabaseAvailability.java:61) ~[neo4j-kernel-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:442) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:110) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.database.Database.start(Database.java:511) ~[neo4j-kernel-4.2.5.jar:4.2.5]
    at org.neo4j.dbms.database.AbstractDatabaseManager.startDatabase(AbstractDatabaseManager.java:187) ~[neo4j-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.database.MultiDatabaseManager.forSingleDatabase(MultiDatabaseManager.java:141) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.database.MultiDatabaseManager.startDatabase(MultiDatabaseManager.java:119) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.Transition$Prepared.doTransitionAction(Transition.java:101) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.Transition$Prepared.doTransition(Transition.java:88) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitionStep(DbmsReconciler.java:355) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitionStep(DbmsReconciler.java:356) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitionStep(DbmsReconciler.java:356) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.lambda$doTransitions$12(DbmsReconciler.java:324) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.namedJob(DbmsReconciler.java:335) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitions(DbmsReconciler.java:325) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.lambda$doTransitions$10(DbmsReconciler.java:310) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700) [?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
    at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
    at java.lang.Thread.run(Thread.java:834) [?:?]
2021-04-26 21:39:12.006+0000 INFO  Called db.clearQueryCaches(): Query cache already empty.
2021-04-26 21:39:19.478+0000 INFO  Sending metrics to CSV file at /Users/danflavin/Library/Application Support/com.Neo4j.Relate/Data/dbmss/dbms-9c3de7fb-c391-461c-8b77-2be30636f488/metrics
2021-04-26 21:39:19.529+0000 INFO  Bolt enabled on localhost:7687.
2021-04-26 21:39:20.651+0000 INFO  Remote interface available at http://localhost:7474/
2021-04-26 21:39:20.652+0000 INFO  Started.
2021-04-26 21:39:20.927+0000 INFO  Neo4j Server shutdown initiated by request
2021-04-26 21:39:20.927+0000 INFO  Stopping...
2021-04-26 21:39:26.809+0000 INFO  Stopped.
2021-04-26 21:39:45.584+0000 INFO  Starting...
2021-04-26 21:39:48.426+0000 INFO  ======== Neo4j 4.2.5 ========
2021-04-26 21:39:51.752+0000 ERROR [neo4j/99376483] Could not register function: custom.debugQry(level = OFF :: STRING?, threshold = 0s :: STRING?, logsLogLevel = NONE :: STRING?) :: (STRING?)
with: CALL dbms.setConfigValue('dbms.logs.query.enabled', $level)
 CALL dbms.setConfigValue('dbms.logs.query.page_logging_enabled', 'TRUE')
 CALL dbms.setConfigValue('dbms.logs.query.threshold', $threshold)
 CALL dbms.setConfigValue('dbms.logs.query.allocation_logging_enabled', 'TRUE')
 CALL dbms.setConfigValue('dbms.logs.query.runtime_logging_enabled', 'TRUE')
 CALL dbms.setConfigValue('dbms.logs.query.parameter_logging_enabled', 'TRUE')
 CALL dbms.setConfigValue('dbms.logs.query.time_logging_enabled', 'TRUE')

 CALL dbms.setConfigValue('dbms.logs.debug.level', $logsLogLevel)

 CALL dbms.setConfigValue('dbms.track_query_allocation', 'TRUE')
 CALL dbms.setConfigValue('dbms.track_query_cpu_time', 'TRUE')
 RETURN [{level: $level}, {threshold: $threshold}, {logsLogLevel: $logsLogLevel}] AS res
 single result true
java.lang.UnsupportedOperationException: null
    at java.util.AbstractCollection.add(AbstractCollection.java:267) ~[?:?]
    at apoc.custom.CypherProceduresHandler.registerFunction(CypherProceduresHandler.java:414) ~[apoc-4.2.0.2.jar:4.2.0.2]
    at apoc.custom.CypherProceduresHandler$UserFunctionDescriptor.register(CypherProceduresHandler.java:692) ~[apoc-4.2.0.2.jar:4.2.0.2]
    at apoc.custom.CypherProceduresHandler.lambda$restoreProceduresAndFunctions$2(CypherProceduresHandler.java:214) ~[apoc-4.2.0.2.jar:4.2.0.2]
    at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1655) ~[?:?]
    at java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:658) ~[?:?]
    at apoc.custom.CypherProceduresHandler.restoreProceduresAndFunctions(CypherProceduresHandler.java:213) ~[apoc-4.2.0.2.jar:4.2.0.2]
    at apoc.custom.CypherProceduresHandler.available(CypherProceduresHandler.java:120) ~[apoc-4.2.0.2.jar:4.2.0.2]
    at org.neo4j.internal.helpers.Listeners.notifySingleListener(Listeners.java:126) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.internal.helpers.Listeners.notify(Listeners.java:83) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.availability.DatabaseAvailabilityGuard.fulfill(DatabaseAvailabilityGuard.java:119) ~[neo4j-kernel-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.availability.DatabaseAvailability.start(DatabaseAvailability.java:61) ~[neo4j-kernel-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:442) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:110) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.database.Database.start(Database.java:511) ~[neo4j-kernel-4.2.5.jar:4.2.5]
    at org.neo4j.dbms.database.AbstractDatabaseManager.startDatabase(AbstractDatabaseManager.java:187) ~[neo4j-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.database.MultiDatabaseManager.forSingleDatabase(MultiDatabaseManager.java:141) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.database.MultiDatabaseManager.startDatabase(MultiDatabaseManager.java:119) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.Transition$Prepared.doTransitionAction(Transition.java:101) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.Transition$Prepared.doTransition(Transition.java:88) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitionStep(DbmsReconciler.java:355) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitionStep(DbmsReconciler.java:356) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitionStep(DbmsReconciler.java:356) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.lambda$doTransitions$12(DbmsReconciler.java:324) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.namedJob(DbmsReconciler.java:335) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitions(DbmsReconciler.java:325) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.lambda$doTransitions$10(DbmsReconciler.java:310) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700) [?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
    at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
    at java.lang.Thread.run(Thread.java:834) [?:?]
2021-04-26 21:39:53.125+0000 INFO  Called db.clearQueryCaches(): Query cache already empty.
2021-04-26 21:40:07.389+0000 ERROR Failed to start Neo4j on dbms.connector.http.listen_address, a socket address. If missing port or hostname it is acquired from dbms.default_listen_address.
java.lang.RuntimeException: Error starting Neo4j database server at /Users/danflavin/Library/Application Support/com.Neo4j.Relate/Data/dbmss/dbms-3944ce61-8fa4-4f02-b8d9-472601496be9/data/databases
    at org.neo4j.graphdb.facade.DatabaseManagementServiceFactory.startDatabaseServer(DatabaseManagementServiceFactory.java:207) ~[neo4j-4.2.5.jar:4.2.5]
    at org.neo4j.graphdb.facade.DatabaseManagementServiceFactory.build(DatabaseManagementServiceFactory.java:163) ~[neo4j-4.2.5.jar:4.2.5]
    at com.neo4j.server.enterprise.EnterpriseManagementServiceFactory.createManagementService(EnterpriseManagementServiceFactory.java:38) ~[neo4j-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.server.enterprise.EnterpriseBootstrapper.createNeo(EnterpriseBootstrapper.java:20) ~[neo4j-enterprise-4.2.5.jar:4.2.5]
    at org.neo4j.server.NeoBootstrapper.start(NeoBootstrapper.java:134) [neo4j-4.2.5.jar:4.2.5]
    at org.neo4j.server.NeoBootstrapper.start(NeoBootstrapper.java:90) [neo4j-4.2.5.jar:4.2.5]
    at com.neo4j.server.enterprise.EnterpriseEntryPoint.main(EnterpriseEntryPoint.java:25) [neo4j-enterprise-4.2.5.jar:4.2.5]
Caused by: org.neo4j.kernel.lifecycle.LifecycleException: Component 'org.neo4j.procedure.impl.GlobalProceduresRegistry@6537ac' was successfully initialized, but failed to start. Please see the attached cause exception "Unable to register procedure, because the name `apoc.generate.ba` is already in use.".
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:463) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:110) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.graphdb.facade.DatabaseManagementServiceFactory.startDatabaseServer(DatabaseManagementServiceFactory.java:198) ~[neo4j-4.2.5.jar:4.2.5]
    ... 6 more
Caused by: org.neo4j.internal.kernel.api.exceptions.ProcedureException: Unable to register procedure, because the name `apoc.generate.ba` is already in use.
    at org.neo4j.procedure.impl.ProcedureRegistry.register(ProcedureRegistry.java:93) ~[neo4j-procedure-4.2.5.jar:4.2.5]
    at org.neo4j.procedure.impl.GlobalProceduresRegistry.register(GlobalProceduresRegistry.java:154) ~[neo4j-procedure-4.2.5.jar:4.2.5]
    at org.neo4j.procedure.impl.GlobalProceduresRegistry.register(GlobalProceduresRegistry.java:94) ~[neo4j-procedure-4.2.5.jar:4.2.5]
    at org.neo4j.procedure.impl.GlobalProceduresRegistry.start(GlobalProceduresRegistry.java:386) ~[neo4j-procedure-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:442) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:110) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.graphdb.facade.DatabaseManagementServiceFactory.startDatabaseServer(DatabaseManagementServiceFactory.java:198) ~[neo4j-4.2.5.jar:4.2.5]
    ... 6 more
2021-04-26 21:40:07.390+0000 INFO  Neo4j Server shutdown initiated by request
2021-04-26 21:40:07.390+0000 INFO  Stopped.
2021-04-26 21:41:55.168+0000 INFO  Starting...
2021-04-26 21:41:57.916+0000 INFO  ======== Neo4j 4.2.5 ========
2021-04-26 21:42:01.253+0000 ERROR [neo4j/99376483] Could not register function: custom.debugQry(level = OFF :: STRING?, threshold = 0s :: STRING?, logsLogLevel = NONE :: STRING?) :: (STRING?)
with: CALL dbms.setConfigValue('dbms.logs.query.enabled', $level)
 CALL dbms.setConfigValue('dbms.logs.query.page_logging_enabled', 'TRUE')
 CALL dbms.setConfigValue('dbms.logs.query.threshold', $threshold)
 CALL dbms.setConfigValue('dbms.logs.query.allocation_logging_enabled', 'TRUE')
 CALL dbms.setConfigValue('dbms.logs.query.runtime_logging_enabled', 'TRUE')
 CALL dbms.setConfigValue('dbms.logs.query.parameter_logging_enabled', 'TRUE')
 CALL dbms.setConfigValue('dbms.logs.query.time_logging_enabled', 'TRUE')

 CALL dbms.setConfigValue('dbms.logs.debug.level', $logsLogLevel)

 CALL dbms.setConfigValue('dbms.track_query_allocation', 'TRUE')
 CALL dbms.setConfigValue('dbms.track_query_cpu_time', 'TRUE')
 RETURN [{level: $level}, {threshold: $threshold}, {logsLogLevel: $logsLogLevel}] AS res
 single result true
java.lang.UnsupportedOperationException: null
    at java.util.AbstractCollection.add(AbstractCollection.java:267) ~[?:?]
    at apoc.custom.CypherProceduresHandler.registerFunction(CypherProceduresHandler.java:410) ~[apoc-4.2.0.0.jar:4.2.0.0]
    at apoc.custom.CypherProceduresHandler$UserFunctionDescriptor.register(CypherProceduresHandler.java:686) ~[apoc-4.2.0.0.jar:4.2.0.0]
    at apoc.custom.CypherProceduresHandler.lambda$restoreProceduresAndFunctions$2(CypherProceduresHandler.java:212) ~[apoc-4.2.0.0.jar:4.2.0.0]
    at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1655) ~[?:?]
    at java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:658) ~[?:?]
    at apoc.custom.CypherProceduresHandler.restoreProceduresAndFunctions(CypherProceduresHandler.java:211) ~[apoc-4.2.0.0.jar:4.2.0.0]
    at apoc.custom.CypherProceduresHandler.available(CypherProceduresHandler.java:120) ~[apoc-4.2.0.0.jar:4.2.0.0]
    at org.neo4j.internal.helpers.Listeners.notifySingleListener(Listeners.java:126) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.internal.helpers.Listeners.notify(Listeners.java:83) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.availability.DatabaseAvailabilityGuard.fulfill(DatabaseAvailabilityGuard.java:119) ~[neo4j-kernel-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.availability.DatabaseAvailability.start(DatabaseAvailability.java:61) ~[neo4j-kernel-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:442) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:110) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.database.Database.start(Database.java:511) ~[neo4j-kernel-4.2.5.jar:4.2.5]
    at org.neo4j.dbms.database.AbstractDatabaseManager.startDatabase(AbstractDatabaseManager.java:187) ~[neo4j-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.database.MultiDatabaseManager.forSingleDatabase(MultiDatabaseManager.java:141) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.database.MultiDatabaseManager.startDatabase(MultiDatabaseManager.java:119) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.Transition$Prepared.doTransitionAction(Transition.java:101) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.Transition$Prepared.doTransition(Transition.java:88) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitionStep(DbmsReconciler.java:355) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitionStep(DbmsReconciler.java:356) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitionStep(DbmsReconciler.java:356) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.lambda$doTransitions$12(DbmsReconciler.java:324) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.namedJob(DbmsReconciler.java:335) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitions(DbmsReconciler.java:325) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.lambda$doTransitions$10(DbmsReconciler.java:310) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700) [?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
    at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
    at java.lang.Thread.run(Thread.java:834) [?:?]
2021-04-26 21:42:02.657+0000 INFO  Called db.clearQueryCaches(): Query cache already empty.
2021-04-26 21:42:10.392+0000 INFO  Sending metrics to CSV file at /Users/danflavin/Library/Application Support/com.Neo4j.Relate/Data/dbmss/dbms-3944ce61-8fa4-4f02-b8d9-472601496be9/metrics
2021-04-26 21:42:10.425+0000 INFO  Bolt enabled on localhost:7687.
2021-04-26 21:42:11.532+0000 INFO  Remote interface available at http://localhost:7474/
2021-04-26 21:42:11.533+0000 INFO  Started

Specifications (Mandatory)

Code used to create function:

CALL apoc.custom.asFunction('debugQry',
'CALL dbms.setConfigValue(\'dbms.logs.query.enabled\', $level)
 CALL dbms.setConfigValue(\'dbms.logs.query.page_logging_enabled\', \'TRUE\')
 CALL dbms.setConfigValue(\'dbms.logs.query.threshold\', $threshold)
 CALL dbms.setConfigValue(\'dbms.logs.query.allocation_logging_enabled\', \'TRUE\')
 CALL dbms.setConfigValue(\'dbms.logs.query.runtime_logging_enabled\', \'TRUE\')
 CALL dbms.setConfigValue(\'dbms.logs.query.parameter_logging_enabled\', \'TRUE\')
 CALL dbms.setConfigValue(\'dbms.logs.query.time_logging_enabled\', \'TRUE\')

 CALL dbms.setConfigValue(\'dbms.logs.debug.level\', $logsLogLevel)

 CALL dbms.setConfigValue(\'dbms.track_query_allocation\', \'TRUE\')
 CALL dbms.setConfigValue(\'dbms.track_query_cpu_time\', \'TRUE\')
 RETURN [{level: $level}, {threshold: $threshold}, {logsLogLevel: $logsLogLevel}] AS res',
'RETURN res',
[['level', 'STRING', "'OFF'"], ['threshold', 'STRING', "'0s'"], ['logsLogLevel', 'STRING', "'NONE'"]],  TRUE, 'Set debug: RETURN custom.debugQry(\'VERBOSE\', \'0s\', \'INFO\')')
;

Currently used versions

Versions

voutilad commented 3 years ago

Simpler reproduction using Neo4j 4.2.5 and APOC 4.2.0.2:

  1. Create a new dbms, installing APOC.
  2. Connect to the neo4j database and run: 
    CALL apoc.custom.asFunction('fn', 'return 1');
  3. Restart the dbms
  4. Check the neo4j logs
2021-04-27 14:51:24.103+0000 INFO  Starting...
2021-04-27 14:51:26.762+0000 INFO  ======== Neo4j 4.2.5 ========
2021-04-27 14:51:30.483+0000 ERROR [neo4j/a79ccc62] Could not register function: custom.fn(params = {} :: MAP?) :: (LIST? OF MAP?)
with: return 1
 single result false
java.lang.UnsupportedOperationException: null
    at java.util.AbstractCollection.add(AbstractCollection.java:267) ~[?:?]
    at apoc.custom.CypherProceduresHandler.registerFunction(CypherProceduresHandler.java:414) ~[apoc-4.2.0.2.jar:4.2.0.2]
    at apoc.custom.CypherProceduresHandler$UserFunctionDescriptor.register(CypherProceduresHandler.java:692) ~[apoc-4.2.0.2.jar:4.2.0.2]
    at apoc.custom.CypherProceduresHandler.lambda$restoreProceduresAndFunctions$2(CypherProceduresHandler.java:214) ~[apoc-4.2.0.2.jar:4.2.0.2]
    at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1655) ~[?:?]
    at java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:658) ~[?:?]
    at apoc.custom.CypherProceduresHandler.restoreProceduresAndFunctions(CypherProceduresHandler.java:213) ~[apoc-4.2.0.2.jar:4.2.0.2]
    at apoc.custom.CypherProceduresHandler.available(CypherProceduresHandler.java:120) ~[apoc-4.2.0.2.jar:4.2.0.2]
    at org.neo4j.internal.helpers.Listeners.notifySingleListener(Listeners.java:126) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.internal.helpers.Listeners.notify(Listeners.java:83) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.availability.DatabaseAvailabilityGuard.fulfill(DatabaseAvailabilityGuard.java:119) ~[neo4j-kernel-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.availability.DatabaseAvailability.start(DatabaseAvailability.java:61) ~[neo4j-kernel-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:442) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:110) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.database.Database.start(Database.java:511) ~[neo4j-kernel-4.2.5.jar:4.2.5]
    at org.neo4j.dbms.database.AbstractDatabaseManager.startDatabase(AbstractDatabaseManager.java:187) ~[neo4j-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.database.MultiDatabaseManager.forSingleDatabase(MultiDatabaseManager.java:141) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.database.MultiDatabaseManager.startDatabase(MultiDatabaseManager.java:119) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.Transition$Prepared.doTransitionAction(Transition.java:101) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.Transition$Prepared.doTransition(Transition.java:88) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitionStep(DbmsReconciler.java:355) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitionStep(DbmsReconciler.java:356) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitionStep(DbmsReconciler.java:356) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.lambda$doTransitions$12(DbmsReconciler.java:324) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.namedJob(DbmsReconciler.java:335) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitions(DbmsReconciler.java:325) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.lambda$doTransitions$10(DbmsReconciler.java:310) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700) [?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
    at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
    at java.lang.Thread.run(Thread.java:834) [?:?]
voutilad commented 3 years ago

Probably duplicate of #1744

dfgitn4j commented 3 years ago

Just tried apoc 4.2.0.3 on a 4.2.5 db per the original problem definition and I still get the same error / unable to start db. Hence not resolved by #1744 unfortunately

2021-05-04 19:17:35.299+0000 INFO  Starting...
2021-05-04 19:17:38.092+0000 INFO  ======== Neo4j 4.2.5 ========
2021-05-04 19:17:41.207+0000 ERROR [neo4j/99376483] Could not register function: custom.debugQry(level = OFF :: STRING?, threshold = 0s :: STRING?, logsLogLevel = NONE :: STRING?) :: (STRING?)
with: CALL dbms.setConfigValue('dbms.logs.query.enabled', $level)
 CALL dbms.setConfigValue('dbms.logs.query.page_logging_enabled', 'TRUE')
 CALL dbms.setConfigValue('dbms.logs.query.threshold', $threshold)
 CALL dbms.setConfigValue('dbms.logs.query.allocation_logging_enabled', 'TRUE')
 CALL dbms.setConfigValue('dbms.logs.query.runtime_logging_enabled', 'TRUE')
 CALL dbms.setConfigValue('dbms.logs.query.parameter_logging_enabled', 'TRUE')
 CALL dbms.setConfigValue('dbms.logs.query.time_logging_enabled', 'TRUE')

 CALL dbms.setConfigValue('dbms.logs.debug.level', $logsLogLevel)

 CALL dbms.setConfigValue('dbms.track_query_allocation', 'TRUE')
 CALL dbms.setConfigValue('dbms.track_query_cpu_time', 'TRUE')
 RETURN [{level: $level}, {threshold: $threshold}, {logsLogLevel: $logsLogLevel}] AS res
 single result true
java.lang.UnsupportedOperationException: null
    at java.util.AbstractCollection.add(AbstractCollection.java:267) ~[?:?]
    at apoc.custom.CypherProceduresHandler.registerFunction(CypherProceduresHandler.java:412) ~[apoc-4.2.0.3.jar:4.2.0.3]
    at apoc.custom.CypherProceduresHandler$UserFunctionDescriptor.register(CypherProceduresHandler.java:694) ~[apoc-4.2.0.3.jar:4.2.0.3]
    at apoc.custom.CypherProceduresHandler.lambda$restoreProceduresAndFunctions$2(CypherProceduresHandler.java:213) ~[apoc-4.2.0.3.jar:4.2.0.3]
    at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1655) ~[?:?]
    at java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:658) ~[?:?]
    at apoc.custom.CypherProceduresHandler.restoreProceduresAndFunctions(CypherProceduresHandler.java:212) ~[apoc-4.2.0.3.jar:4.2.0.3]
    at apoc.custom.CypherProceduresHandler.available(CypherProceduresHandler.java:119) ~[apoc-4.2.0.3.jar:4.2.0.3]
    at org.neo4j.internal.helpers.Listeners.notifySingleListener(Listeners.java:126) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.internal.helpers.Listeners.notify(Listeners.java:83) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.availability.DatabaseAvailabilityGuard.fulfill(DatabaseAvailabilityGuard.java:119) ~[neo4j-kernel-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.availability.DatabaseAvailability.start(DatabaseAvailability.java:61) ~[neo4j-kernel-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:442) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:110) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.database.Database.start(Database.java:511) ~[neo4j-kernel-4.2.5.jar:4.2.5]
    at org.neo4j.dbms.database.AbstractDatabaseManager.startDatabase(AbstractDatabaseManager.java:187) ~[neo4j-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.database.MultiDatabaseManager.forSingleDatabase(MultiDatabaseManager.java:141) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.database.MultiDatabaseManager.startDatabase(MultiDatabaseManager.java:119) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.Transition$Prepared.doTransitionAction(Transition.java:101) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.Transition$Prepared.doTransition(Transition.java:88) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitionStep(DbmsReconciler.java:355) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitionStep(DbmsReconciler.java:356) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitionStep(DbmsReconciler.java:356) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.lambda$doTransitions$12(DbmsReconciler.java:324) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.namedJob(DbmsReconciler.java:335) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.doTransitions(DbmsReconciler.java:325) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.dbms.DbmsReconciler.lambda$doTransitions$10(DbmsReconciler.java:310) ~[neo4j-dbms-enterprise-4.2.5.jar:4.2.5]
    at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700) [?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
    at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
    at java.lang.Thread.run(Thread.java:834) [?:?]
2021-05-04 19:17:42.538+0000 INFO  Called db.clearQueryCaches(): Query cache already empty.
2021-05-04 19:17:48.574+0000 ERROR Failed to start Neo4j on dbms.connector.http.listen_address, a socket address. If missing port or hostname it is acquired from dbms.default_listen_address.
java.lang.RuntimeException: Error starting Neo4j database server at /Users/danflavin/Library/Application Support/com.Neo4j.Relate/Data/dbmss/dbms-3944ce61-8fa4-4f02-b8d9-472601496be9/data/databases
    at org.neo4j.graphdb.facade.DatabaseManagementServiceFactory.startDatabaseServer(DatabaseManagementServiceFactory.java:207) ~[neo4j-4.2.5.jar:4.2.5]
    at org.neo4j.graphdb.facade.DatabaseManagementServiceFactory.build(DatabaseManagementServiceFactory.java:163) ~[neo4j-4.2.5.jar:4.2.5]
    at com.neo4j.server.enterprise.EnterpriseManagementServiceFactory.createManagementService(EnterpriseManagementServiceFactory.java:38) ~[neo4j-enterprise-4.2.5.jar:4.2.5]
    at com.neo4j.server.enterprise.EnterpriseBootstrapper.createNeo(EnterpriseBootstrapper.java:20) ~[neo4j-enterprise-4.2.5.jar:4.2.5]
    at org.neo4j.server.NeoBootstrapper.start(NeoBootstrapper.java:134) [neo4j-4.2.5.jar:4.2.5]
    at org.neo4j.server.NeoBootstrapper.start(NeoBootstrapper.java:90) [neo4j-4.2.5.jar:4.2.5]
    at com.neo4j.server.enterprise.EnterpriseEntryPoint.main(EnterpriseEntryPoint.java:25) [neo4j-enterprise-4.2.5.jar:4.2.5]
Caused by: org.neo4j.kernel.lifecycle.LifecycleException: Component 'org.neo4j.procedure.impl.GlobalProceduresRegistry@3b6c2be6' was successfully initialized, but failed to start. Please see the attached cause exception "Some jar procedure files (bloom-plugin-4.x-1.5.1.jar) are invalid, see log for details.".
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:463) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:110) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.graphdb.facade.DatabaseManagementServiceFactory.startDatabaseServer(DatabaseManagementServiceFactory.java:198) ~[neo4j-4.2.5.jar:4.2.5]
    ... 6 more
Caused by: java.util.zip.ZipException: Some jar procedure files (bloom-plugin-4.x-1.5.1.jar) are invalid, see log for details.
    at org.neo4j.procedure.impl.ProcedureJarLoader.loadProceduresFromDir(ProcedureJarLoader.java:82) ~[neo4j-procedure-4.2.5.jar:4.2.5]
    at org.neo4j.procedure.impl.GlobalProceduresRegistry.start(GlobalProceduresRegistry.java:383) ~[neo4j-procedure-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.lifecycle.LifeSupport$LifecycleInstance.start(LifeSupport.java:442) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.kernel.lifecycle.LifeSupport.start(LifeSupport.java:110) ~[neo4j-common-4.2.5.jar:4.2.5]
    at org.neo4j.graphdb.facade.DatabaseManagementServiceFactory.startDatabaseServer(DatabaseManagementServiceFactory.java:198) ~[neo4j-4.2.5.jar:4.2.5]
    ... 6 more
2021-05-04 19:17:48.575+0000 INFO  Neo4j Server shutdown initiated by request
2021-05-04 19:17:48.575+0000 INFO  Stopped.
conker84 commented 3 years ago

@vga91 is this fixed?

rjbaucells commented 3 years ago

I can confirm the error is still present in apoc-4.2.0.4.

This bug prevents the use of custom.xxx() functions and procedures. Once the database is restarted and the error happens there is nothing we can do to re-register the custom functions and procedures. The only solution I have found is removing all custom procedures & functions, restarting the db and registering again:

CALL apoc.custom.list() YIELD name 
WITH name 
CALL apoc.custom.removeProcedure(name) 
RETURN name

Restart database, and then register all procedures and functions

rjbaucells commented 3 years ago

Any updated on this issue, I just upgraded to Neo4J 4.3 using APOC 4.3.0.0 and the bug is still present.

This bug prevents the use of custom.xxx() functions and procedures!

vga91 commented 3 years ago

@rjbaucells
The bug has been fixed and will be released soon. However, it should only be a "log-only bug", it should still work. That is, with:

the procedure works despite the UnsupportedOperationException: null log error.

Maybe your problem is another. Could you provide the steps to replicate the issue and the full log? Thank you.

rjbaucells commented 3 years ago

Yes, I am facing another problem. A new database with your steps (@vga91) work fine, but I am pretty sure my problem was triggered by the database restart. I had a few procedures registered in the database (working without problems), after a restart they stop working with the following error (on the application side):

Neo.DatabaseError.Statement.ExecutionFailed

There is no procedure with the name `custom.XXX` registered for this database instance. Please ensure you've spelled the procedure name correctly and that the procedure is properly deployed.

I delete all the procedures from the database:

CALL apoc.custom.list() YIELD name WITH name CALL apoc.custom.removeProcedure(name)  RETURN name

verified they were gone:

CALL apoc.custom.list()

but they are still present in the database:

CALL dbms.procedures() YIELD name WITH name WHERE name STARTS WITH 'custom.' RETURN name
╒══════════════╕
│"name"        │
╞══════════════╡
│"custom.test1"│
├──────────────┤
│"custom.test2"│
└──────────────┘

Re-registering those procedures again does not make any difference, I continue getting the same error that the procedure does not exists (CALL apoc.custom.list() list them without problems).

vga91 commented 3 years ago

@rjbaucells Could you write one or more procedures that cause this problem? And also the error attached in the neo4j.log.

rjbaucells commented 3 years ago

Sorry, but I gave up, no longer using custom functions/procedures.

A simple test that I cannot make it work:

CALL apoc.custom.declareFunction('test2(subject::NODE) :: BOOLEAN', 'RETURN true', true, 'dummy function');

This statement works and returns true for all nodes:

MATCH (n:`AnyLabel`) return custom.test2(n) as V
╒════╕
│"V" │
╞════╡
│true│
├────┤
│true│
├────┤
│true│
├────┤
│true│
├────┤
│true│
├────┤
│true│
├────┤
│true│
├────┤
│true│
├────┤
│true│
└────┘

This statement errors out:

MATCH (n) return custom.test2(n) as V
Neo.DatabaseError.Statement.ExecutionFailed

Unknown function 'custom.test2'

Log file:

2021-07-02 20:25:31.263+0000 ERROR [o.n.b.r.s.i.ErrorReporter] Client triggered an unexpected error [Neo.DatabaseError.Statement.ExecutionFailed]: Unknown function 'custom.test2', reference 492807c8-db7f-43fc-b0b2-6cc5aa916dc2.
2021-07-02 20:25:31.263+0000 ERROR [o.n.b.r.s.i.ErrorReporter] Client triggered an unexpected error [Neo.DatabaseError.Statement.ExecutionFailed]: Unknown function 'custom.test2', reference 492807c8-db7f-43fc-b0b2-6cc5aa916dc2.
org.neo4j.fabric.executor.FabricException: Unknown function 'custom.test2'
    at org.neo4j.fabric.executor.Exceptions.transform(Exceptions.java:65) ~[neo4j-fabric-4.3.1.jar:4.3.1]
    at org.neo4j.fabric.executor.Exceptions.transform(Exceptions.java:35) ~[neo4j-fabric-4.3.1.jar:4.3.1]
    at org.neo4j.fabric.stream.Rx2SyncStream.readRecord(Rx2SyncStream.java:69) ~[neo4j-fabric-4.3.1.jar:4.3.1]
    at org.neo4j.fabric.bolt.BoltQueryExecutionImpl$QueryExecutionImpl.request(BoltQueryExecutionImpl.java:179) ~[neo4j-fabric-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.runtime.AbstractCypherAdapterStream.handleRecords(AbstractCypherAdapterStream.java:104) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.v3.messaging.ResultHandler.onPullRecords(ResultHandler.java:41) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.v4.messaging.PullResultConsumer.consume(PullResultConsumer.java:42) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.runtime.statemachine.impl.TransactionStateMachine$State.consumeResult(TransactionStateMachine.java:514) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.runtime.statemachine.impl.TransactionStateMachine$State$2.streamResult(TransactionStateMachine.java:358) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.runtime.statemachine.impl.TransactionStateMachine.streamResult(TransactionStateMachine.java:97) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.v4.runtime.InTransactionState.processStreamResultMessage(InTransactionState.java:76) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.v4.runtime.AbstractStreamingState.processUnsafe(AbstractStreamingState.java:49) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.v4.runtime.InTransactionState.processUnsafe(InTransactionState.java:63) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.v3.runtime.FailSafeBoltStateMachineState.process(FailSafeBoltStateMachineState.java:48) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.runtime.statemachine.impl.AbstractBoltStateMachine.nextState(AbstractBoltStateMachine.java:151) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.runtime.statemachine.impl.AbstractBoltStateMachine.process(AbstractBoltStateMachine.java:99) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.messaging.BoltRequestMessageReader.lambda$doRead$1(BoltRequestMessageReader.java:93) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.runtime.DefaultBoltConnection.lambda$enqueue$0(DefaultBoltConnection.java:156) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.runtime.DefaultBoltConnection.processNextBatchInternal(DefaultBoltConnection.java:252) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.runtime.DefaultBoltConnection.processNextBatch(DefaultBoltConnection.java:187) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.runtime.DefaultBoltConnection.processNextBatch(DefaultBoltConnection.java:177) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.runtime.scheduling.ExecutorBoltScheduler.executeBatch(ExecutorBoltScheduler.java:257) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at org.neo4j.bolt.runtime.scheduling.ExecutorBoltScheduler.lambda$scheduleBatchOrHandleError$3(ExecutorBoltScheduler.java:240) ~[neo4j-bolt-4.3.1.jar:4.3.1]
    at java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700) [?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-all-4.1.65.Final.jar:4.1.65.Final]
    at java.lang.Thread.run(Thread.java:829) [?:?]
Caused by: org.neo4j.graphdb.QueryExecutionException: Unknown function 'custom.test2'
    at apoc.custom.CypherProceduresHandler$2.apply(CypherProceduresHandler.java:380) ~[apoc.jar:4.3.0.0]
    at org.neo4j.procedure.impl.ProcedureRegistry.callFunction(ProcedureRegistry.java:255) ~[neo4j-procedure-4.3.1.jar:4.3.1]
    at org.neo4j.procedure.impl.GlobalProceduresRegistry.callFunction(GlobalProceduresRegistry.java:370) ~[neo4j-procedure-4.3.1.jar:4.3.1]
    at org.neo4j.kernel.impl.newapi.AllStoreHolder.callFunction(AllStoreHolder.java:1028) ~[neo4j-kernel-4.3.1.jar:4.3.1]
    at org.neo4j.kernel.impl.newapi.AllStoreHolder.functionCall(AllStoreHolder.java:932) ~[neo4j-kernel-4.3.1.jar:4.3.1]
    at org.neo4j.cypher.internal.runtime.interpreted.CallSupport$.callFunction(CallSupport.scala:39) ~[neo4j-cypher-interpreted-runtime-4.3.1.jar:4.3.1]
    at org.neo4j.cypher.internal.runtime.interpreted.TransactionBoundQueryContext.callFunction(TransactionBoundQueryContext.scala:1141) ~[neo4j-cypher-interpreted-runtime-4.3.1.jar:4.3.1]
    at org.neo4j.cypher.internal.planning.ExceptionTranslatingQueryContext.callFunction(ExceptionTranslatingQueryContext.scala:296) ~[neo4j-cypher-4.3.1.jar:4.3.1]
    at org.neo4j.codegen.OperatorTaskPipeline0_70.compiledOperate(Unknown Source) ~[?:?]
    at org.neo4j.cypher.internal.runtime.pipelined.operators.CompiledTask.operateWithProfile(OperatorCodeGenBaseTemplates.scala:450) ~[neo4j-cypher-pipelined-runtime-4.3.1.jar:4.3.1]
    at org.neo4j.cypher.internal.runtime.pipelined.PipelineTask.executeOperators(PipelineTask.scala:62) ~[neo4j-cypher-pipelined-runtime-4.3.1.jar:4.3.1]
    at org.neo4j.cypher.internal.runtime.pipelined.PipelineTask.executeWorkUnit(PipelineTask.scala:52) ~[neo4j-cypher-pipelined-runtime-4.3.1.jar:4.3.1]
    at org.neo4j.cypher.internal.runtime.pipelined.Worker.executeTask(Worker.scala:138) ~[neo4j-cypher-pipelined-runtime-4.3.1.jar:4.3.1]
    at org.neo4j.cypher.internal.runtime.pipelined.Worker.workOnQuery(Worker.scala:92) ~[neo4j-cypher-pipelined-runtime-4.3.1.jar:4.3.1]
    at org.neo4j.cypher.internal.runtime.pipelined.execution.CallingThreadExecutingQuery.request(CallingThreadExecutingQuery.scala:39) ~[neo4j-cypher-pipelined-runtime-4.3.1.jar:4.3.1]
    at org.neo4j.cypher.internal.PipelinedRuntimeResult.request(PipelinedRuntime.scala:490) ~[neo4j-enterprise-cypher-4.3.1.jar:4.3.1]
    at org.neo4j.cypher.internal.result.StandardInternalExecutionResult.request(StandardInternalExecutionResult.scala:90) ~[neo4j-cypher-4.3.1.jar:4.3.1]
    at org.neo4j.cypher.internal.result.ClosingExecutionResult.request(ClosingExecutionResult.scala:144) ~[neo4j-cypher-4.3.1.jar:4.3.1]
    at org.neo4j.fabric.stream.QuerySubject$BasicQuerySubject$1.doRequest(QuerySubject.java:184) ~[neo4j-fabric-4.3.1.jar:4.3.1]
    at org.neo4j.fabric.stream.QuerySubject$BasicQuerySubject$1.request(QuerySubject.java:167) ~[neo4j-fabric-4.3.1.jar:4.3.1]
    at reactor.core.publisher.FluxPeek$PeekSubscriber.request(FluxPeek.java:137) ~[reactor-core-3.4.6.jar:3.4.6]
    at reactor.core.publisher.FluxPeek$PeekSubscriber.request(FluxPeek.java:137) ~[reactor-core-3.4.6.jar:3.4.6]
    at reactor.core.publisher.FluxPeek$PeekSubscriber.request(FluxPeek.java:137) ~[reactor-core-3.4.6.jar:3.4.6]
    at reactor.core.publisher.FluxPeek$PeekSubscriber.request(FluxPeek.java:137) ~[reactor-core-3.4.6.jar:3.4.6]
    at reactor.core.publisher.FluxPeek$PeekSubscriber.request(FluxPeek.java:137) ~[reactor-core-3.4.6.jar:3.4.6]
    at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.request(Operators.java:2157) ~[reactor-core-3.4.6.jar:3.4.6]
    at reactor.core.publisher.FluxPeek$PeekSubscriber.request(FluxPeek.java:137) ~[reactor-core-3.4.6.jar:3.4.6]
    at reactor.core.publisher.StrictSubscriber.request(StrictSubscriber.java:138) ~[reactor-core-3.4.6.jar:3.4.6]
    at org.neo4j.fabric.stream.Rx2SyncStream$RecordSubscriber.request(Rx2SyncStream.java:129) ~[neo4j-fabric-4.3.1.jar:4.3.1]
    at org.neo4j.fabric.stream.Rx2SyncStream.maybeRequest(Rx2SyncStream.java:91) ~[neo4j-fabric-4.3.1.jar:4.3.1]
    at org.neo4j.fabric.stream.Rx2SyncStream.readRecord(Rx2SyncStream.java:50) ~[neo4j-fabric-4.3.1.jar:4.3.1]
    ... 25 more

In my opinion custom functions and procedures are not stable enough to use it in production. I have had a procedure working without problem and after a database restart it no longer works. This example fails for some queries and works for others...

conker84 commented 3 years ago

@rjbaucells I'm sorry to hear that but I tried to replicate your problem with your dump and Neo4j 4.2.8 and APOC 4.2.0.5 and it works. I tried with both debugQry and test2 functions.

@voutilad can you please confirm if the bug is solved in APOC 4.2.0.5?

For APOC 4.3.0.0 we need to cherry-pick the fix in it so in the next release it will be fixed as well