Thread: Slow when joining with view
The case https://stackoverflow.com/questions/30861967/slow-when-joining-with-view
--
It doesn't make sense that this query took 10s:
explain analyze
SELECT x1.id
FROM ( SELECT id, data->>'open_course_id' oc_id FROM student_credits WHERE (data->>'student_id')::BIGINT = '5500'
) x1
JOIN ( SELECT id FROM V_OpenCourse_WithTC WHERE semester_id = '53'
) x2 ON x1.oc_id::BIGINT = x2.id when both of its components took less than 100ms:
SELECT id, data->>'open_course_id' oc_id FROM student_credits WHERE (data->>'student_id')::BIGINT = '5500' SELECT id FROM V_OpenCourse_WithTC WHERE semester_id = '53'Best Regards,
Kiswono P
GB
Kiswono P
GB
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
--
Best Regards,
Kiswono P
GB