Performance problems with apoc.path.expand and apoc.run.cypher

[magaton]

Hello, I have raised this problem on discord, hopefully, it will get some more attention here.

My model:

Period (id, year, startDate, endDate, type)
Indices are on all fields. startDate and endDate are of type Date

Client(login, type)
Indices are on all fields

(Client)-[:HAS_SPONSOR]->(Client)

Commissionable (effectiveDate, value, type)
Indices are on effectiveDate (of type Date) and type

I need to calculate and create Commission|Earning (id, type, value) nodes and connect them with Period and Client:
(Client)-[:EARNED]->(Commission)-[:EARNING_FOR_PERIOD]->(Period)

The simplest query, that works reasonably well:

github.com

magaton/slashco-mlm/blob/master/variable-length-rel.cypher

MATCH (currentWeek: Period) 
WHERE currentWeek.type="Week" AND currentWeek.year IN [2020,2021]
WITH currentWeek
MATCH (amb:Client{type:"Ambassador"})
WITH currentWeek, amb
MATCH(amb)<-[hs:HAS_SPONSOR*0..2]-(per)
WITH currentWeek, amb, per, SIZE(hs) AS level   
OPTIONAL MATCH (per)-[:MADE]->(comm:Commissionable) WHERE comm.effectiveDate >= currentWeek.startDate AND comm.effectiveDate < currentWeek.endDate
WITH currentWeek, amb, per, comm, level, per.type AS type, CASE WHEN comm.type="Return" THEN 0.0 ELSE comm.value END AS commCV
WITH currentWeek, amb, level, type, CASE WHEN level < 2 THEN 0.25 WHEN level = 2 THEN 0.10 ELSE 0 END as multiplier, COALESCE(round(sum(commCV),2), 0.0) as cv
WITH currentWeek, amb, level, type, multiplier, cv, round(multiplier*cv,2) AS commissionContribution, ('C' + level + SUBSTRING(type, 0, 1)) AS commissionType
MERGE (amb)-[:EARNED]->(perLevelAndTypeComm:Earning:Commission{id:(currentWeek.id + commissionType + amb.id )})-[:EARNING_FOR_PERIOD]->(currentWeek)
ON CREATE SET perLevelAndTypeComm.type=commissionType, perLevelAndTypeComm.value=commissionContribution;

Profile is slashco-mlm/profile-var-length-rel.txt at master · magaton/slashco-mlm · GitHub

I have 67 ambassadors only (it will be millions of them ) and it takes 9s.
I am also trying to find a way how to make it faster.

Now, since the hierarchy can be configurable (as mentioned before) and can be, e,g. 3 or 4, instead of 2, I would like to use apoc.path.expand, since variable-length relationship cannot be paralelised.

github.com

magaton/slashco-mlm/blob/master/apoc-path-expand.cypher

MATCH (currentWeek: Period) 
WHERE currentWeek.type="Week" AND currentWeek.year IN [2020,2021]
WITH currentWeek
MATCH (amb:Client{type:"Ambassador"})
WITH currentWeek, amb
CALL apoc.path.expand(amb, '<HAS_SPONSOR', null, 0, 2)
YIELD path
WITH currentWeek, amb, last(nodes(path)) AS per, length(path) AS level
OPTIONAL MATCH (per)-[:MADE]->(comm:Commissionable) WHERE comm.effectiveDate >= currentWeek.startDate AND comm.effectiveDate < currentWeek.endDate
WITH currentWeek, amb, per, comm, level, per.type AS type, CASE WHEN comm.type="Return" THEN 0.0 ELSE comm.value END AS commCV
WITH currentWeek, amb, level, type, CASE WHEN level < 2 THEN 0.25 WHEN level = 2 THEN 0.10 ELSE 0 END as multiplier, COALESCE(round(sum(commCV),2), 0.0) as cv
WITH currentWeek, amb, level, type, multiplier, cv, round(multiplier*cv,2) AS commissionContribution, ('C' + level + SUBSTRING(type, 0, 1)) AS commissionType
MERGE (amb)-[:EARNED]->(perLevelAndTypeComm:Earning:Commission{id:(currentWeek.id + commissionType + amb.id )})-[:EARNING_FOR_PERIOD]->(currentWeek)
ON CREATE SET perLevelAndTypeComm.type=commissionType, perLevelAndTypeComm.value=commissionContribution;

This one takes 14 min!?
Profile is here:

github.com

magaton/slashco-mlm/blob/master/profile-apoc-path-expander.txt

+-----------------------------------------------------------------------------------------------------------------+
| Plan      | Statement    | Version      | Planner | Runtime       | Time   | DbHits     | Rows | Memory (Bytes) |
+-----------------------------------------------------------------------------------------------------------------+
| "PROFILE" | "WRITE_ONLY" | "CYPHER 4.2" | "COST"  | "INTERPRETED" | 889259 | 1062531212 | 0    | 66545168       |
+-----------------------------------------------------------------------------------------------------------------+


+-------------------------------------------+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+
| Operator                                  | Details                                                                                              | Estimated Rows | Rows      | DB Hits   | Memory (Bytes) | Page Cache Hits/Misses |
+-------------------------------------------+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+
| +ProduceResults@neo4j                     |                                                                                                      |            284 |         0 |         0 |                |                    0/0 |
| |                                         +------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+
| +EmptyResult@neo4j                        |                                                                                                      |            284 |         0 |         0 |                |                    0/0 |
| |                                         +------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+
| +Apply@neo4j                              |                                                                                                      |            284 |     15052 |         0 |                |                    0/0 |
| |\                                        +------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+
| | +AntiConditionalApply@neo4j             |                                                                                                      |            284 |     15052 |         0 |                |                    0/0 |
| | |\                                      +------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+
| | | +SetProperty@neo4j                    | perLevelAndTypeComm.value = commissionContribution                                                   |            284 |     15052 |     15052 |                |                    0/0 |
| | | |                                     +------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+

This file has been truncated. show original

I profiled neo4j process with visualVM and although my heap sizes are 1g min and 4g max, the memory is never above 750mb. CPU stays reasonably low. My env: OSX 11.2.3, JDK 11, neo4j community 4.2.4, single instance, apoc-4.2.0.2

What could be the problem, why apoc-path-expand is so much slower than variable-length relationship query.

And finally, since in queries I have fragments that should come from the configuration. I have tried to isolate them in cypher queries and call them with apoc.cypher.run

query:

github.com

magaton/slashco-mlm/blob/master/variable-length-rel-with-cypher-run.cypher

 MATCH (currentWeek: Period) 
 WHERE currentWeek.type="Week" AND currentWeek.year IN [2020,2021]
 WITH currentWeek
 MATCH (amb:Client{type:"Ambassador"})
 WITH currentWeek, amb
 //CALL apoc.path.expand(amb, '<HAS_SPONSOR', '+Client', 0, 2)
 //YIELD path
 //WITH currentWeek, amb, last(nodes(path)) AS per, length(path) AS level
 MATCH(amb)<-[hs:HAS_SPONSOR*0..2]-(per)
 WITH currentWeek, amb, per, SIZE(hs) AS level
 OPTIONAL MATCH (comm:Commissionable)<-[:MADE]-(per) WHERE comm.effectiveDate >= currentWeek.startDate AND comm.effectiveDate <= currentWeek.endDate
 WITH currentWeek, amb, per, comm, level, per.type AS type 
 CALL apoc.cypher.run("WITH comm, CASE WHEN comm.type='Return' THEN 0.0 ELSE comm.value END AS commCV RETURN commCV", {comm:comm}) YIELD value
 WITH currentWeek, amb, per, comm, level, type, value.commCV AS commCV
 CALL apoc.cypher.run("WITH amb, commCV, level, type, 
                      CASE WHEN level < 2 THEN 0.25 WHEN level = 2 THEN 0.10 ELSE 0 END as multiplier, 
                      COALESCE(round(sum(commCV),2), 0.0) as cv
                      WITH amb, level, type, multiplier, cv, round(multiplier*cv,2) AS commissionContribution, 
                      ('C' + level + SUBSTRING(type, 0, 1)) AS commissionType RETURN commissionContribution, commissionType", 
                      {amb:amb, commCV:commCV, level:level, type:type}) YIELD value

This file has been truncated. show original

profile:

github.com

magaton/slashco-mlm/blob/master/profile-var-length-rel-with-cypher-run.txt

+--------------------------------------------------------------------------------------------------------------+
| Plan      | Statement    | Version      | Planner | Runtime       | Time  | DbHits   | Rows | Memory (Bytes) |
+--------------------------------------------------------------------------------------------------------------+
| "PROFILE" | "WRITE_ONLY" | "CYPHER 4.2" | "COST"  | "INTERPRETED" | 14253 | 19612130 | 0    | 53857464       |
+--------------------------------------------------------------------------------------------------------------+


+-------------------------------------------+------------------------------------------------------------------------------------------------------+----------------+-------+----------+----------------+------------------------+
| Operator                                  | Details                                                                                              | Estimated Rows | Rows  | DB Hits  | Memory (Bytes) | Page Cache Hits/Misses |
+-------------------------------------------+------------------------------------------------------------------------------------------------------+----------------+-------+----------+----------------+------------------------+
| +ProduceResults@neo4j                     |                                                                                                      |         801959 |     0 |        0 |                |                    0/0 |
| |                                         +------------------------------------------------------------------------------------------------------+----------------+-------+----------+----------------+------------------------+
| +EmptyResult@neo4j                        |                                                                                                      |         801959 |     0 |        0 |                |                    0/0 |
| |                                         +------------------------------------------------------------------------------------------------------+----------------+-------+----------+----------------+------------------------+
| +Apply@neo4j                              |                                                                                                      |         801959 | 64341 |        0 |                |                    0/0 |
| |\                                        +------------------------------------------------------------------------------------------------------+----------------+-------+----------+----------------+------------------------+
| | +AntiConditionalApply@neo4j             |                                                                                                      |         801959 | 64341 |        0 |                |                    0/0 |
| | |\                                      +------------------------------------------------------------------------------------------------------+----------------+-------+----------+----------------+------------------------+
| | | +SetProperty@neo4j                    | perLevelAndTypeComm.value = commissionContribution                                                   |         801959 | 15052 |    15052 |                |                    0/0 |
| | | |                                     +------------------------------------------------------------------------------------------------------+----------------+-------+----------+----------------+------------------------+

This file has been truncated. show original

This takes 14s, much longer than 1st query without apoc.cypher.run.
What could be the reason?

Thanks in advance,
Milan

[andrew_bowman]

Hello,

I'll need to take a closer look later, but this isn't directly due to the APOC procs, but of how the planner is planning the rest of the query.

Remember that most Cypher operations execute per row, so the more rows there are, the more work is needed.

In your first query plan, rows hit a max of 90128 rows and the mode is around 15k rows. DB hits spike at 18552115 db hits on the optional expansion.

In the apoc.cypher.run query plan, rows also spike early at 90128 rows, and the mode is at about 64k rows, with a db hit spike of 18560302 which is about the same as the last query.

The path expander plan is the worst, with a spike of 528401520 rows and two consecutive db hit spikes of around 528427384. This is due to a label scan and a hash join midway through the query.

I'll look at this in more depth later on, but understand, these rows and spikes are not directly because of the APOC calls, but around how the query was planned around them. There may be ways to optimize to deal with some of the bad planner decisions here.

[magaton]

Am I right to say that one should not use apoc procedures without tweaking execution plan if the performance is of concern?

If so, hope that this does not apply to function, meaning those should not influence planner to make bad decisions?

[andrew_bowman]

It's not a guaranteed thing, since it depends entirely on the rest of the query. It's always a good idea to recheck your plan if there are drastic changes to a query (APOC or not) and if testing reveals major timing differences.

I'll try to take a closer look later and see where we can tune this one.