CapnSpek commented on issue #982: URL: https://github.com/apache/age/issues/982#issuecomment-1753385328
Tested for around 100000 vertices and 50000 edges the following queries. Starting notes: Query 11 seems to be great importance and taking more than 1 hour to execute in both the cases. Query 3, 4, 5 have considerably different execution times over the 2 versions. Rest of the queries seem to have mostly identical performances. The label_redesign version is based off Zainab's performance test branch https://github.com/Zainab-Saad/age/tree/performance_test - **Vertex matching:** 1. `SELECT * FROM cypher('xyz', $$ EXPLAIN ANALYZE VERBOSE MATCH (n) RETURN n $$) AS (x agtype);` Old version: Longest time (First execution) - Planning time: 5.919 ms, Execution time: 137.001 ms Mean of next 5 runs - Planning time: 0.237 ms Execution time: 109.460 ms New version: Longest time (Fifth execution) - Planning time: 0.223 ms, Execution time: 114.187 ms Mean of 5 runs- Planning time: 0.219 ms, Execution time: 111.822 ms 2. `SELECT * FROM cypher('xyz', $$ EXPLAIN ANALYZE VERBOSE MATCH (n:Person) RETURN n $$) AS (x agtype);` Old version: Longest time (Second execution) - Planning time: 0.138 ms, Execution time: 103.667 ms Mean of 5 runs - Planning time: 0.118 ms, Execution time: 103.015 ms New version: Longest time (Fourth execution) - Planning time: 0.124 ms, Execution time: 101.266 ms Mean time - Planning time: 0.119 ms, Execution time: 107.646 ms 3. `SELECT * FROM cypher('xyz', $$ EXPLAIN ANALYZE VERBOSE MATCH (n {age: 21}) RETURN n $$) AS (x agtype);` Old version: Longest time (Second execution) - Planning time: 0.339 ms, Execution time: 36.357 ms Mean of 5 runs - Planning time: 0.296 ms, Execution time: 32.867 ms New version: Longest time (First execution) - Planning time: 0.293 ms, Execution time: 110.729 ms Mean of 5 runs - Planning time: 0.289 ms, Execution time: 86.194 ms 4. `SELECT * FROM cypher('xyz', $$ EXPLAIN ANALYZE VERBOSE MATCH (n:Person {age:23}) RETURN n $$) AS (x agtype);` Old version: Longest time (First execution) - Planning time: 0.199 ms, Execution time: 32.599 ms Mean of 5 runs - Planning time: 0.166 ms, Execution time: 31.928 ms New version: Longest time (Fifth execution) - Planning time: 0.145 ms, Execution time: 113.811 ms Mean of 5 runs - Planning time: 0.144 ms, Execution time: 86.045 ms - **Vertex and edge matching:** These queries have been executed only once since they take a very long time to complete. The QPTs have been included as there are noticeable differences in them. 5. `SELECT * FROM cypher('xyz', $$ EXPLAIN ANALYZE VERBOSE MATCH ()-[e]-() RETURN e $$) AS (x agtype);` Old version: ``` QUERY PLAN ------------------------------------------------------------------------------------------------------------------------------------------------------------------- Gather (cost=1000.00..82850088.66 rows=49817144 width=32) (actual time=1.823..262214.764 rows=100000 loops=1) Output: (_agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37051'::oid, e.id), e.properties)) Workers Planned: 2 Workers Launched: 2 -> Nested Loop (cost=0.00..77867374.26 rows=20757143 width=32) (actual time=0.386..261880.557 rows=33333 loops=3) Output: _agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37051'::oid, e.id), e.properties) Join Filter: ((e.end_id = _age_default_alias_0.id) OR (e.start_id = _age_default_alias_0.id)) Rows Removed by Join Filter: 1666650000 Worker 0: actual time=0.239..262199.736 rows=33703 loops=1 Worker 1: actual time=0.236..261827.906 rows=33561 loops=1 -> Parallel Append (cost=0.00..1933.58 rows=41668 width=8) (actual time=0.008..11.155 rows=33334 loops=3) Worker 0: actual time=0.006..11.550 rows=33704 loops=1 Worker 1: actual time=0.006..11.450 rows=33561 loops=1 -> Parallel Seq Scan on xyz."Person" _age_default_alias_0_2 (cost=0.00..1725.24 rows=58824 width=8) (actual time=0.007..8.176 rows=33334 loops=3) Output: _age_default_alias_0_2.id Worker 0: actual time=0.006..8.379 rows=33704 loops=1 Worker 1: actual time=0.006..8.491 rows=33561 loops=1 -> Parallel Seq Scan on xyz._ag_label_vertex _age_default_alias_0_1 (cost=0.00..0.00 rows=1 width=8) (actual time=0.002..0.002 rows=0 loops=1) Output: _age_default_alias_0_1.id -> Append (cost=0.00..1117.11 rows=49941 width=29) (actual time=0.001..4.719 rows=50000 loops=100001) Worker 0: actual time=0.001..4.670 rows=50000 loops=33704 Worker 1: actual time=0.001..4.682 rows=50000 loops=33561 -> Seq Scan on xyz._ag_label_edge e_1 (cost=0.00..0.00 rows=1 width=56) (actual time=0.000..0.000 rows=0 loops=100001) Output: e_1.id, e_1.start_id, e_1.end_id, e_1.properties Worker 0: actual time=0.000..0.000 rows=0 loops=33704 Worker 1: actual time=0.000..0.000 rows=0 loops=33561 -> Seq Scan on xyz."Knows" e_2 (cost=0.00..867.40 rows=49940 width=29) (actual time=0.001..2.546 rows=50000 loops=100001) Output: e_2.id, e_2.start_id, e_2.end_id, e_2.properties Worker 0: actual time=0.001..2.507 rows=50000 loops=33704 Worker 1: actual time=0.001..2.513 rows=50000 loops=33561 Planning Time: 4.255 ms Execution Time: 262220.020 ms (32 rows) ``` Planning time: 4.255 ms, Execution time: 262220.020 ms (4 mins 22 seconds) New version: ``` QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------------------------------ Nested Loop (cost=0.00..88089069.31 rows=49923878 width=32) (actual time=0.061..622593.464 rows=100000 loops=1) Output: _agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37658'::oid, e.label_id), _label_name('37658'::oid, e.start_label_id), _label_name('37658'::oid, e.end_label_id), e.start_label_id, e.end_label_id, e.properties) Join Filter: ((e.end_id = _age_default_alias_0.id) OR (e.start_id = _age_default_alias_0.id)) Rows Removed by Join Filter: 4999950000 -> Append (cost=0.00..2735.02 rows=100002 width=8) (actual time=0.012..36.013 rows=100001 loops=1) -> Seq Scan on xyz._ag_label_vertex _age_default_alias_0_1 (cost=0.00..0.00 rows=1 width=8) (actual time=0.004..0.005 rows=0 loops=1) Output: _age_default_alias_0_1.id -> Seq Scan on xyz."Person" _age_default_alias_0_2 (cost=0.00..2235.01 rows=100001 width=8) (actual time=0.006..25.512 rows=100001 loops=1) Output: _age_default_alias_0_2.id -> Materialize (cost=0.00..1468.95 rows=50048 width=41) (actual time=0.001..3.356 rows=50000 loops=100001) Output: e.id, e.start_id, e.end_id, e.label_id, e.start_label_id, e.end_label_id, e.properties -> Append (cost=0.00..1218.71 rows=50048 width=41) (actual time=0.008..15.429 rows=50000 loops=1) -> Seq Scan on xyz._ag_label_edge e_1 (cost=0.00..0.00 rows=1 width=68) (actual time=0.002..0.002 rows=0 loops=1) Output: e_1.id, e_1.start_id, e_1.end_id, e_1.label_id, e_1.start_label_id, e_1.end_label_id, e_1.properties -> Seq Scan on xyz."Knows" e_2 (cost=0.00..968.47 rows=50047 width=41) (actual time=0.006..11.553 rows=50000 loops=1) Output: e_2.id, e_2.start_id, e_2.end_id, e_2.label_id, e_2.start_label_id, e_2.end_label_id, e_2.properties Planning Time: 0.569 ms Execution Time: 622598.595 ms (18 rows) ``` Planning time: 0.569 ms, Execution time: 622598.595 ms (10 mins 22 seconds) 6. `SELECT * FROM cypher('xyz', $$ EXPLAIN ANALYZE VERBOSE MATCH ()-[e:Knows]-() RETURN e $$) AS (x agtype);` Old version: ``` QUERY PLAN ------------------------------------------------------------------------------------------------------------------------------------------------------------------- Gather (cost=1000.00..67379672.45 rows=200002 width=32) (actual time=0.613..191252.134 rows=100000 loops=1) Output: (_agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37051'::oid, e.id), e.properties)) Workers Planned: 2 Workers Launched: 2 -> Nested Loop (cost=0.00..67358672.25 rows=83334 width=32) (actual time=0.161..191155.507 rows=33333 loops=3) Output: _agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37051'::oid, e.id), e.properties) Join Filter: ((e.end_id = _age_default_alias_0.id) OR (e.start_id = _age_default_alias_0.id)) Rows Removed by Join Filter: 1666650000 Worker 0: actual time=0.218..191241.816 rows=33351 loops=1 Worker 1: actual time=0.219..191109.443 rows=33352 loops=1 -> Parallel Append (cost=0.00..1933.58 rows=41668 width=8) (actual time=0.007..10.099 rows=33334 loops=3) Worker 0: actual time=0.005..10.356 rows=33352 loops=1 Worker 1: actual time=0.005..10.606 rows=33352 loops=1 -> Parallel Seq Scan on xyz."Person" _age_default_alias_0_2 (cost=0.00..1725.24 rows=58824 width=8) (actual time=0.006..6.541 rows=33334 loops=3) Output: _age_default_alias_0_2.id Worker 0: actual time=0.005..6.831 rows=33352 loops=1 Worker 1: actual time=0.005..6.986 rows=33352 loops=1 -> Parallel Seq Scan on xyz._ag_label_vertex _age_default_alias_0_1 (cost=0.00..0.00 rows=1 width=8) (actual time=0.002..0.002 rows=0 loops=1) Output: _age_default_alias_0_1.id -> Seq Scan on xyz."Knows" e (cost=0.00..867.40 rows=49940 width=29) (actual time=0.001..2.526 rows=50000 loops=100001) Output: e.id, e.start_id, e.end_id, e.properties Worker 0: actual time=0.001..2.524 rows=50000 loops=33352 Worker 1: actual time=0.001..2.522 rows=50000 loops=33352 Planning Time: 0.330 ms Execution Time: 191255.881 ms (25 rows) ``` Planning time: 0.330 ms, Execution time: 191225.881 ms (3 mins 11 seconds) New version: ``` QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------------------------------------ Gather (cost=1000.00..71658449.02 rows=200002 width=32) (actual time=1.095..194880.646 rows=100000 loops=1) Output: (_agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37658'::oid, e.label_id), _label_name('37658'::oid, e.start_label_id), _label_name('37658'::oid, e.end_label_id), e.start_label_id, e.end_label_id, e.properties)) Workers Planned: 2 Workers Launched: 2 -> Nested Loop (cost=0.00..71637448.82 rows=83334 width=32) (actual time=0.206..194771.089 rows=33333 loops=3) Output: _agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37658'::oid, e.label_id), _label_name('37658'::oid, e.start_label_id), _label_name('37658'::oid, e.end_label_id), e.start_labe l_id, e.end_label_id, e.properties) Join Filter: ((e.end_id = _age_default_alias_0.id) OR (e.start_id = _age_default_alias_0.id)) Rows Removed by Join Filter: 1666650000 Worker 0: actual time=0.259..194862.345 rows=33777 loops=1 Worker 1: actual time=0.264..194702.696 rows=33615 loops=1 -> Parallel Append (cost=0.00..2031.58 rows=41668 width=8) (actual time=0.011..17.917 rows=33334 loops=3) Worker 0: actual time=0.006..18.060 rows=33777 loops=1 Worker 1: actual time=0.008..18.263 rows=33615 loops=1 -> Parallel Seq Scan on xyz."Person" _age_default_alias_0_2 (cost=0.00..1823.24 rows=58824 width=8) (actual time=0.009..11.239 rows=33334 loops=3) Output: _age_default_alias_0_2.id Worker 0: actual time=0.006..11.926 rows=33777 loops=1 Worker 1: actual time=0.007..11.502 rows=33615 loops=1 -> Parallel Seq Scan on xyz._ag_label_vertex _age_default_alias_0_1 (cost=0.00..0.00 rows=1 width=8) (actual time=0.003..0.003 rows=0 loops=1) Output: _age_default_alias_0_1.id -> Seq Scan on xyz."Knows" e (cost=0.00..968.47 rows=50047 width=41) (actual time=0.001..2.591 rows=50000 loops=100001) Output: e.id, e.start_id, e.end_id, e.properties, e.label_id, e.start_label_id, e.end_label_id Worker 0: actual time=0.001..2.568 rows=50000 loops=33777 Worker 1: actual time=0.001..2.573 rows=50000 loops=33615 Planning Time: 0.443 ms Execution Time: 194887.249 ms (25 rows) ``` Planning time: 0.443 ms, Execution time: 191255.881 ms (3 minutes 14 seconds) 7. `SELECT * FROM cypher('xyz', $$ EXPLAIN ANALYZE VERBOSE MATCH (:Person)-[e]-() RETURN e $$) AS (x agtype);` Old version: ``` QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ---- Gather (cost=1000.00..1101138.00 rows=250127 width=32) (actual time=0.817..284577.697 rows=100000 loops=1) Output: (_agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37051'::oid, e.id), e.properties)) Workers Planned: 2 Workers Launched: 2 -> Nested Loop (cost=0.00..1075125.30 rows=104220 width=32) (actual time=0.185..283628.982 rows=33333 loops=3) Output: _agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37051'::oid, e.id), e.properties) Join Filter: (((e.end_id = _age_default_alias_0.id) AND ((_extract_label_id(e.start_id))::integer = 3)) OR ((e.start_id = _age_default_alias_0.id) AND ((_extract_label_id(e.end_id))::integer = 3 ))) Rows Removed by Join Filter: 1666650000 Worker 0: actual time=0.247..282474.827 rows=33184 loops=1 Worker 1: actual time=0.251..283848.649 rows=33360 loops=1 -> Parallel Append (cost=0.00..956.57 rows=209 width=29) (actual time=0.010..14.147 rows=16667 loops=3) Worker 0: actual time=0.007..15.586 rows=16592 loops=1 Worker 1: actual time=0.006..13.005 rows=16680 loops=1 -> Parallel Seq Scan on xyz."Knows" e_2 (cost=0.00..955.53 rows=293 width=29) (actual time=0.008..10.167 rows=16667 loops=3) Output: e_2.id, e_2.start_id, e_2.end_id, e_2.properties Filter: (((_extract_label_id(e_2.start_id))::integer = 3) OR ((_extract_label_id(e_2.end_id))::integer = 3)) Worker 0: actual time=0.007..11.734 rows=16592 loops=1 Worker 1: actual time=0.005..9.291 rows=16680 loops=1 -> Parallel Seq Scan on xyz._ag_label_edge e_1 (cost=0.00..0.00 rows=1 width=56) (actual time=0.002..0.002 rows=0 loops=1) Output: e_1.id, e_1.start_id, e_1.end_id, e_1.properties Filter: (((_extract_label_id(e_1.start_id))::integer = 3) OR ((_extract_label_id(e_1.end_id))::integer = 3)) -> Append (cost=0.00..2637.02 rows=100002 width=8) (actual time=0.001..12.011 rows=100001 loops=50000) Worker 0: actual time=0.001..12.014 rows=100001 loops=16592 Worker 1: actual time=0.001..12.003 rows=100001 loops=16680 -> Seq Scan on xyz._ag_label_vertex _age_default_alias_0_1 (cost=0.00..0.00 rows=1 width=8) (actual time=0.000..0.000 rows=0 loops=50000) Output: _age_default_alias_0_1.id Worker 0: actual time=0.000..0.000 rows=0 loops=16592 Worker 1: actual time=0.000..0.000 rows=0 loops=16680 -> Seq Scan on xyz."Person" _age_default_alias_0_2 (cost=0.00..2137.01 rows=100001 width=8) (actual time=0.001..7.687 rows=100001 loops=50000) Output: _age_default_alias_0_2.id Worker 0: actual time=0.001..7.689 rows=100001 loops=16592 Worker 1: actual time=0.001..7.677 rows=100001 loops=16680 Planning Time: 0.551 ms Execution Time: 284582.137 ms (34 rows) ``` Planning time: 0.551 ms, Execution time: 284582.137 ms (4 mins 44 seconds) New version: ``` QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------------------------------------ Gather (cost=1000.00..101360174.37 rows=25086905 width=32) (actual time=0.861..291863.787 rows=100000 loops=1) Output: (_agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37658'::oid, e.label_id), _label_name('37658'::oid, e.start_label_id), _label_name('37658'::oid, e.end_label_id), e.start_label_id, e.end_label_id, e.properties)) Workers Planned: 2 Workers Launched: 2 -> Nested Loop (cost=0.00..98850483.87 rows=10452877 width=32) (actual time=0.593..291494.956 rows=33333 loops=3) Output: _agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37658'::oid, e.label_id), _label_name('37658'::oid, e.start_label_id), _label_name('37658'::oid, e.end_label_id), e.start_labe l_id, e.end_label_id, e.properties) Join Filter: (((e.end_id = _age_default_alias_0.id) AND (e.start_label_id = 3)) OR ((e.start_id = _age_default_alias_0.id) AND (e.end_label_id = 3))) Rows Removed by Join Filter: 1666650000 Worker 0: actual time=1.342..291846.439 rows=32528 loops=1 Worker 1: actual time=0.331..291093.356 rows=32376 loops=1 -> Parallel Append (cost=0.00..1013.86 rows=20854 width=41) (actual time=0.016..18.049 rows=16667 loops=3) Worker 0: actual time=0.011..17.051 rows=16264 loops=1 Worker 1: actual time=0.010..19.240 rows=16188 loops=1 -> Parallel Seq Scan on xyz."Knows" e_2 (cost=0.00..909.59 rows=29439 width=41) (actual time=0.014..14.485 rows=16667 loops=3) Output: e_2.id, e_2.start_id, e_2.end_id, e_2.label_id, e_2.start_label_id, e_2.end_label_id, e_2.properties Filter: ((e_2.start_label_id = 3) OR (e_2.end_label_id = 3)) Worker 0: actual time=0.010..14.290 rows=16264 loops=1 Worker 1: actual time=0.009..15.155 rows=16188 loops=1 -> Parallel Seq Scan on xyz._ag_label_edge e_1 (cost=0.00..0.00 rows=1 width=68) (actual time=0.003..0.003 rows=0 loops=1) Output: e_1.id, e_1.start_id, e_1.end_id, e_1.label_id, e_1.start_label_id, e_1.end_label_id, e_1.properties Filter: ((e_1.start_label_id = 3) OR (e_1.end_label_id = 3)) -> Append (cost=0.00..2735.02 rows=100002 width=8) (actual time=0.001..12.440 rows=100001 loops=50000) Worker 0: actual time=0.001..12.861 rows=100001 loops=16264 Worker 1: actual time=0.001..12.873 rows=100001 loops=16188 -> Seq Scan on xyz._ag_label_vertex _age_default_alias_0_1 (cost=0.00..0.00 rows=1 width=8) (actual time=0.000..0.000 rows=0 loops=50000) Output: _age_default_alias_0_1.id Worker 0: actual time=0.000..0.000 rows=0 loops=16264 Worker 1: actual time=0.000..0.000 rows=0 loops=16188 -> Seq Scan on xyz."Person" _age_default_alias_0_2 (cost=0.00..2235.01 rows=100001 width=8) (actual time=0.001..8.112 rows=100001 loops=50000) Output: _age_default_alias_0_2.id Worker 0: actual time=0.001..8.477 rows=100001 loops=16264 Worker 1: actual time=0.001..8.478 rows=100001 loops=16188 Planning Time: 0.628 ms Execution Time: 291871.477 ms (34 rows) ``` Planning time: 0.628 ms, Execution time: 291871.477 ms (4 minutes, 51 seconds) 8. `SELECT * FROM cypher('xyz', $$ EXPLAIN ANALYZE VERBOSE MATCH (:Person)-[e:Knows]-() RETURN e $$) AS (x agtype);` Old version: ``` QUERY PLAN --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- Nested Loop (cost=0.00..1373537.46 rows=1000 width=32) (actual time=0.059..624454.671 rows=100000 loops=1) Output: _agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37051'::oid, e.id), e.properties) Join Filter: (((e.end_id = _age_default_alias_0.id) AND ((_extract_label_id(e.start_id))::integer = 3)) OR ((e.start_id = _age_default_alias_0.id) AND ((_extract_label_id(e.end_id))::integer = 3))) Rows Removed by Join Filter: 4999950000 -> Append (cost=0.00..2637.02 rows=100002 width=8) (actual time=0.020..31.987 rows=100001 loops=1) -> Seq Scan on xyz._ag_label_vertex _age_default_alias_0_1 (cost=0.00..0.00 rows=1 width=8) (actual time=0.008..0.008 rows=0 loops=1) Output: _age_default_alias_0_1.id -> Seq Scan on xyz."Person" _age_default_alias_0_2 (cost=0.00..2137.01 rows=100001 width=8) (actual time=0.011..22.304 rows=100001 loops=1) Output: _age_default_alias_0_2.id -> Materialize (cost=0.00..1369.29 rows=498 width=29) (actual time=0.001..3.251 rows=50000 loops=100001) Output: e.id, e.start_id, e.end_id, e.properties -> Seq Scan on xyz."Knows" e (cost=0.00..1366.80 rows=498 width=29) (actual time=0.012..5.873 rows=50000 loops=1) Output: e.id, e.start_id, e.end_id, e.properties Filter: (((_extract_label_id(e.start_id))::integer = 3) OR ((_extract_label_id(e.end_id))::integer = 3)) Planning Time: 0.392 ms Execution Time: 624460.157 ms ``` Planning time: 0.392 ms, Execution time: 624460.157 ms (10 mins 24 seconds) New version: ``` QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------------------------------------ Gather (cost=1000.00..82085241.00 rows=200002 width=32) (actual time=0.647..225625.113 rows=100000 loops=1) Output: (_agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37658'::oid, e.label_id), _label_name('37658'::oid, e.start_label_id), _label_name('37658'::oid, e.end_label_id), e.start_label_id, e.end_label_id, e.properties)) Workers Planned: 2 Workers Launched: 2 -> Nested Loop (cost=0.00..82064240.80 rows=83334 width=32) (actual time=0.213..225483.229 rows=33333 loops=3) Output: _agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37658'::oid, e.label_id), _label_name('37658'::oid, e.start_label_id), _label_name('37658'::oid, e.end_label_id), e.start_labe l_id, e.end_label_id, e.properties) Join Filter: (((e.end_id = _age_default_alias_0.id) AND (e.start_label_id = 3)) OR ((e.start_id = _age_default_alias_0.id) AND (e.end_label_id = 3))) Rows Removed by Join Filter: 1666650000 Worker 0: actual time=0.295..225518.659 rows=33372 loops=1 Worker 1: actual time=0.289..225607.427 rows=33290 loops=1 -> Parallel Append (cost=0.00..2031.58 rows=41668 width=8) (actual time=0.011..16.605 rows=33334 loops=3) Worker 0: actual time=0.011..17.505 rows=33372 loops=1 Worker 1: actual time=0.010..16.310 rows=33291 loops=1 -> Parallel Seq Scan on xyz."Person" _age_default_alias_0_2 (cost=0.00..1823.24 rows=58824 width=8) (actual time=0.009..10.207 rows=33334 loops=3) Output: _age_default_alias_0_2.id Worker 0: actual time=0.010..10.536 rows=33372 loops=1 Worker 1: actual time=0.009..10.888 rows=33291 loops=1 -> Parallel Seq Scan on xyz._ag_label_vertex _age_default_alias_0_1 (cost=0.00..0.00 rows=1 width=8) (actual time=0.002..0.002 rows=0 loops=1) Output: _age_default_alias_0_1.id -> Seq Scan on xyz."Knows" e (cost=0.00..968.47 rows=50047 width=41) (actual time=0.001..2.633 rows=50000 loops=100001) Output: e.id, e.start_id, e.end_id, e.properties, e.label_id, e.start_label_id, e.end_label_id Worker 0: actual time=0.001..2.631 rows=50000 loops=33372 Worker 1: actual time=0.001..2.638 rows=50000 loops=33291 Planning Time: 0.424 ms Execution Time: 225631.693 ms (25 rows) ``` Planning time: 0.424 ms, Execution time: 225631.693 ms (3 mins 45 seconds) 9. `SELECT * FROM cypher('xyz', $$ EXPLAIN ANALYZE VERBOSE MATCH (:Person)-[e:Knows]-(:Person) RETURN e $$) AS (x agtype);` Old version: ``` QUERY PLAN --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- Nested Loop (cost=0.00..1373021.25 rows=499 width=32) (actual time=0.063..631233.102 rows=100000 loops=1) Output: _agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37051'::oid, e.id), e.properties) Join Filter: (((e.end_id = _age_default_alias_0.id) AND ((_extract_label_id(e.start_id))::integer = 3)) OR ((e.start_id = _age_default_alias_0.id) AND ((_extract_label_id(e.end_id))::integer = 3))) Rows Removed by Join Filter: 4999950000 -> Seq Scan on xyz."Person" _age_default_alias_0 (cost=0.00..2137.01 rows=100001 width=8) (actual time=0.016..14.782 rows=100001 loops=1) Output: _age_default_alias_0.id, _age_default_alias_0.properties -> Materialize (cost=0.00..1369.29 rows=498 width=29) (actual time=0.001..3.249 rows=50000 loops=100001) Output: e.id, e.start_id, e.end_id, e.properties -> Seq Scan on xyz."Knows" e (cost=0.00..1366.80 rows=498 width=29) (actual time=0.015..6.254 rows=50000 loops=1) Output: e.id, e.start_id, e.end_id, e.properties Filter: (((_extract_label_id(e.start_id))::integer = 3) OR ((_extract_label_id(e.end_id))::integer = 3)) Planning Time: 0.256 ms Execution Time: 631238.784 ms (13 rows) ``` Planning time: 0.256 ms, Execution time: 631238.784 ms (10 mins 31 seconds) New version: ``` QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------------------------------ Nested Loop (cost=0.00..112611205.59 rows=100093 width=32) (actual time=0.077..706801.036 rows=100000 loops=1) Output: _agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37658'::oid, e.label_id), _label_name('37658'::oid, e.start_label_id), _label_name('37658'::oid, e.end_label_id), e.start_label_id, e.end_label_id, e.properties) Join Filter: (((e.end_id = _age_default_alias_0.id) AND (e.start_label_id = 3)) OR ((e.start_id = _age_default_alias_0.id) AND (e.end_label_id = 3))) Rows Removed by Join Filter: 4999950000 -> Seq Scan on xyz."Person" _age_default_alias_0 (cost=0.00..2235.01 rows=100001 width=8) (actual time=0.023..26.069 rows=100001 loops=1) Output: _age_default_alias_0.id, _age_default_alias_0.properties, _age_default_alias_0.label_id -> Materialize (cost=0.00..1218.70 rows=50047 width=41) (actual time=0.001..3.511 rows=50000 loops=100001) Output: e.id, e.start_id, e.end_id, e.label_id, e.start_label_id, e.end_label_id, e.properties -> Seq Scan on xyz."Knows" e (cost=0.00..968.47 rows=50047 width=41) (actual time=0.013..11.748 rows=50000 loops=1) Output: e.id, e.start_id, e.end_id, e.label_id, e.start_label_id, e.end_label_id, e.properties Planning Time: 0.290 ms Execution Time: 706808.499 ms (12 rows) ``` Planning time: 0.290 ms, Execution time: 706808.499 ms (11 mins 36 seconds) 10. `SELECT * FROM cypher('xyz', $$ EXPLAIN ANALYZE VERBOSE MATCH (:Person {age:24})-[e:Knows]-() RETURN e $$) AS (x agtype);` Old version: ``` QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------- Nested Loop (cost=0.00..90650.16 rows=100 width=32) (actual time=47.157..4098.367 rows=973 loops=1) Output: _agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37051'::oid, e.id), e.properties) Join Filter: ((e.start_id = _age_default_alias_0.id) OR (e.end_id = _age_default_alias_0.id)) Rows Removed by Join Filter: 48649027 -> Seq Scan on xyz."Knows" e (cost=0.00..867.40 rows=49940 width=29) (actual time=0.016..4.076 rows=50000 loops=1) Output: e.id, e.start_id, e.end_id, e.properties -> Materialize (cost=0.00..2387.51 rows=100 width=8) (actual time=0.000..0.029 rows=973 loops=50000) Output: _age_default_alias_0.id -> Seq Scan on xyz."Person" _age_default_alias_0 (cost=0.00..2387.01 rows=100 width=8) (actual time=0.235..28.606 rows=973 loops=1) Output: _age_default_alias_0.id Filter: (_age_default_alias_0.properties @> '{"age": 24}'::agtype) Rows Removed by Filter: 99028 Planning Time: 0.234 ms Execution Time: 4098.467 ms (14 rows) ``` Planning time: 0.234 ms, Execution time: 4098.467 ms (6 mins 40 seconds) New version: ``` QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------------------------------ Nested Loop (cost=0.00..91286.99 rows=100 width=32) (actual time=125.086..4145.615 rows=973 loops=1) Output: _agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37658'::oid, e.label_id), _label_name('37658'::oid, e.start_label_id), _label_name('37658'::oid, e.end_label_id), e.start_label_id, e.end_label_id, e.properties) Join Filter: ((e.start_id = _age_default_alias_0.id) OR (e.end_id = _age_default_alias_0.id)) Rows Removed by Join Filter: 48649027 -> Seq Scan on xyz."Knows" e (cost=0.00..968.47 rows=50047 width=41) (actual time=0.024..4.896 rows=50000 loops=1) Output: e.id, e.start_id, e.end_id, e.properties, e.label_id, e.start_label_id, e.end_label_id -> Materialize (cost=0.00..2735.51 rows=100 width=8) (actual time=0.000..0.031 rows=973 loops=50000) Output: _age_default_alias_0.id -> Seq Scan on xyz."Person" _age_default_alias_0 (cost=0.00..2735.01 rows=100 width=8) (actual time=0.744..106.682 rows=973 loops=1) Output: _age_default_alias_0.id Filter: (_age_default_alias_0.properties @> agtype_build_map('age'::text, '24'::agtype)) Rows Removed by Filter: 99028 Planning Time: 0.350 ms Execution Time: 4145.763 ms (14 rows) ``` Planning time: 0.350 ms, Execution time: 4145.763 ms (6 mins 41 seconds) 11. `SELECT * FROM cypher('xyz', $$ EXPLAIN ANALYZE VERBOSE MATCH (:Person {age:24})-[e:Knows]-(:Person {age:41}) RETURN e $$) AS (x agtype);` Old version: ``` QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- Gather (cost=1000.00..9770892.49 rows=1 width=32) (actual time=566068.766..3748770.135 rows=11 loops=1) Output: (_agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37051'::oid, e.id), e.properties)) Workers Planned: 1 Workers Launched: 1 -> Nested Loop (cost=0.00..9769892.39 rows=1 width=32) (actual time=696233.881..3747321.843 rows=6 loops=2) Output: _agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37051'::oid, e.id), e.properties) Join Filter: (((e.start_id = _age_default_alias_0.id) AND (e.end_id = _age_default_alias_1.id)) OR ((e.end_id = _age_default_alias_0.id) AND (e.start_id = _age_default_alias_1.id))) Rows Removed by Join Filter: 24641224994 Worker 0: actual time=826399.321..3745873.940 rows=5 loops=1 -> Parallel Seq Scan on xyz."Person" _age_default_alias_1 (cost=0.00..1872.30 rows=59 width=8) (actual time=0.017..16.568 rows=506 loops=2) Output: _age_default_alias_1.id, _age_default_alias_1.properties Filter: (_age_default_alias_1.properties @> '{"age": 41}'::agtype) Rows Removed by Filter: 49494 Worker 0: actual time=0.018..17.071 rows=504 loops=1 -> Nested Loop (cost=0.00..65679.66 rows=4994000 width=37) (actual time=0.002..5084.650 rows=48650000 loops=1013) Output: _age_default_alias_0.id, e.id, e.start_id, e.end_id, e.properties Worker 0: actual time=0.002..5109.275 rows=48650000 loops=504 -> Seq Scan on xyz."Knows" e (cost=0.00..867.40 rows=49940 width=29) (actual time=0.001..3.622 rows=50000 loops=1013) Output: e.id, e.start_id, e.end_id, e.properties Worker 0: actual time=0.001..3.636 rows=50000 loops=504 -> Materialize (cost=0.00..2387.51 rows=100 width=8) (actual time=0.000..0.029 rows=973 loops=50650000) Output: _age_default_alias_0.id Worker 0: actual time=0.000..0.029 rows=973 loops=25200000 -> Seq Scan on xyz."Person" _age_default_alias_0 (cost=0.00..2387.01 rows=100 width=8) (actual time=0.099..29.497 rows=973 loops=2) Output: _age_default_alias_0.id Filter: (_age_default_alias_0.properties @> '{"age": 24}'::agtype) Rows Removed by Filter: 99028 Worker 0: actual time=0.061..29.781 rows=973 loops=1 Planning Time: 0.196 ms Execution Time: 3748770.183 ms (30 rows) ``` Planning time: 0.196 ms, Execution time: 3748770.183 ms (1 hour 2 minutes) New version: ``` QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- ------------------------------------ Gather (cost=1000.00..9818150.09 rows=1 width=32) (actual time=1148489.664..4062078.609 rows=11 loops=1) Output: (_agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37658'::oid, e.label_id), _label_name('37658'::oid, e.start_label_id), _label_name('37658'::oid, e.end_label_id), e.start_label_id, e.end_label_id, e.properties)) Workers Planned: 1 Workers Launched: 1 -> Nested Loop (cost=0.00..9817149.99 rows=1 width=32) (actual time=881640.920..4061255.715 rows=6 loops=2) Output: _agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37658'::oid, e.label_id), _label_name('37658'::oid, e.start_label_id), _label_name('37658'::oid, e.end_label_id), e.start_labe l_id, e.end_label_id, e.properties) Join Filter: (((e.start_id = _age_default_alias_0.id) AND (e.end_id = _age_default_alias_1.id)) OR ((e.end_id = _age_default_alias_0.id) AND (e.start_id = _age_default_alias_1.id))) Rows Removed by Join Filter: 24641224994 Worker 0: actual time=614792.925..4062067.082 rows=4 loops=1 -> Parallel Seq Scan on xyz."Person" _age_default_alias_1 (cost=0.00..2117.36 rows=59 width=8) (actual time=0.089..46.175 rows=506 loops=2) Output: _age_default_alias_1.id, _age_default_alias_1.properties, _age_default_alias_1.label_id Filter: (_age_default_alias_1.properties @> agtype_build_map('age'::text, '41'::agtype)) Rows Removed by Filter: 49494 Worker 0: actual time=0.125..46.211 rows=506 loops=1 -> Nested Loop (cost=0.00..66262.49 rows=5004700 width=49) (actual time=0.003..5605.075 rows=48650000 loops=1013) Output: _age_default_alias_0.id, e.id, e.start_id, e.end_id, e.label_id, e.start_label_id, e.end_label_id, e.properties Worker 0: actual time=0.002..5612.637 rows=48650000 loops=506 -> Seq Scan on xyz."Knows" e (cost=0.00..968.47 rows=50047 width=41) (actual time=0.001..3.836 rows=50000 loops=1013) Output: e.id, e.start_id, e.end_id, e.properties, e.label_id, e.start_label_id, e.end_label_id Worker 0: actual time=0.001..3.844 rows=50000 loops=506 -> Materialize (cost=0.00..2735.51 rows=100 width=8) (actual time=0.000..0.030 rows=973 loops=50650000) Output: _age_default_alias_0.id Worker 0: actual time=0.000..0.031 rows=973 loops=25300000 -> Seq Scan on xyz."Person" _age_default_alias_0 (cost=0.00..2735.01 rows=100 width=8) (actual time=0.452..78.515 rows=973 loops=2) Output: _age_default_alias_0.id Filter: (_age_default_alias_0.properties @> agtype_build_map('age'::text, '24'::agtype)) Rows Removed by Filter: 99028 Worker 0: actual time=0.168..78.695 rows=973 loops=1 Planning Time: 0.589 ms Execution Time: 4062078.753 ms (30 rows) ``` Planning time: 0.589 ms, Execution time: 4062078.753 ms (1 hour 7 minutes) 12. `SELECT * FROM cypher('xyz', $$ EXPLAIN ANALYZE VERBOSE MATCH ()-[e:Knows]->() RETURN startNode(e) $$) AS (x agtype);` ``` QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------- Seq Scan on xyz."Knows" e (cost=0.00..1241.95 rows=49940 width=32) (actual time=0.198..20495.647 rows=50000 loops=1) Output: age_startnode('"xyz"'::agtype, _agtype_build_edge(e.id, e.start_id, e.end_id, _label_name('37051'::oid, e.id), e.properties)) Planning Time: 0.152 ms Execution Time: 20498.801 ms (4 rows) ``` Planning time: 0.152 ms, Execution time: 20498.801 ms (20 seconds) New version: Haven't checked for new version yet. - **Update Queries:** 13. `SELECT * FROM cypher('xyz', $$ EXPLAIN ANALYZE VERBOSE MATCH (n:Person {age:23})-[e:Knows]-() SET n.age=25 $$) AS (x agtype);` ``` 2023-10-09 12:38:43.058 EEST [6136] ERROR: cannot display a value of type internal 2023-10-09 12:38:43.058 EEST [6136] STATEMENT: SELECT * FROM cypher('xyz', $$ EXPLAIN ANALYZE VERBOSE MATCH (n:Person {age:24})-[e:Knows]-() SET n.age=25 RETURN n $$) AS (x agtype); ERROR: cannot display a value of type internal ``` Without explain analyze verbose, query took about 5 seconds to complete New version: About 5 seconds to complete - **Detach delete queries** 14.) `SELECT * FROM cypher('xyz', $$ EXPLAIN ANALYZE VERBOSE MATCH (n:Person {age:24})-[e:Knows]-() DETACH DELETE n $$) AS (x agtype);` ``` 2023-10-09 12:40:41.789 EEST [6136] ERROR: cannot display a value of type internal 2023-10-09 12:40:41.789 EEST [6136] STATEMENT: SELECT * FROM cypher('xyz', $$ EXPLAIN ANALYZE VERBOSE MATCH (n:Person {age:24})-[e:Knows]-() DETACH DELETE n RETURN n $$) AS (x agtype); ERROR: cannot display a value of type internal ``` Without explain analyze verbose, query took about 5 seconds to complete New version: About 5 seconds to complete -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: dev-unsubscr...@age.apache.org For queries about this service, please contact Infrastructure at: us...@infra.apache.org
