Inconsistent performance

[YuanchengJiang]

Neo4j version: 5.4.0
Operating system: Ubuntu 20.04
API/Driver: Cypher
Dataset: https://github.com/neo4j-graph-examples/cybersecurity

Query 1: MATCH (s3:Computer)<--(s4:HighValue)-->(s0:Computer)-->(s2:User)--()-->(s1:User)<--() RETURN s3 ORDER BY id(s3) ASC SKIP 4 LIMIT 6
Response time: ready to start consuming query after 100 ms, results consumed after another 0 ms

Query 2: OPTIONAL MATCH (s3:Computer)<--(s4:HighValue)-->(s0:Computer)-->(s2:User)--()-->(s1:User)<--() RETURN s3 ORDER BY id(s3) ASC SKIP 4 LIMIT 6
Response time: ready to start consuming query after 97 ms, results consumed after another 201287 ms

Adding OPTIONAL in Query 2 unexpectedly makes the execution more than 2000x times slower : (

Query 1 Profile:

neo4j@neo4j> PROFILE MATCH (s3:Computer)<--(s4:HighValue)-->(s0:Computer)-->(s2:User)--()-->(s1:User)<--() RETURN s3 ORDER BY id(s3) ASC SKIP 4 LIMIT 6;
+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| s3                                                                                                                                                                                                                        |
+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| (:Computer {neo4jImportId: "13", owned: FALSE, domain: "TestCompany.Local", operatingsystem: "Windows 10", name: "COMP00001.TestCompany.Local", objectid: "S-1-5-21-883232822-274137685-4173207997-1000", enabled: TRUE}) |
| (:Computer {neo4jImportId: "13", owned: FALSE, domain: "TestCompany.Local", operatingsystem: "Windows 10", name: "COMP00001.TestCompany.Local", objectid: "S-1-5-21-883232822-274137685-4173207997-1000", enabled: TRUE}) |
| (:Computer {neo4jImportId: "13", owned: FALSE, domain: "TestCompany.Local", operatingsystem: "Windows 10", name: "COMP00001.TestCompany.Local", objectid: "S-1-5-21-883232822-274137685-4173207997-1000", enabled: TRUE}) |
| (:Computer {neo4jImportId: "13", owned: FALSE, domain: "TestCompany.Local", operatingsystem: "Windows 10", name: "COMP00001.TestCompany.Local", objectid: "S-1-5-21-883232822-274137685-4173207997-1000", enabled: TRUE}) |
| (:Computer {neo4jImportId: "13", owned: FALSE, domain: "TestCompany.Local", operatingsystem: "Windows 10", name: "COMP00001.TestCompany.Local", objectid: "S-1-5-21-883232822-274137685-4173207997-1000", enabled: TRUE}) |
| (:Computer {neo4jImportId: "13", owned: FALSE, domain: "TestCompany.Local", operatingsystem: "Windows 10", name: "COMP00001.TestCompany.Local", objectid: "S-1-5-21-883232822-274137685-4173207997-1000", enabled: TRUE}) |
+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

+-------------------------------------------------------------------------------------------------+
| Plan      | Statement   | Version | Planner | Runtime   | Time | DbHits | Rows | Memory (Bytes) |
+-------------------------------------------------------------------------------------------------+
| "PROFILE" | "READ_ONLY" | ""      | "COST"  | "SLOTTED" | 100  | 140    | 6    | 64             |
+-------------------------------------------------------------------------------------------------+


Planner COST

Runtime SLOTTED

Runtime version 5.4

+------------------+----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+------------+
| Operator         | Id | Details                                                                                              | Estimated Rows | Rows | DB Hits | Page Cache Hits/Misses | Ordered by |
+------------------+----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+------------+
| +ProduceResults  |  0 | s3                                                                                                   |              6 |    6 |      48 |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+            |
| +Skip            |  1 | 4                                                                                                    |              6 |    6 |       0 |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+            |
| +Limit           |  2 | 6 + 4                                                                                                |             10 |   10 |       0 |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+            |
| +Filter          |  3 | not anon_6 = anon_1 AND not anon_6 = anon_3 AND not anon_6 = anon_2 AND not anon_6 = anon_0 AND not  |             10 |   10 |       0 |                    0/0 |            |
| |                |    | anon_6 = anon_5                                                                                      |                |      |         |                        |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+            |
| +Expand(All)     |  4 | (s1)<-[anon_6]-(anon_7)                                                                              |             11 |   17 |      43 |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+            |
| +Filter          |  5 | s1:User AND not anon_5 = anon_3 AND not anon_5 = anon_0 AND not anon_5 = anon_1 AND not anon_5 = ano |              4 |    7 |       7 |                    0/0 |            |
| |                |    | n_2                                                                                                  |                |      |         |                        |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+            |
| +Expand(All)     |  6 | (anon_4)-[anon_5]->(s1)                                                                              |             21 |    7 |      14 |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+            |
| +Filter          |  7 | not anon_3 = anon_2 AND not anon_3 = anon_1 AND not anon_3 = anon_0                                  |              4 |    1 |       0 |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+            |
| +Expand(All)     |  8 | (s2)-[anon_3]-(anon_4)                                                                               |              4 |    1 |       3 |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+            |
| +Filter          |  9 | not anon_2 = anon_1 AND not anon_2 = anon_0 AND s2:User                                              |              1 |    1 |       1 |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+            |
| +Expand(All)     | 10 | (s0)-[anon_2]->(s2)                                                                                  |              1 |    1 |      10 |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+            |
| +Filter          | 11 | not anon_1 = anon_0 AND s0:Computer                                                                  |              0 |    1 |       1 |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+            |
| +Expand(All)     | 12 | (s4)-[anon_1]->(s0)                                                                                  |              0 |    1 |       4 |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+            |
| +Filter          | 13 | s4:HighValue                                                                                         |              0 |    1 |       2 |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+            |
| +Expand(All)     | 14 | (s3)<-[anon_0]-(s4)                                                                                  |              0 |    2 |       5 |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+            |
| +NodeByLabelScan | 15 | s3:Computer                                                                                          |              0 |    1 |       2 |                    0/0 | s3 ASC     |
+------------------+----+------------------------------------------------------------------------------------------------------+----------------+------+---------+------------------------+------------+

Total database accesses: 140, total allocated memory: 64

6 rows
ready to start consuming query after 100 ms, results consumed after another 0 ms

Query 2 Profile:

neo4j@neo4j> PROFILE OPTIONAL MATCH (s3:Computer)<--(s4:HighValue)-->(s0:Computer)-->(s2:User)--()-->(s1:User)<--() RETURN s3 ORDER BY id(s3) ASC SKIP 4 LIMIT 6;
+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| s3                                                                                                                                                                                                                        |
+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| (:Computer {neo4jImportId: "13", owned: FALSE, domain: "TestCompany.Local", operatingsystem: "Windows 10", name: "COMP00001.TestCompany.Local", objectid: "S-1-5-21-883232822-274137685-4173207997-1000", enabled: TRUE}) |
| (:Computer {neo4jImportId: "13", owned: FALSE, domain: "TestCompany.Local", operatingsystem: "Windows 10", name: "COMP00001.TestCompany.Local", objectid: "S-1-5-21-883232822-274137685-4173207997-1000", enabled: TRUE}) |
| (:Computer {neo4jImportId: "13", owned: FALSE, domain: "TestCompany.Local", operatingsystem: "Windows 10", name: "COMP00001.TestCompany.Local", objectid: "S-1-5-21-883232822-274137685-4173207997-1000", enabled: TRUE}) |
| (:Computer {neo4jImportId: "13", owned: FALSE, domain: "TestCompany.Local", operatingsystem: "Windows 10", name: "COMP00001.TestCompany.Local", objectid: "S-1-5-21-883232822-274137685-4173207997-1000", enabled: TRUE}) |
| (:Computer {neo4jImportId: "13", owned: FALSE, domain: "TestCompany.Local", operatingsystem: "Windows 10", name: "COMP00001.TestCompany.Local", objectid: "S-1-5-21-883232822-274137685-4173207997-1000", enabled: TRUE}) |
| (:Computer {neo4jImportId: "13", owned: FALSE, domain: "TestCompany.Local", operatingsystem: "Windows 10", name: "COMP00001.TestCompany.Local", objectid: "S-1-5-21-883232822-274137685-4173207997-1000", enabled: TRUE}) |
+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+

+-------------------------------------------------------------------------------------------------------+
| Plan      | Statement   | Version | Planner | Runtime   | Time   | DbHits     | Rows | Memory (Bytes) |
+-------------------------------------------------------------------------------------------------------+
| "PROFILE" | "READ_ONLY" | ""      | "COST"  | "SLOTTED" | 201384 | 1301703116 | 6    | 1936           |
+-------------------------------------------------------------------------------------------------------+


Planner COST

Runtime SLOTTED

Runtime version 5.4

+------------------+----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+------------+
| Operator         | Id | Details                                                                                              | Estimated Rows | Rows      | DB Hits   | Memory (Bytes) | Page Cache Hits/Misses | Ordered by |
+------------------+----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+------------+
| +ProduceResults  |  0 | s3                                                                                                   |              6 |         6 |        48 |                |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+            |
| +Skip            |  1 | 4                                                                                                    |              6 |         6 |         0 |                |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+            |
| +Top             |  2 | s3 ASC LIMIT 6 + 4                                                                                   |             10 |        10 |         0 |           1872 |                    0/0 | s3 ASC     |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+------------+
| +Optional        |  3 |                                                                                                      |        4320275 | 209102400 |         0 |                |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+------------+
| +Filter          |  4 | not anon_6 = anon_1 AND not anon_6 = anon_3 AND not anon_6 = anon_2 AND not anon_6 = anon_0 AND not  |        4320275 | 209102400 |         0 |                |                    0/0 |            |
| |                |    | anon_6 = anon_5                                                                                      |                |           |           |                |                        |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+------------+
| +Expand(All)     |  5 | (s1)<-[anon_6]-(anon_7)                                                                              |        4542924 | 320176800 | 850586400 |                |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+------------+
| +Filter          |  6 | not anon_2 = anon_0 AND not anon_5 = anon_0 AND not anon_1 = anon_0 AND not anon_3 = anon_0 AND s3:C |        1575581 | 111051600 | 222701486 |                |                    0/0 |            |
| |                |    | omputer                                                                                              |                |           |           |                |                        |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+------------+
| +Expand(All)     |  7 | (s4)-[anon_0]->(s3)                                                                                  |        1640211 | 223213716 | 224879490 |                |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+------------+
| +Filter          |  8 | s4:HighValue AND not anon_5 = anon_1 AND not anon_3 = anon_1 AND not anon_2 = anon_1                 |          13249 |    185086 |    657310 |                |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+------------+
| +Expand(All)     |  9 | (s0)<-[anon_1]-(s4)                                                                                  |          23140 |    657310 |   1008243 |                |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+------------+
| +Filter          | 10 | s0:Computer AND not anon_5 = anon_2 AND not anon_3 = anon_2                                          |           3320 |     92543 |    299790 |                |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+------------+
| +Expand(All)     | 11 | (s2)<-[anon_2]-(s0)                                                                                  |           5177 |    299790 |    806709 |                |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+------------+
| +Filter          | 12 | s2:User AND not anon_5 = anon_3                                                                      |           1795 |    103201 |    378888 |                |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+------------+
| +Expand(All)     | 13 | (anon_4)-[anon_3]-(s2)                                                                               |           8528 |    378888 |    382153 |                |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+------------+
| +Expand(All)     | 14 | (s1)<-[anon_5]-(anon_4)                                                                              |            865 |       865 |      2298 |                |                    0/0 |            |
| |                +----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+------------+
| +NodeByLabelScan | 15 | s1:User                                                                                              |            300 |       300 |       301 |                |                    0/0 |            |
+------------------+----+------------------------------------------------------------------------------------------------------+----------------+-----------+-----------+----------------+------------------------+------------+

Total database accesses: 1301703116, total allocated memory: 1936

6 rows
ready to start consuming query after 97 ms, results consumed after another 201287 ms

[HannesSandberg]

Thank you! We will look into this.

[hedengran]

Hello @YuanchengJiang, thank you again for reporting this! I've investigated the issue and concluded that he reason why we pick a worse plan in the OPTIONAL MATCH case is because of an incorrect assumption encoded in the planner regarding ORDER BY combined with OPTIONAL MATCH. I've addressed the issue in a PR and the fix should be present in the next release of Neo4j 5.