Question 114402 in PostgreSQL Question posted in
The official documentation can be found here.

Postgresql – Bad query plan on different boolean values

I have a table which is used as a job queue. New rows are continuously being inserted in the table and the fetched rows are updated. There are JOINs in the query and Postgres uses Nested Loop join for it. Around 400 rows are picked up from this table at a time. reminders table has a column named active. If value of active is false or the condition is not present, only close to 400 rows are fetched in the outer loop else Postgres fetches more than 100K rows.

Any help in solving this is appreciated.

Indexes on tables:

reminders: (id, created_at), (namespace)
reminder_items: (queued_at, process_status), (id, created_at), (next_run_at, created_at, active) WHERE (queued_at IS NULL)
namespace: (name), (id), (active)

Query when reminders.active = false

EXPLAIN (ANALYZE TRUE, VERBOSE TRUE, COSTS TRUE, BUFFERS TRUE, TIMING TRUE) SELECT ri.*
        FROM reminder_items ri
        JOIN reminders r ON ri.reminder_id = r.id
        JOIN namespaces ns ON r.namespace = ns.Name
        AND ns.Active = TRUE
        AND r.active = FALSE
        AND r.deleted_at IS NULL
        AND ri.next_run_at > 1664471640
        AND ri.next_run_at < 1664475260
        AND ri.active = TRUE
        AND ri.queued_at IS NULL
        AND ri.created_at >= 1656633600
        AND ri.created_at < 1664475260
        AND r.created_at >= 1656633600
        AND r.created_at <= 1664475260
        LIMIT 400;

Query plan

QUERY PLAN
Limit  (cost=1001.42..6144.95 rows=400 width=163) (actual time=4.076..9.737 rows=400 loops=1)
"  Output: ri.id, ri.reminder_id, ri.queued_at, ri.config_id, ri.active, ri.process_status, ri.next_run_at, ri.total_count, ri.""interval"", ri.sent_count, ri.last_sent, ri.channels, ri.created_at, ri.updated_at, ri.deleted_at, ri.retry_count, ri.bucket_configuration_count"
  Buffers: shared hit=6312 read=15
  I/O Timings: read=3.038
  ->  Nested Loop  (cost=1001.42..427914.42 rows=33200 width=163) (actual time=4.075..9.692 rows=400 loops=1)
"        Output: ri.id, ri.reminder_id, ri.queued_at, ri.config_id, ri.active, ri.process_status, ri.next_run_at, ri.total_count, ri.""interval"", ri.sent_count, ri.last_sent, ri.channels, ri.created_at, ri.updated_at, ri.deleted_at, ri.retry_count, ri.bucket_configuration_count"
        Inner Unique: true
        Buffers: shared hit=6312 read=15
        I/O Timings: read=3.038
        ->  Gather  (cost=1001.14..426454.35 rows=33200 width=184) (actual time=4.056..9.348 rows=400 loops=1)
"              Output: ri.id, ri.reminder_id, ri.queued_at, ri.config_id, ri.active, ri.process_status, ri.next_run_at, ri.total_count, ri.""interval"", ri.sent_count, ri.last_sent, ri.channels, ri.created_at, ri.updated_at, ri.deleted_at, ri.retry_count, ri.bucket_configuration_count, r.namespace"
              Workers Planned: 2
              Workers Launched: 2
              Buffers: shared hit=6279 read=15
              I/O Timings: read=3.038
              ->  Nested Loop  (cost=1.14..422134.35 rows=13833 width=184) (actual time=1.201..4.366 rows=134 loops=3)
"                    Output: ri.id, ri.reminder_id, ri.queued_at, ri.config_id, ri.active, ri.process_status, ri.next_run_at, ri.total_count, ri.""interval"", ri.sent_count, ri.last_sent, ri.channels, ri.created_at, ri.updated_at, ri.deleted_at, ri.retry_count, ri.bucket_configuration_count, r.namespace"
                    Buffers: shared hit=6279 read=15
                    I/O Timings: read=3.038
                    Worker 0:  actual time=0.065..3.181 rows=135 loops=1
                      Buffers: shared hit=2070
                    Worker 1:  actual time=0.098..3.237 rows=135 loops=1
                      Buffers: shared hit=2101
                    ->  Parallel Append  (cost=0.57..65882.19 rows=13834 width=163) (actual time=0.153..0.629 rows=136 loops=3)
                          Buffers: shared hit=664 read=6
                          I/O Timings: read=1.001
                          Worker 0:  actual time=0.008..0.257 rows=135 loops=1
                            Buffers: shared hit=216
                          Worker 1:  actual time=0.041..0.296 rows=135 loops=1
                            Buffers: shared hit=240
                          ->  Parallel Index Scan using reminder_items_y2022m09_next_run_at_created_at_active_idx on public.reminder_items_y2022m09 ri_3  (cost=0.57..65579.34 rows=13786 width=163) (actual time=0.022..0.226 rows=123 loops=3)
"                                Output: ri_3.id, ri_3.reminder_id, ri_3.queued_at, ri_3.config_id, ri_3.active, ri_3.process_status, ri_3.next_run_at, ri_3.total_count, ri_3.""interval"", ri_3.sent_count, ri_3.last_sent, ri_3.channels, ri_3.created_at, ri_3.updated_at, ri_3.deleted_at, ri_3.retry_count, ri_3.bucket_configuration_count"
                                Index Cond: ((ri_3.next_run_at > 1664471640) AND (ri_3.next_run_at < 1664475260) AND (ri_3.created_at >= 1656633600) AND (ri_3.created_at < 1664475260) AND (ri_3.active = true))
                                Buffers: shared hit=609
                                Worker 0:  actual time=0.015..0.225 rows=130 loops=1
                                  Buffers: shared hit=210
                                Worker 1:  actual time=0.040..0.280 rows=135 loops=1
                                  Buffers: shared hit=240
                          ->  Parallel Index Scan using reminder_items_y2022m08_next_run_at_created_at_active_idx on public.reminder_items_y2022m08 ri_2  (cost=0.57..225.08 rows=66 width=163) (actual time=0.012..0.040 rows=16 loops=2)
"                                Output: ri_2.id, ri_2.reminder_id, ri_2.queued_at, ri_2.config_id, ri_2.active, ri_2.process_status, ri_2.next_run_at, ri_2.total_count, ri_2.""interval"", ri_2.sent_count, ri_2.last_sent, ri_2.channels, ri_2.created_at, ri_2.updated_at, ri_2.deleted_at, ri_2.retry_count, ri_2.bucket_configuration_count"
                                Index Cond: ((ri_2.next_run_at > 1664471640) AND (ri_2.next_run_at < 1664475260) AND (ri_2.created_at >= 1656633600) AND (ri_2.created_at < 1664475260) AND (ri_2.active = true))
                                Buffers: shared hit=38
                                Worker 0:  actual time=0.007..0.016 rows=5 loops=1
                                  Buffers: shared hit=6
                          ->  Parallel Index Scan using reminder_items_y2022m07_next_run_at_created_at_active_idx on public.reminder_items_y2022m07 ri_1  (cost=0.57..8.59 rows=1 width=163) (actual time=0.409..1.083 rows=6 loops=1)
"                                Output: ri_1.id, ri_1.reminder_id, ri_1.queued_at, ri_1.config_id, ri_1.active, ri_1.process_status, ri_1.next_run_at, ri_1.total_count, ri_1.""interval"", ri_1.sent_count, ri_1.last_sent, ri_1.channels, ri_1.created_at, ri_1.updated_at, ri_1.deleted_at, ri_1.retry_count, ri_1.bucket_configuration_count"
                                Index Cond: ((ri_1.next_run_at > 1664471640) AND (ri_1.next_run_at < 1664475260) AND (ri_1.created_at >= 1656633600) AND (ri_1.created_at < 1664475260) AND (ri_1.active = true))
                                Buffers: shared hit=17 read=6
                                I/O Timings: read=1.001
                    ->  Append  (cost=0.57..25.72 rows=3 width=36) (actual time=0.026..0.027 rows=1 loops=408)
                          Buffers: shared hit=5615 read=9
                          I/O Timings: read=2.037
                          Worker 0:  actual time=0.020..0.021 rows=1 loops=135
                            Buffers: shared hit=1854
                          Worker 1:  actual time=0.021..0.021 rows=1 loops=135
                            Buffers: shared hit=1861
                          ->  Index Scan using reminders_y2022m07_pkey on public.reminders_y2022m07 r_1  (cost=0.57..8.57 rows=1 width=36) (actual time=0.011..0.011 rows=0 loops=408)
"                                Output: r_1.id, r_1.namespace"
                                Index Cond: ((r_1.id = ri.reminder_id) AND (r_1.created_at >= 1656633600) AND (r_1.created_at <= 1664475260))
                                Filter: ((NOT r_1.active) AND (r_1.deleted_at IS NULL))
                                Rows Removed by Filter: 0
                                Buffers: shared hit=1634 read=9
                                I/O Timings: read=2.037
                                Worker 0:  actual time=0.005..0.005 rows=0 loops=135
                                  Buffers: shared hit=544
                                Worker 1:  actual time=0.005..0.005 rows=0 loops=135
                                  Buffers: shared hit=541
                          ->  Index Scan using reminders_y2022m08_pkey on public.reminders_y2022m08 r_2  (cost=0.57..8.57 rows=1 width=36) (actual time=0.006..0.006 rows=0 loops=408)
"                                Output: r_2.id, r_2.namespace"
                                Index Cond: ((r_2.id = ri.reminder_id) AND (r_2.created_at >= 1656633600) AND (r_2.created_at <= 1664475260))
                                Filter: ((NOT r_2.active) AND (r_2.deleted_at IS NULL))
                                Buffers: shared hit=1666
                                Worker 0:  actual time=0.005..0.005 rows=0 loops=135
                                  Buffers: shared hit=546
                                Worker 1:  actual time=0.005..0.005 rows=0 loops=135
                                  Buffers: shared hit=541
                          ->  Index Scan using reminders_y2022m09_pkey on public.reminders_y2022m09 r_3  (cost=0.57..8.57 rows=1 width=36) (actual time=0.009..0.010 rows=1 loops=408)
"                                Output: r_3.id, r_3.namespace"
                                Index Cond: ((r_3.id = ri.reminder_id) AND (r_3.created_at >= 1656633600) AND (r_3.created_at <= 1664475260))
                                Filter: ((NOT r_3.active) AND (r_3.deleted_at IS NULL))
                                Buffers: shared hit=2315
                                Worker 0:  actual time=0.009..0.010 rows=1 loops=135
                                  Buffers: shared hit=764
                                Worker 1:  actual time=0.009..0.010 rows=1 loops=135
                                  Buffers: shared hit=779
        ->  Memoize  (cost=0.28..6.54 rows=1 width=24) (actual time=0.000..0.000 rows=1 loops=400)
              Output: ns.name
              Cache Key: r.namespace
              Cache Mode: logical
              Hits: 389  Misses: 11  Evictions: 0  Overflows: 0  Memory Usage: 2kB
              Buffers: shared hit=33
              ->  Index Scan using namespaces_name_index on public.namespaces ns  (cost=0.27..6.53 rows=1 width=24) (actual time=0.004..0.004 rows=1 loops=11)
                    Output: ns.name
                    Index Cond: ((ns.name)::text = (r.namespace)::text)
                    Filter: ns.active
                    Buffers: shared hit=33
Query Identifier: -6499700351606025442
Planning:
  Buffers: shared hit=1251
Planning Time: 5.957 ms
Execution Time: 9.889 ms

Query when reminders.active = true

EXPLAIN (ANALYZE TRUE, VERBOSE TRUE, COSTS TRUE, BUFFERS TRUE, TIMING TRUE) SELECT ri.*
        FROM reminder_items ri
        JOIN reminders r ON ri.reminder_id = r.id
        JOIN namespaces ns ON r.namespace = ns.Name
        AND ns.Active = TRUE
        AND r.active = TRUE
        AND r.deleted_at IS NULL
        AND ri.next_run_at > 1664471917
        AND ri.next_run_at < 1664475537
        AND ri.active = TRUE
        AND ri.queued_at IS NULL
        AND ri.created_at >= 1656633600
        AND ri.created_at < 1664475537
        AND r.created_at >= 1656633600
        AND r.created_at <= 1664475537
        LIMIT 400;

Query plan

QUERY PLAN
Limit  (cost=1001.42..6144.87 rows=400 width=163) (actual time=1.432..958.027 rows=400 loops=1)
"  Output: ri.id, ri.reminder_id, ri.queued_at, ri.config_id, ri.active, ri.process_status, ri.next_run_at, ri.total_count, ri.""interval"", ri.sent_count, ri.last_sent, ri.channels, ri.created_at, ri.updated_at, ri.deleted_at, ri.retry_count, ri.bucket_configuration_count"
  Buffers: shared hit=1812210 read=59 dirtied=224
  I/O Timings: read=20.351
  ->  Nested Loop  (cost=1001.42..427946.40 rows=33203 width=163) (actual time=1.431..957.977 rows=400 loops=1)
"        Output: ri.id, ri.reminder_id, ri.queued_at, ri.config_id, ri.active, ri.process_status, ri.next_run_at, ri.total_count, ri.""interval"", ri.sent_count, ri.last_sent, ri.channels, ri.created_at, ri.updated_at, ri.deleted_at, ri.retry_count, ri.bucket_configuration_count"
        Inner Unique: true
        Buffers: shared hit=1812210 read=59 dirtied=224
        I/O Timings: read=20.351
        ->  Gather  (cost=1001.14..426486.25 rows=33203 width=184) (actual time=1.405..957.356 rows=402 loops=1)
"              Output: ri.id, ri.reminder_id, ri.queued_at, ri.config_id, ri.active, ri.process_status, ri.next_run_at, ri.total_count, ri.""interval"", ri.sent_count, ri.last_sent, ri.channels, ri.created_at, ri.updated_at, ri.deleted_at, ri.retry_count, ri.bucket_configuration_count, r.namespace"
              Workers Planned: 2
              Workers Launched: 2
              Buffers: shared hit=1812086 read=59 dirtied=223
              I/O Timings: read=20.351
              ->  Nested Loop  (cost=1.14..422165.95 rows=13835 width=184) (actual time=614.043..947.957 rows=135 loops=3)
"                    Output: ri.id, ri.reminder_id, ri.queued_at, ri.config_id, ri.active, ri.process_status, ri.next_run_at, ri.total_count, ri.""interval"", ri.sent_count, ri.last_sent, ri.channels, ri.created_at, ri.updated_at, ri.deleted_at, ri.retry_count, ri.bucket_configuration_count, r.namespace"
                    Buffers: shared hit=1812086 read=59 dirtied=223
                    I/O Timings: read=20.351
                    Worker 0:  actual time=918.780..937.869 rows=90 loops=1
                      Buffers: shared hit=579156 read=33 dirtied=56
                      I/O Timings: read=11.298
                    Worker 1:  actual time=922.574..951.608 rows=133 loops=1
                      Buffers: shared hit=587055 read=7 dirtied=104
                      I/O Timings: read=3.086
                    ->  Parallel Append  (cost=0.57..65887.94 rows=13835 width=163) (actual time=0.025..69.957 rows=41234 loops=3)
                          Buffers: shared hit=187091 read=5 dirtied=7
                          I/O Timings: read=1.373
                          Worker 0:  actual time=0.017..57.049 rows=39562 loops=1
                            Buffers: shared hit=59425
                          Worker 1:  actual time=0.014..80.984 rows=40034 loops=1
                            Buffers: shared hit=60806 read=2 dirtied=1
                            I/O Timings: read=0.915
                          ->  Parallel Index Scan using reminder_items_y2022m09_next_run_at_created_at_active_idx on public.reminder_items_y2022m09 ri_3  (cost=0.57..65585.09 rows=13787 width=163) (actual time=0.014..65.623 rows=41223 loops=3)
"                                Output: ri_3.id, ri_3.reminder_id, ri_3.queued_at, ri_3.config_id, ri_3.active, ri_3.process_status, ri_3.next_run_at, ri_3.total_count, ri_3.""interval"", ri_3.sent_count, ri_3.last_sent, ri_3.channels, ri_3.created_at, ri_3.updated_at, ri_3.deleted_at, ri_3.retry_count, ri_3.bucket_configuration_count"
                                Index Cond: ((ri_3.next_run_at > 1664471917) AND (ri_3.next_run_at < 1664475537) AND (ri_3.created_at >= 1656633600) AND (ri_3.created_at < 1664475537) AND (ri_3.active = true))
                                Buffers: shared hit=187041 read=3 dirtied=7
                                I/O Timings: read=1.344
                                Worker 0:  actual time=0.017..53.025 rows=39562 loops=1
                                  Buffers: shared hit=59425
                                Worker 1:  actual time=0.013..76.860 rows=40034 loops=1
                                  Buffers: shared hit=60806 read=2 dirtied=1
                                  I/O Timings: read=0.915
                          ->  Parallel Index Scan using reminder_items_y2022m08_next_run_at_created_at_active_idx on public.reminder_items_y2022m08 ri_2  (cost=0.57..225.08 rows=66 width=163) (actual time=0.014..0.068 rows=30 loops=1)
"                                Output: ri_2.id, ri_2.reminder_id, ri_2.queued_at, ri_2.config_id, ri_2.active, ri_2.process_status, ri_2.next_run_at, ri_2.total_count, ri_2.""interval"", ri_2.sent_count, ri_2.last_sent, ri_2.channels, ri_2.created_at, ri_2.updated_at, ri_2.deleted_at, ri_2.retry_count, ri_2.bucket_configuration_count"
                                Index Cond: ((ri_2.next_run_at > 1664471917) AND (ri_2.next_run_at < 1664475537) AND (ri_2.created_at >= 1656633600) AND (ri_2.created_at < 1664475537) AND (ri_2.active = true))
                                Buffers: shared hit=36
                          ->  Parallel Index Scan using reminder_items_y2022m07_next_run_at_created_at_active_idx on public.reminder_items_y2022m07 ri_1  (cost=0.57..8.59 rows=1 width=163) (actual time=0.045..0.083 rows=3 loops=1)
"                                Output: ri_1.id, ri_1.reminder_id, ri_1.queued_at, ri_1.config_id, ri_1.active, ri_1.process_status, ri_1.next_run_at, ri_1.total_count, ri_1.""interval"", ri_1.sent_count, ri_1.last_sent, ri_1.channels, ri_1.created_at, ri_1.updated_at, ri_1.deleted_at, ri_1.retry_count, ri_1.bucket_configuration_count"
                                Index Cond: ((ri_1.next_run_at > 1664471917) AND (ri_1.next_run_at < 1664475537) AND (ri_1.created_at >= 1656633600) AND (ri_1.created_at < 1664475537) AND (ri_1.active = true))
                                Buffers: shared hit=14 read=2
                                I/O Timings: read=0.029
                    ->  Append  (cost=0.57..25.72 rows=3 width=36) (actual time=0.021..0.021 rows=0 loops=123701)
                          Buffers: shared hit=1624995 read=54 dirtied=216
                          I/O Timings: read=18.978
                          Worker 0:  actual time=0.022..0.022 rows=0 loops=39562
                            Buffers: shared hit=519731 read=33 dirtied=56
                            I/O Timings: read=11.298
                          Worker 1:  actual time=0.021..0.021 rows=0 loops=40034
                            Buffers: shared hit=526249 read=5 dirtied=103
                            I/O Timings: read=2.171
                          ->  Index Scan using reminders_y2022m07_pkey on public.reminders_y2022m07 r_1  (cost=0.57..8.57 rows=1 width=36) (actual time=0.005..0.005 rows=0 loops=123701)
"                                Output: r_1.id, r_1.namespace"
                                Index Cond: ((r_1.id = ri.reminder_id) AND (r_1.created_at >= 1656633600) AND (r_1.created_at <= 1664475537))
                                Filter: (r_1.active AND (r_1.deleted_at IS NULL))
                                Buffers: shared hit=494810 read=5
                                I/O Timings: read=1.160
                                Worker 0:  actual time=0.005..0.005 rows=0 loops=39562
                                  Buffers: shared hit=158252
                                Worker 1:  actual time=0.006..0.006 rows=0 loops=40034
                                  Buffers: shared hit=160140
                          ->  Index Scan using reminders_y2022m08_pkey on public.reminders_y2022m08 r_2  (cost=0.57..8.57 rows=1 width=36) (actual time=0.005..0.005 rows=0 loops=123701)
"                                Output: r_2.id, r_2.namespace"
                                Index Cond: ((r_2.id = ri.reminder_id) AND (r_2.created_at >= 1656633600) AND (r_2.created_at <= 1664475537))
                                Filter: (r_2.active AND (r_2.deleted_at IS NULL))
                                Rows Removed by Filter: 0
                                Buffers: shared hit=494836
                                Worker 0:  actual time=0.005..0.005 rows=0 loops=39562
                                  Buffers: shared hit=158249
                                Worker 1:  actual time=0.005..0.005 rows=0 loops=40034
                                  Buffers: shared hit=160137
                          ->  Index Scan using reminders_y2022m09_pkey on public.reminders_y2022m09 r_3  (cost=0.57..8.57 rows=1 width=36) (actual time=0.010..0.010 rows=0 loops=123701)
"                                Output: r_3.id, r_3.namespace"
                                Index Cond: ((r_3.id = ri.reminder_id) AND (r_3.created_at >= 1656633600) AND (r_3.created_at <= 1664475537))
                                Filter: (r_3.active AND (r_3.deleted_at IS NULL))
                                Rows Removed by Filter: 1
                                Buffers: shared hit=635349 read=49 dirtied=216
                                I/O Timings: read=17.817
                                Worker 0:  actual time=0.010..0.010 rows=0 loops=39562
                                  Buffers: shared hit=203230 read=33 dirtied=56
                                  I/O Timings: read=11.298
                                Worker 1:  actual time=0.010..0.010 rows=0 loops=40034
                                  Buffers: shared hit=205972 read=5 dirtied=103
                                  I/O Timings: read=2.171
        ->  Memoize  (cost=0.28..6.54 rows=1 width=24) (actual time=0.001..0.001 rows=1 loops=402)
              Output: ns.name
              Cache Key: r.namespace
              Cache Mode: logical
              Hits: 361  Misses: 41  Evictions: 0  Overflows: 0  Memory Usage: 6kB
              Buffers: shared hit=124 dirtied=1
              ->  Index Scan using namespaces_name_index on public.namespaces ns  (cost=0.27..6.53 rows=1 width=24) (actual time=0.005..0.005 rows=1 loops=41)
                    Output: ns.name
                    Index Cond: ((ns.name)::text = (r.namespace)::text)
                    Filter: ns.active
                    Rows Removed by Filter: 0
                    Buffers: shared hit=124 dirtied=1
Query Identifier: -6499700351606025442
Planning:
  Buffers: shared hit=1251
Planning Time: 6.272 ms
Execution Time: 958.219 ms

Edit: Query plan after setting max_parallel_workers_per_gather = 0

QUERY PLAN
Limit  (cost=1.42..11118.93 rows=400 width=163) (actual time=0.640..3188.959 rows=400 loops=1)
"  Output: ri.id, ri.reminder_id, ri.queued_at, ri.config_id, ri.active, ri.process_status, ri.next_run_at, ri.total_count, ri.""interval"", ri.sent_count, ri.last_sent, ri.channels, ri.created_at, ri.updated_at, ri.deleted_at, ri.retry_count, ri.bucket_configuration_count"
  Buffers: shared hit=2442983 read=107 dirtied=39
  I/O Timings: read=14.735
  ->  Nested Loop  (cost=1.42..921448.55 rows=33153 width=163) (actual time=0.639..3188.902 rows=400 loops=1)
"        Output: ri.id, ri.reminder_id, ri.queued_at, ri.config_id, ri.active, ri.process_status, ri.next_run_at, ri.total_count, ri.""interval"", ri.sent_count, ri.last_sent, ri.channels, ri.created_at, ri.updated_at, ri.deleted_at, ri.retry_count, ri.bucket_configuration_count"
        Inner Unique: true
        Buffers: shared hit=2442983 read=107 dirtied=39
        I/O Timings: read=14.735
        ->  Nested Loop  (cost=1.14..919989.66 rows=33153 width=184) (actual time=0.616..3188.279 rows=402 loops=1)
"              Output: ri.id, ri.reminder_id, ri.queued_at, ri.config_id, ri.active, ri.process_status, ri.next_run_at, ri.total_count, ri.""interval"", ri.sent_count, ri.last_sent, ri.channels, ri.created_at, ri.updated_at, ri.deleted_at, ri.retry_count, ri.bucket_configuration_count, r.namespace"
              Buffers: shared hit=2442868 read=107 dirtied=39
              I/O Timings: read=14.735
              ->  Append  (cost=0.57..66223.67 rows=33153 width=163) (actual time=0.078..232.043 rows=167795 loops=1)
                    Buffers: shared hit=235522 read=45 dirtied=20
                    I/O Timings: read=1.104
                    ->  Index Scan using reminder_items_y2022m07_next_run_at_created_at_active_idx on public.reminder_items_y2022m07 ri_1  (cost=0.57..8.60 rows=1 width=163) (actual time=0.078..0.221 rows=16 loops=1)
"                          Output: ri_1.id, ri_1.reminder_id, ri_1.queued_at, ri_1.config_id, ri_1.active, ri_1.process_status, ri_1.next_run_at, ri_1.total_count, ri_1.""interval"", ri_1.sent_count, ri_1.last_sent, ri_1.channels, ri_1.created_at, ri_1.updated_at, ri_1.deleted_at, ri_1.retry_count, ri_1.bucket_configuration_count"
                          Index Cond: ((ri_1.next_run_at > 1664507457) AND (ri_1.next_run_at < 1664511077) AND (ri_1.created_at >= 1656633600) AND (ri_1.created_at < 1664511077) AND (ri_1.active = true))
                          Buffers: shared hit=24 read=11
                          I/O Timings: read=0.106
                    ->  Index Scan using reminder_items_y2022m08_next_run_at_created_at_active_idx on public.reminder_items_y2022m08 ri_2  (cost=0.57..225.55 rows=113 width=163) (actual time=0.019..0.446 rows=2 loops=1)
"                          Output: ri_2.id, ri_2.reminder_id, ri_2.queued_at, ri_2.config_id, ri_2.active, ri_2.process_status, ri_2.next_run_at, ri_2.total_count, ri_2.""interval"", ri_2.sent_count, ri_2.last_sent, ri_2.channels, ri_2.created_at, ri_2.updated_at, ri_2.deleted_at, ri_2.retry_count, ri_2.bucket_configuration_count"
                          Index Cond: ((ri_2.next_run_at > 1664507457) AND (ri_2.next_run_at < 1664511077) AND (ri_2.created_at >= 1656633600) AND (ri_2.created_at < 1664511077) AND (ri_2.active = true))
                          Buffers: shared hit=5 read=1
                          I/O Timings: read=0.424
                    ->  Index Scan using reminder_items_y2022m09_next_run_at_created_at_active_idx on public.reminder_items_y2022m09 ri_3  (cost=0.57..65823.76 rows=33039 width=163) (actual time=0.032..213.454 rows=167777 loops=1)
"                          Output: ri_3.id, ri_3.reminder_id, ri_3.queued_at, ri_3.config_id, ri_3.active, ri_3.process_status, ri_3.next_run_at, ri_3.total_count, ri_3.""interval"", ri_3.sent_count, ri_3.last_sent, ri_3.channels, ri_3.created_at, ri_3.updated_at, ri_3.deleted_at, ri_3.retry_count, ri_3.bucket_configuration_count"
                          Index Cond: ((ri_3.next_run_at > 1664507457) AND (ri_3.next_run_at < 1664511077) AND (ri_3.created_at >= 1656633600) AND (ri_3.created_at < 1664511077) AND (ri_3.active = true))
                          Buffers: shared hit=235493 read=33 dirtied=20
                          I/O Timings: read=0.575
              ->  Append  (cost=0.57..25.72 rows=3 width=36) (actual time=0.017..0.017 rows=0 loops=167795)
                    Buffers: shared hit=2207346 read=62 dirtied=19
                    I/O Timings: read=13.631
                    ->  Index Scan using reminders_y2022m07_pkey on public.reminders_y2022m07 r_1  (cost=0.57..8.57 rows=1 width=36) (actual time=0.004..0.004 rows=0 loops=167795)
"                          Output: r_1.id, r_1.namespace"
                          Index Cond: ((r_1.id = ri.reminder_id) AND (r_1.created_at >= 1656633600) AND (r_1.created_at <= 1664511077))
                          Filter: (r_1.active AND (r_1.deleted_at IS NULL))
                          Buffers: shared hit=671170 read=26
                          I/O Timings: read=5.753
                    ->  Index Scan using reminders_y2022m08_pkey on public.reminders_y2022m08 r_2  (cost=0.57..8.57 rows=1 width=36) (actual time=0.004..0.004 rows=0 loops=167795)
"                          Output: r_2.id, r_2.namespace"
                          Index Cond: ((r_2.id = ri.reminder_id) AND (r_2.created_at >= 1656633600) AND (r_2.created_at <= 1664511077))
                          Filter: (r_2.active AND (r_2.deleted_at IS NULL))
                          Rows Removed by Filter: 0
                          Buffers: shared hit=671180 read=2
                          I/O Timings: read=0.662
                    ->  Index Scan using reminders_y2022m09_pkey on public.reminders_y2022m09 r_3  (cost=0.57..8.57 rows=1 width=36) (actual time=0.008..0.008 rows=0 loops=167795)
"                          Output: r_3.id, r_3.namespace"
                          Index Cond: ((r_3.id = ri.reminder_id) AND (r_3.created_at >= 1656633600) AND (r_3.created_at <= 1664511077))
                          Filter: (r_3.active AND (r_3.deleted_at IS NULL))
                          Rows Removed by Filter: 1
                          Buffers: shared hit=864996 read=34 dirtied=19
                          I/O Timings: read=7.216
        ->  Memoize  (cost=0.28..6.54 rows=1 width=24) (actual time=0.001..0.001 rows=1 loops=402)
              Output: ns.name
              Cache Key: r.namespace
              Cache Mode: logical
              Hits: 364  Misses: 38  Evictions: 0  Overflows: 0  Memory Usage: 6kB
              Buffers: shared hit=115
              ->  Index Scan using namespaces_name_index on public.namespaces ns  (cost=0.27..6.53 rows=1 width=24) (actual time=0.005..0.005 rows=1 loops=38)
                    Output: ns.name
                    Index Cond: ((ns.name)::text = (r.namespace)::text)
                    Filter: ns.active
                    Rows Removed by Filter: 0
                    Buffers: shared hit=115
Query Identifier: -6499700351606025442
Planning:
  Buffers: shared hit=1251
Planning Time: 6.039 ms
Execution Time: 3189.116 ms
Tags:

2

Answers


  1. 0

    Your query has these ON filters on reminder_items.

     ...    AND ri.next_run_at > 1664471640
        AND ri.next_run_at < 1664475260
        AND ri.active = TRUE
        AND ri.queued_at IS NULL
        AND ri.created_at >= 1656633600
        AND ri.created_at < 1664475260 ...

    Due to the way BTREE indexes work, you should create a compound index on that table starting with the columns where you match for equality, then a single column where you match on a range. This might work.

    CREATE INDEX active_queued_created ON reminder_items
        (active, queued_at, next_run);

    The database query engine can random-access that BTREE index to the first eligible row, then scan it sequentially to the last row. That helps performance.

    Now, your ON filters do range matches on two columns, created_at and next_run. BTREE indexes can only exploit one range match, not two. Therefore you need to choose whether to put next_run or created_at in the index. You should choose the most selective of those two columns. I chose next_run because your range for that is narrower than it is for created_at.

    You should try adding the index I suggest, then examine your EXPLAIN output again to figure out what indexes might help on other tables.

    And, by the way, when you use LIMIT without ORDER BY, you’re telling the query engine "give me whatever 400 rows you want" — the choice of rows won’t be deterministic.

    Login or Signup to reply.
  2. 0

    The reason for the problem is pretty clear, but the solution is not.

    It is scanning the reminder_items using the index, in that index’s order. When doing it, the first rows it encounter all find join partners where reminder.active is false, so the LIMIT kicks and it gets to stop early. But few of those early rows find join partners meeting reminder.active, so when testing for that condition it has to keep going for a long time before it catches its LIMIT. This could be because reminder.active=true is very rare, or it could be that they are common but are all bunched up at one end of the next_run_at "value space".

    One thing you can try is adding an ORDER BY next_run_at DESC to the query. This might cause it scan that index in the other direction, where it might encounter its LIMIT sooner. But you mentioned this being a queue. If what it does with the rows it finds is to toggle off the corresponding value of reminder.active, then this solution wouldn’t last for long, as then it would soon become depleted of matching rows when starting from that direction, too.

    Another thing to try would be create index on reminder (active, created_at). That might cause the planner to invert the nested loop, so it scans reminders as outer and reminder_items on the inner side. This could be particularly effective if reminder.active=true is rare, as this proposed index would provide an effective way to efficiently skip the inactive ones.

    A more general solution might be to increase the LIMIT. Skipping over the filtered out values would still be a lot of work, but that work would be amortized over a larger number of fetched rows. What is driving the current choice of LIMIT?

    Login or Signup to reply.
Please signup or login to give your own answer.

Back To Top
Search