Query execution plan
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)
Der Plan zeigt, dass PostgreSQL Millionen von Beiträgen für die Sichtbarkeitsprüfung verarbeitet, wobei eine große Abweichung zwischen geschätzten und tatsächlichen Zeilen besteht (7 geschätzt vs. 5,16 Millionen tatsächlich).
Ich habe die Abfrage und den Ausführungsplan einem LLM vorgelegt, um zu sehen, ob es dabei helfen kann, die Engstelle zu identifizieren. Es schlug eine kleine Änderung vor, die durch die Verwendung von OFFSET 0 in Reviewable.viewable_by indexierte Abfragen für die einzelnen überprüfbaren Beiträge anstelle des Scannens von Millionen von Beiträgen bewirkt:
Ich habe die modifizierte Abfrage direkt getestet (Discourse wurde nicht geändert), und die Ausführungszeit sank von 32,95 s auf 1,64 s, wobei die exakt gleiche Anzahl von 15.150 überprüfbaren Einträgen zurückgegeben wurde.
Ich kenne mich nicht sehr gut mit PostgreSQL aus, aber soweit ich das verstehe, ist OFFSET 0 ein Workaround für den PostgreSQL-Planer, also vielleicht nicht unbedingt die richtige dauerhafte Lösung, aber vielleicht hilft es dabei, das Problem einzugrenzen.
