特定のモデレーターではレビューセクションで500サーバーエラーが発生します

あるモデレーターがレビュー(Review)セクションで常にサーバーエラーメッセージに遭遇しています。これは、生成されたクエリのいずれかが通常の30秒のタイムアウトよりもはるかに長い時間がかかるためであるようです。

アクションはこれだけです:/review に移動し、Status ドロップダウンを Everything に変更する(ただし、他のオプションでも同じ問題が発生します)。他のスタッフ全員にとっては、同じアクションは一瞬で完了します。このモデレーターは最も活発なメンバーであり、これが問題を引き起こす要因になっているようです。

Error message

:frowning:
Server Error
while trying to load /review?priority=low&status=all&sort_order=created_at&additional_filters=%7B%7D
Error code: 500 error

生成されたクエリの形式:

Trouble query
SELECT COUNT(*) FROM "reviewables" LEFT OUTER JOIN "categories" ON "categories"."id" = "reviewables"."category_id" LEFT OUTER JOIN "category_moderation_groups" ON "category_moderation_groups"."category_id" = "categories"."id" WHERE ((reviewables.reviewable_by_moderator AND TRUE) OR (category_moderation_groups.group_id IN (2, 3, 10, 11, 12, 13, 14, 41, 42, 43, 45))) AND (reviewables.category_id IS NULL OR reviewables.category_id IN (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)) AND (NOT EXISTS (
          SELECT 1
          FROM topics private_message
          WHERE private_message.id = reviewables.topic_id
            AND private_message.archetype = 'private_message'
            AND private_message.id NOT IN (SELECT "topics"."id" FROM "topics" WHERE ("topics"."archetype" = 'private_message' AND (topics.id IN (SELECT topic_id
        FROM topic_allowed_users
        WHERE user_id = 12345
        )
              OR topics.id IN (SELECT tg.topic_id
        FROM topic_allowed_groups tg
        JOIN group_users gu ON gu.user_id = 12345 AND gu.group_id = tg.group_id
        )) OR topics.subtype = 'moderator_warning'
        OR topics.id IN (SELECT "reviewables"."topic_id" FROM "reviewables" WHERE "reviewables"."type" = 'ReviewableFlaggedPost' AND "reviewables"."status" = 0 AND (score >= 0.0))
        ))
        )
        ) AND (NOT EXISTS (
          SELECT 1 FROM posts reviewable_target
          WHERE reviewables.target_type = 'Post'
            AND reviewable_target.id = reviewables.target_id
            AND NOT EXISTS (SELECT "posts"."id" FROM "posts" WHERE (posts.post_type IN (1, 2, 3, 4)) AND "posts"."topic_id" IN (SELECT "topics"."id" FROM "topics" LEFT OUTER JOIN "shared_drafts" ON "shared_drafts"."topic_id" = "topics"."id" WHERE "shared_drafts"."id" IS NULL AND ("topics"."archetype" != 'private_message' AND (topics.category_id IS NULL OR topics.category_id IN (SELECT id FROM categories WHERE NOT read_restricted OR id IN (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))) OR "topics"."archetype" = 'private_message' AND "topics"."archetype" = 'private_message' AND ((topics.id IN (SELECT topic_id
        FROM topic_allowed_users
        WHERE user_id = 12345
        )
              OR topics.id IN (SELECT tg.topic_id
        FROM topic_allowed_groups tg
        JOIN group_users gu ON gu.user_id = 12345 AND gu.group_id = tg.group_id
        )) OR topics.subtype = 'moderator_warning'
        OR topics.id IN (SELECT "reviewables"."topic_id" FROM "reviewables" WHERE "reviewables"."type" = 'ReviewableFlaggedPost' AND "reviewables"."status" = 0 AND (score >= 0.0))
        ))) AND (posts.id = reviewable_target.id))
        )
        ) AND "reviewables"."type" IN ('ReviewableFlaggedPost', 'ReviewableQueuedPost', 'ReviewableUser', 'ReviewablePost');

 count
-------
 15147
(1 row)

Time: 78545.972 ms (01:18.546)

user_id を自分自身(管理者)のものに変更しても、有意に高速になるわけではなく、私は /review で同じアクションを問題なく実行できるため、コードパスが同じではないと推測しています。

これは Discourse: v2026.7.3 +24 の環境です。

/logs に関連するものはありませんか?情報が少ないと、_診断_するのが少し難しいです :face_with_monocle:

そうなんです。この現象が発生するたびにログエントリは記録されますが、おそらく30秒のタイムアウトを指しているだけだと思います。

ログ:

Pitchfork worker is about to timeout, dumping backtrace for main thread /var/www/discourse/vendor/bundle/ruby/3.4.0/gems/rack-mini-profiler-4.0.1/lib/patches/db/pg/alias_method.rb:109:in 'PG::Connecti

情報:

Pitchfork worker is about to timeout, dumping backtrace for main thread
/var/www/discourse/vendor/bundle/ruby/3.4.0/gems/rack-mini-profiler-4.0.1/lib/patches/db/pg/alias_method.rb:109:in 'PG::Connection#exec'
/var/www/discourse/vendor/bundle/ruby/3.4.0/gems/rack-mini-profiler-4.0.1/lib/patches/db/pg/alias_method.rb:109:in 'PG::Connection#async_exec'
/var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.5/lib/active_record/connection_adapters/postgresql/database_statements.rb:167:in 'ActiveRecord::ConnectionAdapters::PostgreSQL::DatabaseStatements#perform_query'
/var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.5/lib/active_record/connection_adapters/abstract/database_statements.rb:556:in 'block (2 levels) in ActiveRecord::ConnectionAdapters::DatabaseStatements#raw_execute'
/var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.5/lib/active_record/connection_adapters/abstract_adapter.rb:1022:in 'block in ActiveRecord::ConnectionAdapters::AbstractAdapter#with_raw_connection'
/var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.5/lib/active_support/concurrency/null_lock.rb:9:in 'ActiveSupport::Concurrency::NullLock#synchronize'
/var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.5/lib/active_record/connection_adapters/abstract_adapter.rb:991:in 'ActiveRecord::ConnectionAdapters::AbstractAdapter#with_raw_connection'
/var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.5/lib/active_record/connection_adapters/abstract/database_statements.rb:555:in 'block in ActiveRecord::ConnectionAdapters::DatabaseStatements#raw_execute'
/var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.5/lib/active_support/notifications/instrumenter.rb:58:in 'ActiveSupport::Notifications::Instrumenter#instrument'
/var/www/discourse/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.5/lib/active_record/connection_adapters/abstract_adapter.rb:1142:in 'ActiveRecord::ConnectionAdapters::AbstractAdapter#log'
/var/www...

バックトレース:

activesupport-8.0.5/lib/active_support/broadcast_logger.rb:218:in 'block in ActiveSupport::BroadcastLogger#dispatch' 
activesupport-8.0.5/lib/active_support/broadcast_logger.rb:217:in 'Array#map' 
activesupport-8.0.5/lib/active_support/broadcast_logger.rb:217:in 'ActiveSupport::BroadcastLogger#dispatch' 
activesupport-8.0.5/lib/active_support/broadcast_logger.rb:129:in 'ActiveSupport::BroadcastLogger#error' 
config/pitchfork.conf.rb:178:in 'block in Pitchfork::Configurator#load'
pitchfork-0.18.2/lib/pitchfork/http_server.rb:55:in 'Pitchfork::HttpServer::TimeoutHandler#call' 
pitchfork-0.18.2/lib/pitchfork/soft_timeout.rb:49:in 'block in Pitchfork::SoftTimeout::Request#interrupt' 
pitchfork-0.18.2/lib/pitchfork/soft_timeout.rb:46:in 'Thread::Mutex#synchronize' 
pitchfork-0.18.2/lib/pitchfork/soft_timeout.rb:46:in 'Pitchfork::SoftTimeout::Request#interrupt' 
pitchfork-0.18.2/lib/pitchfork/soft_timeout.rb:94:in 'block (2 levels) in Pitchfork::SoftTimeout#create_timeout_thread' 
pitchfork-0.18.2/lib/pitchfork/soft_timeout.rb:93:in 'Array#each' 
pitchfork-0.18.2/lib/pitchfork/soft_timeout.rb:93:in 'block in Pitchfork::SoftTimeout#create_timeout_thread' 

他に提供できる情報はありますか?

Perhaps this can be of help:

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)

The plan shows postgresql processing millions of posts for the visibility check, with a large mismatch between estimated and actual rows (7 estimated vs 5.16 million actual).

I fed the query and execution plan to an LLM to see if it could help identify the bottleneck. It suggested a small change that causes indexed lookups for the individual reviewable posts instead of scanning millions of posts, through the use of OFFSET 0 in Reviewable.viewable_by:

result.where(<<~SQL)
  NOT EXISTS (
    SELECT 1 FROM posts reviewable_target
    WHERE reviewables.target_type = 'Post'
      AND reviewable_target.id = reviewables.target_id
      AND NOT EXISTS (#{visible_target.to_sql})
+   OFFSET 0
  )
SQL

I tested the modified query directly (haven’t changed Discourse), and the execution time dropped from 32.95s to 1.64s, returning the exact same count of 15,150 reviewables.

I’m not very familiar with postgresql, but as I understand it, OFFSET 0 is a postgresql planner workaround, so maybe not necessarily the right permanent fix, but perhaps this helps pinpoint the issue.