쿼리 실행 계획
Aggregate (cost=90612107.84..90612107.85 rows=1 width=8) (actual time=32929.952..32930.092 rows=1.00 loops=1)
Output: count(*)
Buffers: shared hit=10674180 read=4288620 dirtied=347 written=31039, temp read=7586 written=7593
I/O Timings: shared read=14261.810 write=293.110, temp read=14.315 write=30.269
-> Hash Left Join (cost=119766.87..90612106.13 rows=682 width=0) (actual time=32194.119..32929.031 rows=15150.00 loops=1)
Hash Cond: (categories.id = category_moderation_groups.category_id)
Filter: (reviewables.reviewable_by_moderator OR (category_moderation_groups.group_id = ANY ('{2,3,10,11,12,13,14,41,42,43,45}'::integer[])))
Buffers: shared hit=10674180 read=4288620 dirtied=347 written=31039, temp read=7586 written=7593
I/O Timings: shared read=14261.810 write=293.110, temp read=14.315 write=30.269
-> Hash Left Join (cost=119765.73..90612102.02 rows=682 width=5) (actual time=32194.091..32926.732 rows=15150.00 loops=1)
Output: reviewables.reviewable_by_moderator, categories.id
Inner Unique: true
Hash Cond: (reviewables.category_id = categories.id)
Buffers: shared hit=10674179 read=4288620 dirtied=347 written=31039, temp read=7586 written=7593
I/O Timings: shared read=14261.810 write=293.110, temp read=14.315 write=30.269
-> Nested Loop Anti Join (cost=119754.18..90612088.62 rows=682 width=5) (actual time=32193.982..32923.913 rows=15150.00 loops=1)
Output: reviewables.reviewable_by_moderator, reviewables.category_id
Buffers: shared hit=10674144 read=4288620 dirtied=347 written=31039, temp read=7586 written=7593
I/O Timings: shared read=14261.810 write=293.110, temp read=14.315 write=30.269
-> Hash Right Anti Join (cost=118961.51..508536.27 rows=1245 width=9) (actual time=32193.966..32197.445 rows=15150.00 loops=1)
Output: reviewables.reviewable_by_moderator, reviewables.topic_id, reviewables.category_id
Hash Cond: (reviewable_target.id = reviewables.target_id)
Join Filter: ((reviewables.target_type)::text = 'Post'::text)
Buffers: shared hit=10620534 read=4187031 dirtied=346 written=30978, temp read=7586 written=7593
I/O Timings: shared read=14228.848 write=292.755, temp read=14.315 write=30.269
-> Merge Anti Join (cost=117907.10..455690.79 rows=10322451 width=4) (actual time=24275.150..30701.899 rows=5224880.00 loops=1)
Output: reviewable_target.id
Merge Cond: (reviewable_target.id = posts.id)
Buffers: shared hit=10619973 read=4187031 dirtied=346 written=30978, temp read=7586 written=7593
I/O Timings: shared read=14228.848 write=292.755, temp read=14.315 write=30.269
-> Index Only Scan using posts_pkey on public.posts reviewable_target (cost=0.43..311977.87 rows=10322458 width=4) (actual time=0.015..3721.140 rows=10388505.00 loops=1)
Output: reviewable_target.id
Heap Fetches: 586809
Index Searches: 1
Buffers: shared hit=9845158 read=105882 dirtied=81 written=2154
I/O Timings: shared read=366.948 write=18.531
-> Sort (cost=117906.67..117906.68 rows=7 width=4) (actual time=24273.538..24994.595 rows=5163625.00 loops=1)
Output: posts.id
Sort Key: posts.id
Sort Method: external merge Disk: 60688kB
Buffers: shared hit=774815 read=4081149 dirtied=265 written=28824, temp read=7586 written=7593
I/O Timings: shared read=13861.900 write=274.223, temp read=14.315 write=30.269
-> Nested Loop (cost=117845.50..117906.57 rows=7 width=4) (actual time=1068.513..23253.874 rows=5163625.00 loops=1)
Output: posts.id
Buffers: shared hit=774815 read=4081149 dirtied=265 written=28824
I/O Timings: shared read=13861.900 write=274.223
-> HashAggregate (cost=117845.06..117845.07 rows=1 width=4) (actual time=1068.458..1116.707 rows=91574.00 loops=1)
Output: topics.id
Group Key: topics.id
Batches: 1 Memory Usage: 5169kB
Buffers: shared hit=18776 read=79072 dirtied=3
I/O Timings: shared read=43.128
-> Gather (cost=1818.73..117845.06 rows=1 width=4) (actual time=81.869..1025.742 rows=91574.00 loops=1)
Output: topics.id
Workers Planned: 2
Workers Launched: 2
Buffers: shared hit=18776 read=79072 dirtied=3
I/O Timings: shared read=43.128
-> Hash Left Join (cost=818.73..116844.96 rows=1 width=4) (actual time=558.090..1017.927 rows=30524.67 loops=3)
Output: topics.id
Inner Unique: true
Hash Cond: (topics.id = shared_drafts.topic_id)
Filter: (shared_drafts.id IS NULL)
Buffers: shared hit=18776 read=79072 dirtied=3
I/O Timings: shared read=43.128
Worker 0: actual time=765.561..1012.978 rows=11078.00 loops=1
JIT:
Functions: 114
Options: Inlining true, Optimization true, Expressions true, Deforming true
Timing: Generation 15.225 ms (Deform 3.129 ms), Inlining 135.900 ms, Optimization 287.768 ms, Emission 329.808 ms, Total 768.701 ms
Buffers: shared hit=2035 read=15493
I/O Timings: shared read=7.217
Worker 1: actual time=827.352..1029.012 rows=8561.00 loops=1
JIT:
Functions: 114
Options: Inlining true, Optimization true, Expressions true, Deforming true
Timing: Generation 6.162 ms (Deform 2.466 ms), Inlining 166.737 ms, Optimization 318.974 ms, Emission 330.326 ms, Total 822.199 ms
Buffers: shared hit=1561 read=11593
I/O Timings: shared read=9.948
-> Parallel Seq Scan on public.topics (cost=817.55..115599.40 rows=474050 width=4) (actual time=558.040..1011.488 rows=30524.67 loops=3)
Output: topics.id, topics.title, topics.last_posted_at, topics.created_at, topics.updated_at, topics.views, topics.posts_count, topics.user_id, topics.last_post_user_id, topics.reply_count, topics.featured_user1_id, topics.featured_user2_id, topics.featured_user3_id, topics.deleted_at, topics.highest_post_number, topics.like_count, topics.incoming_link_count, topics.category_id, topics.visible, topics.moderator_posts_count, topics.closed, topics.archived, topics.bumped_at, topics.has_summary, topics.archetype, topics.featured_user4_id, topics.notify_moderators_count, topics.spam_count, topics.pinned_at, topics.score, topics.percent_rank, topics.subtype, topics.slug, topics.deleted_by_id, topics.participant_count, topics.word_count, topics.excerpt, topics.pinned_globally, topics.pinned_until, topics.fancy_title, topics.highest_staff_post_number, topics.featured_link, topics.reviewable_score, topics.image_upload_id, topics.slow_mode_seconds, topics.bannered_until, topics.external_id, topics.visibility_reason_id, topics.locale, topics.og_image_upload_id
Filter: ((((topics.archetype)::text <> 'private_message'::text) AND ((topics.category_id IS NULL) OR (ANY (topics.category_id = (hashed SubPlan 5).col1)))) OR (((topics.archetype)::text = 'private_message'::text) AND ((topics.archetype)::text = 'private_message'::text) AND ((ANY (topics.id = (hashed SubPlan 6).col1)) OR (ANY (topics.id = (hashed SubPlan 7).col1)) OR ((topics.subtype)::text = 'moderator_warning'::text) OR (ANY (topics.id = (hashed SubPlan 8).col1)))))
Rows Removed by Filter: 449563
Buffers: shared hit=18773 read=79072 dirtied=3
I/O Timings: shared read=43.128
Worker 0: actual time=765.502..1010.751 rows=11078.00 loops=1
Buffers: shared hit=2034 read=15493
I/O Timings: shared read=7.217
Worker 1: actual time=827.293..1026.236 rows=8561.00 loops=1
Buffers: shared hit=1560 read=11593
I/O Timings: shared read=9.948
SubPlan 5
-> Seq Scan on public.categories categories_1 (cost=0.20..25.06 rows=96 width=4) (actual time=12.092..12.202 rows=123.00 loops=3)
Output: categories_1.id
Filter: ((NOT categories_1.read_restricted) OR (categories_1.id = ANY ('{7,9,10,11,13,14,19,23,25,26,28,29,30,32,35,37,41,42,43,44,45,48,49,50,51,52,53,55,56,58,59,61,62,65,66,67,68,69,70,71,72,73,75,76,78,79,82,84,85,86,87,88,90,91,92,95,96,97,98,99,100,101,102,103,104,107,108,109,110,111,112,113,114,115,116,118,124,125,126,127,130}'::integer[])))
Rows Removed by Filter: 1
Buffers: shared hit=69
Worker 0: actual time=16.097..16.230 rows=123.00 loops=1
Buffers: shared hit=23
Worker 1: actual time=11.074..11.204 rows=123.00 loops=1
Buffers: shared hit=23
SubPlan 6
-> Index Only Scan using index_topic_allowed_users_on_user_id_and_topic_id on public.topic_allowed_users topic_allowed_users_1 (cost=0.43..641.51 rows=4328 width=4) (actual time=13.820..15.031 rows=3503.00 loops=3)
Output: topic_allowed_users_1.topic_id
Index Cond: (topic_allowed_users_1.user_id = 18)
Heap Fetches: 879
Index Searches: 3
Buffers: shared hit=536 read=213
I/O Timings: shared read=0.608
Worker 0: actual time=16.351..17.337 rows=3503.00 loops=1
Buffers: shared hit=249 read=1
I/O Timings: shared read=0.038
Worker 1: actual time=15.636..16.995 rows=3503.00 loops=1
Buffers: shared hit=250
SubPlan 7
-> Nested Loop (cost=0.71..128.02 rows=1 width=4) (actual time=17.997..22.239 rows=7742.00 loops=3)
Output: tg_1.topic_id
Buffers: shared hit=167 read=23
I/O Timings: shared read=0.169
Worker 0: actual time=22.450..26.266 rows=7742.00 loops=1
Buffers: shared hit=62 read=2
I/O Timings: shared read=0.075
Worker 1: actual time=22.307..24.222 rows=7742.00 loops=1
Buffers: shared hit=64
-> Index Only Scan using index_group_users_on_user_id_and_group_id on public.group_users gu_1 (cost=0.42..12.23 rows=2 width=4) (actual time=0.076..0.105 rows=11.00 loops=3)
Output: gu_1.user_id, gu_1.group_id
Index Cond: (gu_1.user_id = 18)
Heap Fetches: 33
Index Searches: 3
Buffers: shared hit=46 read=1
I/O Timings: shared read=0.037
Worker 0: actual time=0.111..0.152 rows=11.00 loops=1
Buffers: shared hit=15 read=1
I/O Timings: shared read=0.037
Worker 1: actual time=0.101..0.132 rows=11.00 loops=1
Buffers: shared hit=16
-> Index Only Scan using index_topic_allowed_groups_on_group_id_and_topic_id on public.topic_allowed_groups tg_1 (cost=0.29..44.66 rows=1324 width=8) (actual time=0.008..0.126 rows=703.82 loops=33)
Output: tg_1.group_id, tg_1.topic_id
Index Cond: (tg_1.group_id = gu_1.group_id)
Heap Fetches: 1074
Index Searches: 33
Buffers: shared hit=121 read=22
I/O Timings: shared read=0.132
Worker 0: actual time=0.010..0.194 rows=703.82 loops=11
Buffers: shared hit=47 read=1
I/O Timings: shared read=0.038
Worker 1: actual time=0.009..0.093 rows=703.82 loops=11
Buffers: shared hit=48
SubPlan 8
-> Index Scan using index_reviewables_on_status_and_type on public.reviewables reviewables_2 (cost=0.29..11.89 rows=2 width=4) (actual time=21.244..21.266 rows=5.00 loops=3)
Output: reviewables_2.topic_id
Index Cond: ((reviewables_2.status = 0) AND ((reviewables_2.type)::text = 'ReviewableFlaggedPost'::text))
Filter: (reviewables_2.score >= '0'::double precision)
Index Searches: 3
Buffers: shared hit=16 read=1
I/O Timings: shared read=0.032
Worker 0: actual time=28.239..28.266 rows=5.00 loops=1
Buffers: shared hit=5 read=1
I/O Timings: shared read=0.032
Worker 1: actual time=19.319..19.348 rows=5.00 loops=1
Buffers: shared hit=6
-> Hash (cost=1.08..1.08 rows=8 width=12) (actual time=0.039..0.040 rows=8.00 loops=3)
Output: shared_drafts.id, shared_drafts.topic_id
Buckets: 1024 Batches: 1 Memory Usage: 9kB
Buffers: shared hit=3
Worker 0: actual time=0.048..0.049 rows=8.00 loops=1
Buffers: shared hit=1
Worker 1: actual time=0.048..0.049 rows=8.00 loops=1
Buffers: shared hit=1
-> Seq Scan on public.shared_drafts (cost=0.00..1.08 rows=8 width=12) (actual time=0.032..0.033 rows=8.00 loops=3)
Output: shared_drafts.id, shared_drafts.topic_id
Buffers: shared hit=3
Worker 0: actual time=0.041..0.042 rows=8.00 loops=1
Buffers: shared hit=1
Worker 1: actual time=0.041..0.042 rows=8.00 loops=1
Buffers: shared hit=1
-> Index Scan using index_posts_on_topic_id_and_reply_to_post_number on public.posts (cost=0.43..59.66 rows=184 width=8) (actual time=0.016..0.235 rows=56.39 loops=91574)
Output: posts.id, posts.user_id, posts.topic_id, posts.post_number, posts.raw, posts.cooked, posts.created_at, posts.updated_at, posts.reply_to_post_number, posts.reply_count, posts.quote_count, posts.deleted_at, posts.off_topic_count, posts.like_count, posts.incoming_link_count, posts.bookmark_count, posts.score, posts.reads, posts.post_type, posts.sort_order, posts.last_editor_id, posts.hidden, posts.hidden_reason_id, posts.notify_moderators_count, posts.spam_count, posts.illegal_count, posts.inappropriate_count, posts.last_version_at, posts.user_deleted, posts.reply_to_user_id, posts.percent_rank, posts.notify_user_count, posts.like_score, posts.deleted_by_id, posts.edit_reason, posts.word_count, posts.version, posts.cook_method, posts.wiki, posts.baked_at, posts.baked_version, posts.hidden_at, posts.self_edits, posts.reply_quoted, posts.via_email, posts.raw_email, posts.public_version, posts.action_code, posts.locked_by_id, posts.image_upload_id, posts.outbound_message_id, posts.qa_vote_count, posts.locale
Index Cond: (posts.topic_id = topics.id)
Filter: (posts.post_type = ANY ('{1,2,3,4}'::integer[]))
Index Searches: 91574
Buffers: shared hit=756039 read=4002077 dirtied=262 written=28824
I/O Timings: shared read=13818.772 write=274.223
-> Hash (cost=867.63..867.63 rows=14942 width=18) (actual time=640.985..640.985 rows=15614.00 loops=1)
Output: reviewables.reviewable_by_moderator, reviewables.topic_id, reviewables.target_type, reviewables.target_id, reviewables.category_id
Buckets: 16384 Batches: 1 Memory Usage: 971kB
Buffers: shared hit=561
-> Seq Scan on public.reviewables (cost=0.31..867.63 rows=14942 width=18) (actual time=635.502..638.644 rows=15614.00 loops=1)
Output: reviewables.reviewable_by_moderator, reviewables.topic_id, reviewables.target_type, reviewables.target_id, reviewables.category_id
Filter: (((reviewables.category_id IS NULL) OR (reviewables.category_id = ANY ('{1,46,120,89,12,8,80,27,128,39,20,5,121,117,6,24,18,93,94,54,31,15,83,34,81,33,22,60,57,40,119,129,63,64,38,21,106,17,122,74,77,123,127,7,9,10,11,13,14,19,23,25,26,28,29,30,32,35,37,41,42,43,44,45,48,49,50,51,52,53,55,56,58,59,61,62,65,66,67,68,69,70,71,72,73,75,76,78,79,82,84,85,86,87,88,90,91,92,95,96,97,98,99,100,101,102,103,104,107,108,109,110,111,112,113,114,115,116,118,124,125,126,127,130}'::integer[]))) AND ((reviewables.type)::text = ANY ('{ReviewableFlaggedPost,ReviewableQueuedPost,ReviewableUser,ReviewablePost}'::text[])))
Rows Removed by Filter: 1
Buffers: shared hit=561
-> Index Scan using topics_pkey on public.topics private_message (cost=792.67..72372.33 rows=1 width=4) (actual time=0.048..0.048 rows=0.00 loops=15150)
Output: private_message.id, private_message.title, private_message.last_posted_at, private_message.created_at, private_message.updated_at, private_message.views, private_message.posts_count, private_message.user_id, private_message.last_post_user_id, private_message.reply_count, private_message.featured_user1_id, private_message.featured_user2_id, private_message.featured_user3_id, private_message.deleted_at, private_message.highest_post_number, private_message.like_count, private_message.incoming_link_count, private_message.category_id, private_message.visible, private_message.moderator_posts_count, private_message.closed, private_message.archived, private_message.bumped_at, private_message.has_summary, private_message.archetype, private_message.featured_user4_id, private_message.notify_moderators_count, private_message.spam_count, private_message.pinned_at, private_message.score, private_message.percent_rank, private_message.subtype, private_message.slug, private_message.deleted_by_id, private_message.participant_count, private_message.word_count, private_message.excerpt, private_message.pinned_globally, private_message.pinned_until, private_message.fancy_title, private_message.highest_staff_post_number, private_message.featured_link, private_message.reviewable_score, private_message.image_upload_id, private_message.slow_mode_seconds, private_message.bannered_until, private_message.external_id, private_message.visibility_reason_id, private_message.locale, private_message.og_image_upload_id
Index Cond: (private_message.id = reviewables.topic_id)
Filter: (((private_message.archetype)::text = 'private_message'::text) AND (NOT (ANY (private_message.id = (SubPlan 4).col1))))
Rows Removed by Filter: 1
Index Searches: 14513
Buffers: shared hit=53610 read=101589 dirtied=1 written=61
I/O Timings: shared read=32.962 write=0.356
SubPlan 4
-> Materialize (cost=792.25..140873.63 rows=1227210 width=4) (actual time=3.967..49.455 rows=2668.00 loops=13)
Output: topics_1.id
Storage: Memory Maximum Storage: 470kB
Buffers: shared hit=4306 read=92830 written=38
I/O Timings: shared read=8.159 write=0.227
-> Seq Scan on public.topics topics_1 (cost=792.25..129943.58 rows=1227210 width=4) (actual time=51.560..638.925 rows=10931.00 loops=1)
Output: topics_1.id
Filter: ((((topics_1.archetype)::text = 'private_message'::text) AND ((ANY (topics_1.id = (hashed SubPlan 1).col1)) OR (ANY (topics_1.id = (hashed SubPlan 2).col1)))) OR ((topics_1.subtype)::text = 'moderator_warning'::text) OR (ANY (topics_1.id = (hashed SubPlan 3).col1)))
Rows Removed by Filter: 1428444
Buffers: shared hit=4306 read=92830 written=38
I/O Timings: shared read=8.159 write=0.227
SubPlan 1
-> Index Only Scan using index_topic_allowed_users_on_user_id_and_topic_id on public.topic_allowed_users (cost=0.43..641.51 rows=4328 width=4) (actual time=9.643..11.475 rows=3503.00 loops=1)
Output: topic_allowed_users.topic_id
Index Cond: (topic_allowed_users.user_id = 18)
Heap Fetches: 293
Index Searches: 1
Buffers: shared hit=54 read=195 written=38
I/O Timings: shared read=0.564 write=0.227
SubPlan 2
-> Nested Loop (cost=0.71..128.02 rows=1 width=4) (actual time=9.318..11.005 rows=7742.00 loops=1)
Output: tg.topic_id
Buffers: shared hit=31 read=31
I/O Timings: shared read=0.111
-> Index Only Scan using index_group_users_on_user_id_and_group_id on public.group_users gu (cost=0.42..12.23 rows=2 width=4) (actual time=0.025..0.079 rows=11.00 loops=1)
Output: gu.user_id, gu.group_id
Index Cond: (gu.user_id = 18)
Heap Fetches: 11
Index Searches: 1
Buffers: shared hit=7 read=8
I/O Timings: shared read=0.032
-> Index Only Scan using index_topic_allowed_groups_on_group_id_and_topic_id on public.topic_allowed_groups tg (cost=0.29..44.66 rows=1324 width=8) (actual time=0.005..0.088 rows=703.82 loops=11)
Output: tg.group_id, tg.topic_id
Index Cond: (tg.group_id = gu.group_id)
Heap Fetches: 358
Index Searches: 11
Buffers: shared hit=24 read=23
I/O Timings: shared read=0.079
SubPlan 3
-> Index Scan using index_reviewables_on_status_and_type on public.reviewables reviewables_1 (cost=0.29..11.89 rows=2 width=4) (actual time=9.076..9.092 rows=5.00 loops=1)
Output: reviewables_1.topic_id
Index Cond: ((reviewables_1.status = 0) AND ((reviewables_1.type)::text = 'ReviewableFlaggedPost'::text))
Filter: (reviewables_1.score >= '0'::double precision)
Index Searches: 1
Buffers: shared hit=5
-> Hash (cost=10.00..10.00 rows=124 width=4) (actual time=0.078..0.078 rows=124.00 loops=1)
Output: categories.id
Buckets: 1024 Batches: 1 Memory Usage: 13kB
Buffers: shared hit=35
-> Index Only Scan using categories_pkey on public.categories (cost=0.14..10.00 rows=124 width=4) (actual time=0.014..0.057 rows=124.00 loops=1)
Output: categories.id
Heap Fetches: 36
Index Searches: 1
Buffers: shared hit=35
-> Hash (cost=1.05..1.05 rows=5 width=8) (actual time=0.018..0.019 rows=5.00 loops=1)
Output: category_moderation_groups.group_id, category_moderation_groups.category_id
Buckets: 1024 Batches: 1 Memory Usage: 9kB
Buffers: shared hit=1
-> Seq Scan on public.category_moderation_groups (cost=0.00..1.05 rows=5 width=8) (actual time=0.013..0.014 rows=5.00 loops=1)
Output: category_moderation_groups.group_id, category_moderation_groups.category_id
Buffers: shared hit=1
Planning:
Buffers: shared hit=119
Planning Time: 4.134 ms
JIT:
Functions: 406
Options: Inlining true, Optimization true, Expressions true, Deforming true
Timing: Generation 28.778 ms (Deform 8.210 ms), Inlining 331.978 ms, Optimization 1017.108 ms, Emission 969.572 ms, Total 2347.436 ms
Execution Time: 32947.799 ms
(270 rows)
실행 계획에 따르면 PostgreSQL은 가시성 체크를 위해 수백만 개의 게시물을 처리하고 있으며, 예상 행 수(7행)와 실제 행 수(516만 행) 사이에 큰 불일치가 있습니다.
쿼리와 실행 계획을 LLM에 입력하여 병목 현상을 식별하는 데 도움이 되는지 확인해 보았습니다. LLM은 Reviewable.viewable_by에서 OFFSET 0을 사용하여 수백만 개의 게시물을 스캔하는 대신 개별 reviewable 게시물에 대한 인덱스 조회를 유발하는 작은 변경 사항을 제안했습니다:
수정된 쿼리를 직접 테스트해 보았습니다(Discourse 코드는 변경하지 않았습니다). 실행 시간이 32.95초에서 1.64초로 줄었고, 동일한 15,150개의 reviewables가 반환되었습니다.
