Re: Slow when joining with view

This is weird

*---- first component (fast):*

EXPLAIN ANALYZE
SELECT *
FROM V_CourseClass_Detail x1
WHERE x1.subject_coordinator_id IN
(235,234,243,245,233,242,247,239,246,241,238,237,202,465,432,0) AND
x1.semester_id = 53;

Nested Loop (cost=229.82..1597.02 rows=1 width=2842) (actual
time=3.020..14.778 rows=268 loops=1)
-> Nested Loop Left Join (cost=229.53..1588.59 rows=1 width=2675)
(actual time=3.001..13.145 rows=268 loops=1)
-> Nested Loop Left Join (cost=229.25..1588.15 rows=1
width=2508) (actual time=2.998..12.752 rows=268 loops=1)
-> Nested Loop Left Join (cost=228.97..1587.72 rows=1
width=2341) (actual time=2.993..12.244 rows=268 loops=1)
-> Nested Loop Left Join (cost=228.68..1587.21
rows=1 width=2265) (actual time=2.988..11.674 rows=268 loops=1)
-> Nested Loop (cost=228.39..1584.09 rows=1
width=1624) (actual time=2.987..11.322 rows=268 loops=1)
-> Nested Loop (cost=228.39..1579.99
rows=1 width=1492) (actual time=2.976..9.079 rows=268 loops=1)
-> Nested Loop
(cost=228.11..1579.61 rows=1 width=1063) (actual time=2.971..8.547
rows=268 loops=1)
-> Hash Join
(cost=227.83..1553.16 rows=4 width=896) (actual time=2.958..7.951 rows=268
loops=1)
Hash Cond: (((x1.data
->> 'open_course_id'::text))::bigint = x2.id)
-> Seq Scan on
course_classes x1 (cost=0.00..1319.21 rows=811 width=660) (actual
time=0.026..4.768 rows=269 loops=1)
Filter: ((NOT
is_deleted) AND (((data ->> 'subject_coordinator_id'::text))::bigint = ANY
('{235,234,243,245,233,242,247,239,246,241,238,237,202,465,432,0}'::bigint[])))
Rows Removed by
Filter: 9870
-> Hash
(cost=227.58..227.58 rows=20 width=244) (actual time=2.925..2.925 rows=446
loops=1)
Buckets: 1024
Batches: 1 Memory Usage: 112kB
-> Hash Join
(cost=66.53..227.58 rows=20 width=244) (actual time=0.667..2.831 rows=446
loops=1)
Hash Cond:
(((x2.data ->> 'trimester_course_id'::text))::bigint = x3.id)
-> Seq Scan
on open_courses x2 (cost=0.00..130.58 rows=4036 width=113) (actual
time=0.003..0.731 rows=4036 loops=1)

Filter: (NOT is_deleted)
Rows
Removed by Filter: 22
-> Hash
(cost=66.44..66.44 rows=7 width=139) (actual time=0.659..0.659 rows=159
loops=1)

Buckets: 1024 Batches: 1 Memory Usage: 28kB
->
Seq Scan on trimester_courses x3 (cost=0.00..66.44 rows=7 width=139)
(actual time=0.005..0.629 rows=159 loops=1)

Filter: ((NOT is_deleted) AND (((data ->> 'semester_id'::text))::bigint =
53))

Rows Removed by Filter: 1263
-> Index Scan using tags_pkey
on tags x4 (cost=0.28..6.60 rows=1 width=175) (actual time=0.001..0.002
rows=1 loops=268)
Index Cond: (id =
((x3.data ->> 'curriculum_id'::text))::bigint)
Filter: ((NOT
is_deleted) AND ((data ->> 'type'::text) = 'curriculum'::text))
-> Index Scan using subjects_pkey
on subjects x5 (cost=0.28..0.37 rows=1 width=437) (actual
time=0.001..0.001 rows=1 loops=268)
Index Cond: (id = ((x2.data
->> 'subject_id'::text))::bigint)
-> Seq Scan on events x6
(cost=0.00..4.09 rows=1 width=140) (actual time=0.005..0.008 rows=1
loops=268)
Filter: (id = 53)
Rows Removed by Filter: 86
-> Index Scan using users_pkey on users x7
(cost=0.29..3.11 rows=1 width=649) (actual time=0.001..0.001 rows=0
loops=268)
Index Cond: (((x1.data ->>
'lecturer_id'::text))::bigint = id)
-> Index Scan using class_groups_pkey on class_groups
x8 (cost=0.29..0.50 rows=1 width=84) (actual time=0.001..0.001 rows=1
loops=268)
Index Cond: (((x1.data ->>
'class_group_id'::text))::bigint = id)
-> Index Scan using tags_pkey on tags x9 (cost=0.28..0.43
rows=1 width=175) (actual time=0.001..0.001 rows=1 loops=268)
Index Cond: (((x1.data ->>
'subject_coordinator_id'::text))::bigint = id)
-> Index Scan using tags_pkey on tags x10 (cost=0.28..0.43
rows=1 width=175) (actual time=0.001..0.001 rows=1 loops=268)
Index Cond: (((x1.data ->> 'room_id'::text))::bigint = id)
-> Index Scan using tags_pkey on tags x11 (cost=0.28..8.31 rows=1
width=175) (actual time=0.001..0.001 rows=1 loops=268)
Index Cond: (id = ((x4.data ->> 'major_id'::text))::bigint)
* Planning time: 1.504 ms*
* Execution time: 14.923 ms*

*---- second component (fast):*

EXPLAIN ANALYZE
SELECT cc_merged_id
,
ARRAY_TO_STRING(ARRAY[program_session,curriculum,class_group],' | ')
merged_names
, modified_at
FROM v_courseclass_detail x1
WHERE cc_merged_id IS NOT NULL AND x1.subject_coordinator_id IN
(235,234,243,245,233,242,247,239,246,241,238,237,202,465,432,0) AND
x1.semester_id = 53;

Nested Loop (cost=229.82..1672.95 rows=1 width=1082) (actual
time=2.799..6.618 rows=11 loops=1)
-> Nested Loop Left Join (cost=229.53..1664.61 rows=1 width=1074)
(actual time=2.789..6.572 rows=11 loops=1)
-> Nested Loop Left Join (cost=229.25..1664.17 rows=1
width=1066) (actual time=2.788..6.565 rows=11 loops=1)
-> Nested Loop Left Join (cost=228.97..1663.73 rows=1
width=1058) (actual time=2.785..6.544 rows=11 loops=1)
-> Nested Loop Left Join (cost=228.68..1663.22
rows=1 width=982) (actual time=2.779..6.516 rows=11 loops=1)
-> Nested Loop (cost=228.39..1660.10 rows=1
width=974) (actual time=2.778..6.505 rows=11 loops=1)
-> Nested Loop (cost=228.39..1656.00
rows=1 width=966) (actual time=2.769..6.420 rows=11 loops=1)
-> Nested Loop
(cost=228.11..1655.62 rows=1 width=1055) (actual time=2.763..6.389 rows=11
loops=1)
-> Hash Join
(cost=227.83..1629.18 rows=4 width=888) (actual time=2.752..6.353 rows=11
loops=1)
Hash Cond: (((x1.data
->> 'open_course_id'::text))::bigint = x2.id)
-> Seq Scan on
course_classes x1 (cost=0.00..1395.26 rows=807 width=652) (actual
time=0.210..3.801 rows=11 loops=1)
Filter: ((NOT
is_deleted) AND (((data ->> 'cc_merged_id'::text))::bigint IS NOT NULL) AND
(((data ->> 'subject_coordinator_id'::text))::bigint = ANY
('{235,234,243,245,233,242,247,239,246,241,238,237,202,465,432,0}'::bigint[])))
Rows Removed by
Filter: 10128
-> Hash
(cost=227.58..227.58 rows=20 width=244) (actual time=2.536..2.536 rows=446
loops=1)
Buckets: 1024
Batches: 1 Memory Usage: 112kB
-> Hash Join
(cost=66.53..227.58 rows=20 width=244) (actual time=0.579..2.458 rows=446
loops=1)
Hash Cond:
(((x2.data ->> 'trimester_course_id'::text))::bigint = x3.id)
-> Seq Scan
on open_courses x2 (cost=0.00..130.58 rows=4036 width=113) (actual
time=0.003..0.663 rows=4036 loops=1)

Filter: (NOT is_deleted)
Rows
Removed by Filter: 22
-> Hash
(cost=66.44..66.44 rows=7 width=139) (actual time=0.572..0.572 rows=159
loops=1)

Buckets: 1024 Batches: 1 Memory Usage: 28kB
->
Seq Scan on trimester_courses x3 (cost=0.00..66.44 rows=7 width=139)
(actual time=0.005..0.554 rows=159 loops=1)

Filter: ((NOT is_deleted) AND (((data ->> 'semester_id'::text))::bigint =
53))

Rows Removed by Filter: 1263
-> Index Scan using tags_pkey
on tags x4 (cost=0.28..6.60 rows=1 width=175) (actual time=0.002..0.002
rows=1 loops=11)
Index Cond: (id =
((x3.data ->> 'curriculum_id'::text))::bigint)
Filter: ((NOT
is_deleted) AND ((data ->> 'type'::text) = 'curriculum'::text))
-> Index Scan using subjects_pkey
on subjects x5 (cost=0.28..0.37 rows=1 width=16) (actual time=0.002..0.002
rows=1 loops=11)
Index Cond: (id = ((x2.data
->> 'subject_id'::text))::bigint)
-> Seq Scan on events x6
(cost=0.00..4.09 rows=1 width=16) (actual time=0.004..0.007 rows=1
loops=11)
Filter: (id = 53)
Rows Removed by Filter: 86
-> Index Scan using users_pkey on users x7
(cost=0.29..3.12 rows=1 width=16) (actual time=0.000..0.000 rows=0
loops=11)
Index Cond: (((x1.data ->>
'lecturer_id'::text))::bigint = id)
-> Index Scan using class_groups_pkey on class_groups
x8 (cost=0.29..0.50 rows=1 width=84) (actual time=0.002..0.002 rows=1
loops=11)
Index Cond: (((x1.data ->>
'class_group_id'::text))::bigint = id)
-> Index Scan using tags_pkey on tags x9 (cost=0.28..0.43
rows=1 width=16) (actual time=0.001..0.001 rows=1 loops=11)
Index Cond: (((x1.data ->>
'subject_coordinator_id'::text))::bigint = id)
-> Index Scan using tags_pkey on tags x10 (cost=0.28..0.43
rows=1 width=16) (actual time=0.000..0.000 rows=0 loops=11)
Index Cond: (((x1.data ->> 'room_id'::text))::bigint = id)
-> Index Scan using tags_pkey on tags x11 (cost=0.28..8.31 rows=1
width=16) (actual time=0.001..0.001 rows=1 loops=11)
Index Cond: (id = ((x4.data ->> 'major_id'::text))::bigint)
* Planning time: 1.367 ms*
* Execution time: 6.719 ms*

*---- but when combined (real slow):*

EXPLAIN ANALYZE
SELECT x1.id id
, x1.lecturer_id
, x1.class_group_id
, x1.subject_coordinator_id
, x1.room_id
, x1.time_block_id
, x1.cc_merged_id
, x1.open_course_id
, x1.subject_id
, x1.program_session
, x1.semester_id
, x1.curriculum_id
, x1.major_id
, x1.curriculum -- or batch
, x1.subject
, x1.sks
, x1.semester_code
, x1.lecturer
, x1.class_group
, x1.coordinator
, x1.room
, x1.major
, GREATEST(x1.modified_at, x2.modified_at) modified_at
, x2.merged_names
FROM (
SELECT *
FROM V_CourseClass_Detail x1
WHERE x1.subject_coordinator_id IN
(235,234,243,245,233,242,247,239,246,241,238,237,202,465,432,0) AND
x1.semester_id = 53
) x1
LEFT JOIN (
SELECT cc_merged_id
,
ARRAY_TO_STRING(ARRAY[program_session,curriculum,class_group],' | ')
merged_names
, modified_at
FROM v_courseclass_detail x1
WHERE cc_merged_id IS NOT NULL AND x1.subject_coordinator_id IN
(235,234,243,245,233,242,247,239,246,241,238,237,202,465,432,0) AND
x1.semester_id = 53
) x2 ON x1.id = x2.cc_merged_id

Nested Loop (cost=231.81..3138.12 rows=1 width=2882) (actual
time=623.088..139706.357 rows=268 loops=1)
-> Nested Loop Left Join (cost=231.53..3129.68 rows=1 width=2715)
(actual time=623.061..139700.924 rows=268 loops=1)
-> Nested Loop Left Join (cost=231.25..3129.24 rows=1
width=2548) (actual time=623.052..139699.634 rows=268 loops=1)
-> Nested Loop Left Join (cost=230.96..3128.80 rows=1
width=2381) (actual time=623.030..139697.219 rows=268 loops=1)
Join Filter: (x1.id = ((x1_1.data ->>
'cc_merged_id'::text))::bigint)
Rows Removed by Join Filter: 2937
-> Nested Loop Left Join (cost=228.97..1587.72
rows=1 width=2341) (actual time=5.029..20.389 rows=268 loops=1)
-> Nested Loop Left Join (cost=228.68..1587.21
rows=1 width=2265) (actual time=5.016..18.583 rows=268 loops=1)
-> Nested Loop (cost=228.39..1584.09
rows=1 width=1624) (actual time=5.010..17.392 rows=268 loops=1)
-> Nested Loop
(cost=228.39..1579.99 rows=1 width=1492) (actual time=4.987..13.854
rows=268 loops=1)
-> Nested Loop
(cost=228.11..1579.61 rows=1 width=1063) (actual time=4.972..11.981
rows=268 loops=1)
-> Hash Join
(cost=227.83..1553.16 rows=4 width=896) (actual time=4.946..10.176
rows=268 loops=1)
Hash Cond:
(((x1.data ->> 'open_course_id'::text))::bigint = x2.id)
-> Seq Scan on
course_classes x1 (cost=0.00..1319.21 rows=811 width=660) (actual
time=0.032..4.255 rows=269 loops=1)
Filter:
((NOT is_deleted) AND (((data ->> 'subject_coordinator_id'::text))::bigint
= ANY
('{235,234,243,245,233,242,247,239,246,241,238,237,202,465,432,0}'::bigint[])))
Rows Removed
by Filter: 9870
-> Hash
(cost=227.58..227.58 rows=20 width=244) (actual time=4.884..4.884 rows=446
loops=1)
Buckets:
1024 Batches: 1 Memory Usage: 112kB
-> Hash
Join (cost=66.53..227.58 rows=20 width=244) (actual time=1.079..4.680
rows=446 loops=1)
Hash
Cond: (((x2.data ->> 'trimester_course_id'::text))::bigint = x3.id)
->
Seq Scan on open_courses x2 (cost=0.00..130.58 rows=4036 width=113)
(actual time=0.005..1.279 rows=4036 loops=1)

Filter: (NOT is_deleted)

Rows Removed by Filter: 22
->
Hash (cost=66.44..66.44 rows=7 width=139) (actual time=1.057..1.057
rows=159 loops=1)

Buckets: 1024 Batches: 1 Memory Usage: 28kB

-> Seq Scan on trimester_courses x3 (cost=0.00..66.44 rows=7 width=139)
(actual time=0.012..0.999 rows=159 loops=1)

Filter: ((NOT is_deleted) AND (((data ->>
'semester_id'::text))::bigint = 53))

Rows Removed by Filter: 1263
-> Index Scan using
tags_pkey on tags x4 (cost=0.28..6.60 rows=1 width=175) (actual
time=0.004..0.004 rows=1 loops=268)
Index Cond: (id =
((x3.data ->> 'curriculum_id'::text))::bigint)
Filter: ((NOT
is_deleted) AND ((data ->> 'type'::text) = 'curriculum'::text))
-> Index Scan using
subjects_pkey on subjects x5 (cost=0.28..0.37 rows=1 width=437) (actual
time=0.004..0.004 rows=1 loops=268)
Index Cond: (id =
((x2.data ->> 'subject_id'::text))::bigint)
-> Seq Scan on events x6
(cost=0.00..4.09 rows=1 width=140) (actual time=0.005..0.010 rows=1
loops=268)
Filter: (id = 53)
Rows Removed by Filter: 86
-> Index Scan using users_pkey on users
x7 (cost=0.29..3.11 rows=1 width=649) (actual time=0.002..0.002 rows=0
loops=268)
Index Cond: (((x1.data ->>
'lecturer_id'::text))::bigint = id)
-> Index Scan using class_groups_pkey on
class_groups x8 (cost=0.29..0.50 rows=1 width=84) (actual
time=0.003..0.004 rows=1 loops=268)
Index Cond: (((x1.data ->>
'class_group_id'::text))::bigint = id)
-> Nested Loop (cost=1.99..1541.07 rows=1 width=684)
(actual time=42.916..521.168 rows=11 loops=268)
-> Nested Loop Left Join (cost=1.71..1532.75
rows=1 width=915) (actual time=42.909..521.123 rows=11 loops=268)
-> Nested Loop Left Join
(cost=1.43..1532.31 rows=1 width=907) (actual time=42.907..521.107 rows=11
loops=268)
-> Nested Loop Left Join
(cost=1.15..1531.87 rows=1 width=899) (actual time=42.901..521.057 rows=11
loops=268)
-> Nested Loop Left Join
(cost=0.86..1531.36 rows=1 width=982) (actual time=42.886..520.957 rows=11
loops=268)
-> Nested Loop
(cost=0.57..1528.23 rows=1 width=974) (actual time=42.884..520.933 rows=11
loops=268)
-> Nested Loop
(cost=0.57..1524.13 rows=1 width=966) (actual time=42.875..520.824 rows=11
loops=268)
-> Nested
Loop (cost=0.29..1523.75 rows=1 width=1055) (actual time=42.869..520.767
rows=11 loops=268)
Join
Filter: (x3_1.id = ((x2_1.data ->> 'trimester_course_id'::text))::bigint)
Rows
Removed by Join Filter: 1738
->
Nested Loop (cost=0.00..1502.49 rows=25 width=958) (actual
time=0.163..515.486 rows=1749 loops=268)

-> Nested Loop (cost=0.00..99.16 rows=1 width=306) (actual
time=0.024..6.592 rows=159 loops=268)

Join Filter: (((x3_1.data ->> 'curriculum_id'::text))::bigint = x4_1.id
)

Rows Removed by Join Filter: 15741

-> Seq Scan on trimester_courses x3_1 (cost=0.00..66.44 rows=7
width=139) (actual time=0.004..0.763 rows=159 loops=268)

Filter: ((NOT is_deleted) AND (((data ->>
'semester_id'::text))::bigint = 53))

Rows Removed by Filter: 1263

-> Materialize (cost=0.00..32.26 rows=3 width=175) (actual
time=0.000..0.008 rows=100 loops=42612)

-> Seq Scan on tags x4_1 (cost=0.00..32.24 rows=3 width=175)
(actual time=0.240..0.422 rows=100 loops=1)

Filter: ((NOT is_deleted) AND ((data ->> 'type'::text) =
'curriculum'::text))

Rows Removed by Filter: 583

-> Seq Scan on course_classes x1_1 (cost=0.00..1395.26 rows=807
width=652) (actual time=0.156..3.197 rows=11 loops=42612)

Filter: ((NOT is_deleted) AND (((data ->>
'cc_merged_id'::text))::bigint IS NOT NULL) AND (((data ->>
'subject_coordinator_id'::text))::bigint = ANY
('{235,234,243,245,233,242,247,239,246,241,238,237,202,465,432,0}'::bigint[])))

Rows Removed by Filter: 10128
->
Index Scan using open_courses_pkey on open_courses x2_1 (cost=0.29..0.83
rows=1 width=113) (actual time=0.002..0.002 rows=1 loops=468732)

Index Cond: (id = ((x1_1.data ->> 'open_course_id'::text))::bigint)

Filter: (NOT is_deleted)
-> Index
Scan using subjects_pkey on subjects x5_1 (cost=0.28..0.37 rows=1
width=16) (actual time=0.003..0.003 rows=1 loops=2948)
Index
Cond: (id = ((x2_1.data ->> 'subject_id'::text))::bigint)
-> Seq Scan on
events x6_1 (cost=0.00..4.09 rows=1 width=16) (actual time=0.005..0.008
rows=1 loops=2948)
Filter: (id
= 53)
Rows Removed
by Filter: 86
-> Index Scan using
users_pkey on users x7_1 (cost=0.29..3.12 rows=1 width=16) (actual
time=0.001..0.001 rows=0 loops=2948)
Index Cond:
(((x1_1.data ->> 'lecturer_id'::text))::bigint = id)
-> Index Scan using
class_groups_pkey on class_groups x8_1 (cost=0.29..0.50 rows=1 width=84)
(actual time=0.002..0.003 rows=1 loops=2948)
Index Cond: (((x1_1.data
->> 'class_group_id'::text))::bigint = id)
-> Index Scan using tags_pkey on
tags x9_1 (cost=0.28..0.43 rows=1 width=16) (actual time=0.003..0.003
rows=1 loops=2948)
Index Cond: (((x1_1.data ->>
'subject_coordinator_id'::text))::bigint = id)
-> Index Scan using tags_pkey on tags
x10_1 (cost=0.28..0.43 rows=1 width=16) (actual time=0.000..0.000 rows=0
loops=2948)
Index Cond: (((x1_1.data ->>
'room_id'::text))::bigint = id)
-> Index Scan using tags_pkey on tags x11_1
(cost=0.28..8.31 rows=1 width=16) (actual time=0.001..0.002 rows=1
loops=2948)
Index Cond: (id = ((x4_1.data ->>
'major_id'::text))::bigint)
-> Index Scan using tags_pkey on tags x9 (cost=0.28..0.43
rows=1 width=175) (actual time=0.005..0.005 rows=1 loops=268)
Index Cond: (((x1.data ->>
'subject_coordinator_id'::text))::bigint = id)
-> Index Scan using tags_pkey on tags x10 (cost=0.28..0.43
rows=1 width=175) (actual time=0.002..0.002 rows=1 loops=268)
Index Cond: (((x1.data ->> 'room_id'::text))::bigint = id)
-> Index Scan using tags_pkey on tags x11 (cost=0.28..8.31 rows=1
width=175) (actual time=0.002..0.002 rows=1 loops=268)
Index Cond: (id = ((x4.data ->> 'major_id'::text))::bigint)
* Planning time: 14.533 ms*
* Execution time: 139707.024 ms*

https://stackoverflow.com/questions/30861967/slow-when-joining-with-view

--
Best Regards,
Kiswono P
GB