BUG #13511: View containing correlated subquery with MAX() produces slow plan - Mailing list pgsql-bugs

The following bug has been logged on the website:

Bug reference:      13511
Logged by:          Steven Grimm
Email address:      koreth@gmail.com
PostgreSQL version: 9.4.4
Operating system:   Ubuntu Linux (Heroku PostgreSQL)
Description:

Not sure if this qualifies as a bug, but I found a situation where replacing
part of a query with a semantically equivalent implementation produced a
huge performance gain.

My database has a table where we set new values nondestructively by
appending new rows with the same object ID and the one with the most recent
timestamp is considered current. We had the following view to give us the
most recent values:

CREATE VIEW sobj_current_field_values AS
SELECT object_id, field_id, audit_id, created_time, is_deleted, value
FROM sobj_field_values fv
WHERE fv.created_time = (
    SELECT MAX(created_time)
    FROM sobj_field_values fvmax
    WHERE fv.object_id = fvmax.object_id
    AND fv.field_id = fvmax.field_id
);

The table in question has a primary key of (object_id, field_id,
created_time).

When we joined with this view in a complex query, the optimizer produced a
plan with a lot of sequential scans:

 Nested Loop Left Join  (cost=0.00..112996.18 rows=67 width=264) (actual
time=12.711..2318.208 rows=13333 loops=1)
   Join Filter: (fv.object_id = recipient_ids.recipient_id)
   Rows Removed by Join Filter: 2652869
   Filter: (((fsv.form_submission_id IS NOT NULL) AND (fsv.recipient_id IS
NOT NULL)) OR (recipient_ids.recipient_id IS NOT NULL))
   ->  Nested Loop  (cost=0.00..112791.69 rows=67 width=248) (actual
time=12.690..1928.759 rows=13333 loops=1)
         Join Filter: (fv.object_id = sobj_object_classes.object_id)
         Rows Removed by Join Filter: 5293201
         ->  Seq Scan on sobj_object_classes  (cost=0.00..6.98 rows=398
width=20) (actual time=0.009..0.311 rows=398 loops=1)
         ->  Materialize  (cost=0.00..112384.89 rows=67 width=228) (actual
time=0.035..3.606 rows=13333 loops=398)
               ->  Nested Loop  (cost=0.00..112384.56 rows=67 width=228)
(actual time=12.657..620.760 rows=13333 loops=1)
                     Join Filter: (fv.field_id = sobj_fields.field_id)
                     Rows Removed by Join Filter: 879978
                     ->  Nested Loop Left Join  (cost=0.00..112315.38
rows=67 width=164) (actual time=12.596..484.357 rows=13333 loops=1)
                           Join Filter: (fv.object_id =
fsv.form_submission_id)
                           Rows Removed by Join Filter: 2640332
                           ->  Seq Scan on sobj_field_values fv
(cost=0.00..111205.89 rows=67 width=51) (actual time=0.030..48.523
rows=13333 loops=1)
                                 Filter: ((NOT is_deleted) AND (created_time
= (SubPlan 2)))
                                 SubPlan 2
                                   ->  Result  (cost=8.31..8.32 rows=1
width=0) (actual time=0.003..0.003 rows=1 loops=13333)
                                         InitPlan 1 (returns $2)
                                           ->  Limit  (cost=0.29..8.31
rows=1 width=8) (actual time=0.002..0.002 rows=1 loops=13333)
                                                 ->  Index Only Scan
Backward using sobj_field_values_pkey on sobj_field_values fvmax
(cost=0.29..8.31 rows=1 width=8) (actual time=0.002..0.002 rows=1
loops=13333)
                                                       Index Cond:
((object_id = fv.object_id) AND (field_id = fv.field_id) AND (created_time
IS NOT NULL))
                                                       Heap Fetches: 13333
                           ->  Materialize  (cost=0.00..1108.49 rows=1
width=113) (actual time=0.000..0.013 rows=199 loops=13333)
                                 ->  Nested Loop  (cost=0.00..1108.49 rows=1
width=113) (actual time=0.063..12.334 rows=199 loops=1)
                                       Join Filter: (fsv.form_submission_id
= form_submission_ids.form_submission_id)
                                       Rows Removed by Join Filter: 39402
                                       ->  Nested Loop  (cost=0.00..1101.01
rows=1 width=71) (actual time=0.055..4.961 rows=199 loops=1)
                                             Join Filter: (fsv.form_name =
form_definitions.form_name)
                                             ->  Seq Scan on
form_submission_versions fsv  (cost=0.00..1099.99 rows=1 width=64) (actual
time=0.049..4.619 rows=199 loops=1)
                                                   Filter: ((recipient_id IS
NOT NULL) AND (version = (SubPlan 3)))
                                                   SubPlan 3
                                                     ->  Aggregate
(cost=5.49..5.50 rows=1 width=8) (actual time=0.022..0.022 rows=1
loops=199)
                                                           ->  Seq Scan on
form_submission_versions fsvmax  (cost=0.00..5.49 rows=1 width=8) (actual
time=0.011..0.021 rows=1 loops=199)
                                                                 Filter:
(fsv.form_submission_id = form_submission_id)
                                                                 Rows
Removed by Filter: 198
                                             ->  Seq Scan on
form_definitions  (cost=0.00..1.01 rows=1 width=23) (actual
time=0.000..0.000 rows=1 loops=199)
                                       ->  Seq Scan on form_submission_ids
(cost=0.00..4.99 rows=199 width=58) (actual time=0.002..0.017 rows=199
loops=199)
                     ->  Materialize  (cost=0.00..2.00 rows=67 width=64)
(actual time=0.000..0.004 rows=67 loops=13333)
                           ->  Seq Scan on sobj_fields  (cost=0.00..1.67
rows=67 width=64) (actual time=0.003..0.009 rows=67 loops=1)
   ->  Materialize  (cost=0.00..4.99 rows=199 width=16) (actual
time=0.000..0.011 rows=199 loops=13333)
         ->  Seq Scan on recipient_ids  (cost=0.00..3.99 rows=199 width=16)
(actual time=0.007..0.028 rows=199 loops=1)
 Planning time: 1.894 ms
 Execution time: 2334.938 ms
(45 rows)

When I set enable_seqscan to off, the execution time went from 2334ms to
83ms and the plan looked substantially different. In particular, it looked
like it had started using the primary key to evaluate the view:

 Merge Left Join  (cost=1.26..113888.77 rows=67 width=264) (actual
time=0.069..82.908 rows=13333 loops=1)
   Merge Cond: (fv.object_id = recipient_ids.recipient_id)
   Filter: (((fsv.form_submission_id IS NOT NULL) AND (fsv.recipient_id IS
NOT NULL)) OR (recipient_ids.recipient_id IS NOT NULL))
   ->  Merge Join  (cost=1.11..113868.70 rows=67 width=248) (actual
time=0.060..78.409 rows=13333 loops=1)
         Merge Cond: (fv.object_id = sobj_object_classes.object_id)
         ->  Nested Loop  (cost=0.84..113828.74 rows=67 width=228) (actual
time=0.054..71.372 rows=13333 loops=1)
               ->  Merge Left Join  (cost=0.70..113805.18 rows=67 width=164)
(actual time=0.049..51.553 rows=13333 loops=1)
                     Merge Cond: (fv.object_id = fsv.form_submission_id)
                     ->  Index Scan using sobj_field_values_pkey on
sobj_field_values fv  (cost=0.29..112138.29 rows=67 width=51) (actual
time=0.022..43.437 rows=13333 loops=1)
                           Filter: ((NOT is_deleted) AND (created_time =
(SubPlan 2)))
                           SubPlan 2
                             ->  Result  (cost=8.31..8.32 rows=1 width=0)
(actual time=0.002..0.002 rows=1 loops=13333)
                                   InitPlan 1 (returns $2)
                                     ->  Limit  (cost=0.29..8.31 rows=1
width=8) (actual time=0.002..0.002 rows=1 loops=13333)
                                           ->  Index Only Scan Backward
using sobj_field_values_pkey on sobj_field_values fvmax  (cost=0.29..8.31
rows=1 width=8) (actual time=0.002..0.002 rows=1 loops=13333)
                                                 Index Cond: ((object_id =
fv.object_id) AND (field_id = fv.field_id) AND (created_time IS NOT NULL))
                                                 Heap Fetches: 13333
                     ->  Materialize  (cost=0.42..1666.72 rows=1 width=113)
(actual time=0.026..2.609 rows=12871 loops=1)
                           ->  Nested Loop  (cost=0.42..1666.72 rows=1
width=113) (actual time=0.021..1.285 rows=199 loops=1)
                                 ->  Nested Loop  (cost=0.27..1658.54 rows=1
width=71) (actual time=0.018..0.949 rows=199 loops=1)
                                       Join Filter: (fsv.form_name =
form_definitions.form_name)
                                       ->  Index Scan using
form_submission_versions_form_submission_id_version_idx on
form_submission_versions fsv  (cost=0.14..1650.39 rows=1 width=64) (actual
time=0.014..0.664 rows=199 loops=1)
                                             Filter: ((recipient_id IS NOT
NULL) AND (version = (SubPlan 4)))
                                             SubPlan 4
                                               ->  Result  (cost=8.16..8.17
rows=1 width=0) (actual time=0.002..0.002 rows=1 loops=199)
                                                     InitPlan 3 (returns
$4)
                                                       ->  Limit
(cost=0.14..8.16 rows=1 width=8) (actual time=0.002..0.002 rows=1
loops=199)
                                                             ->  Index Only
Scan Backward using form_submission_versions_form_submission_id_version_idx
on form_submission_versions fsvmax  (cost=0.14..8.16 rows=1 width=8) (actual
time=0.001..0.001 rows=1 loops=199)
                                                                   Index
Cond: ((form_submission_id = fsv.form_submission_id) AND (version IS NOT
NULL))
                                                                   Heap
Fetches: 199
                                       ->  Index Scan using
form_definitions_pkey on form_definitions  (cost=0.12..8.14 rows=1 width=23)
(actual time=0.001..0.001 rows=1 loops=199)
                                 ->  Index Scan using
form_submission_ids_pkey on form_submission_ids  (cost=0.14..8.16 rows=1
width=58) (actual time=0.001..0.001 rows=1 loops=199)
                                       Index Cond: (form_submission_id =
fsv.form_submission_id)
               ->  Index Scan using sobj_fields_pkey on sobj_fields
(cost=0.14..0.34 rows=1 width=64) (actual time=0.001..0.001 rows=1
loops=13333)
                     Index Cond: (field_id = fv.field_id)
         ->  Index Scan using sobj_object_classes_pkey on
sobj_object_classes  (cost=0.27..38.12 rows=398 width=20) (actual
time=0.005..2.216 rows=13332 loops=1)
   ->  Index Only Scan using recipient_ids_pkey on recipient_ids
(cost=0.14..19.07 rows=199 width=16) (actual time=0.008..0.123 rows=397
loops=1)
         Heap Fetches: 397
 Planning time: 2.622 ms
 Execution time: 83.991 ms

After a bunch of experimentation, I discovered that if I replaced the view
with one that uses WHERE NOT EXISTS instead of MAX(), the planner did a much
better job.

CREATE OR REPLACE VIEW sobj_current_field_values AS
  SELECT object_id, field_id, audit_id, created_time, is_deleted, value
  FROM sobj_field_values fv
  WHERE NOT EXISTS (
      SELECT 1
      FROM sobj_field_values fv_newer
      WHERE fv.object_id = fv_newer.object_id
      AND fv.field_id = fv_newer.field_id
      AND fv.created_time < fv_newer.created_time);

Now the full query runs in 91ms and the execution plan looks like this:

 Hash Left Join  (cost=1341.09..2887.68 rows=8889 width=264) (actual
time=32.058..89.558 rows=13333 loops=1)
   Hash Cond: (fv.object_id = recipient_ids.recipient_id)
   Filter: (((fsv.form_submission_id IS NOT NULL) AND (fsv.recipient_id IS
NOT NULL)) OR (recipient_ids.recipient_id IS NOT NULL))
   ->  Hash Join  (cost=1334.61..2803.43 rows=8889 width=248) (actual
time=31.939..82.896 rows=13333 loops=1)
         Hash Cond: (fv.object_id = sobj_object_classes.object_id)
         ->  Hash Join  (cost=1322.66..2669.25 rows=8889 width=228) (actual
time=31.614..74.342 rows=13333 loops=1)
               Hash Cond: (fv.field_id = sobj_fields.field_id)
               ->  Hash Left Join  (cost=1320.15..2544.52 rows=8889
width=164) (actual time=31.557..66.531 rows=13333 loops=1)
                     Hash Cond: (fv.object_id = fsv.form_submission_id)
                     ->  Hash Anti Join  (cost=475.33..1666.14 rows=8889
width=51) (actual time=11.334..37.572 rows=13333 loops=1)
                           Hash Cond: ((fv.object_id = fv_newer.object_id)
AND (fv.field_id = fv_newer.field_id))
                           Join Filter: (fv.created_time <
fv_newer.created_time)
                           Rows Removed by Join Filter: 13333
                           ->  Seq Scan on sobj_field_values fv
(cost=0.00..275.33 rows=13333 width=51) (actual time=0.004..5.820 rows=13333
loops=1)
                                 Filter: (NOT is_deleted)
                           ->  Hash  (cost=275.33..275.33 rows=13333
width=28) (actual time=11.304..11.304 rows=13333 loops=1)
                                 Buckets: 2048  Batches: 1  Memory Usage:
834kB
                                 ->  Seq Scan on sobj_field_values fv_newer
(cost=0.00..275.33 rows=13333 width=28) (actual time=0.003..5.258 rows=13333
loops=1)
                     ->  Hash  (cost=844.81..844.81 rows=1 width=113)
(actual time=20.207..20.207 rows=199 loops=1)
                           Buckets: 1024  Batches: 1  Memory Usage: 29kB
                           ->  Nested Loop  (cost=0.00..844.81 rows=1
width=113) (actual time=0.060..19.829 rows=199 loops=1)
                                 Join Filter: (fsv.form_submission_id =
form_submission_ids.form_submission_id)
                                 Rows Removed by Join Filter: 39402
                                 ->  Nested Loop  (cost=0.00..837.33 rows=1
width=71) (actual time=0.049..3.050 rows=199 loops=1)
                                       Join Filter: (fsv.form_name =
form_definitions.form_name)
                                       ->  Seq Scan on
form_submission_versions fsv  (cost=0.00..836.31 rows=1 width=64) (actual
time=0.036..1.922 rows=199 loops=1)
                                             Filter: ((recipient_id IS NOT
NULL) AND (version = (SubPlan 2)))
                                             SubPlan 2
                                               ->  Result  (cost=4.16..4.17
rows=1 width=0) (actual time=0.007..0.007 rows=1 loops=199)
                                                     InitPlan 1 (returns
$1)
                                                       ->  Limit
(cost=0.14..4.16 rows=1 width=8) (actual time=0.005..0.005 rows=1
loops=199)
                                                             ->  Index Only
Scan Backward using form_submission_versions_form_submission_id_version_idx
on form_submission_versions fsvmax  (cost=0.14..4.16 rows=1 width=8) (actual
time=0.004..0.004 rows=1 loops=199)
                                                                   Index
Cond: ((form_submission_id = fsv.form_submission_id) AND (version IS NOT
NULL))
                                                                   Heap
Fetches: 0
                                       ->  Seq Scan on form_definitions
(cost=0.00..1.01 rows=1 width=23) (actual time=0.001..0.001 rows=1
loops=199)
                                 ->  Seq Scan on form_submission_ids
(cost=0.00..4.99 rows=199 width=58) (actual time=0.002..0.037 rows=199
loops=199)
               ->  Hash  (cost=1.67..1.67 rows=67 width=64) (actual
time=0.041..0.041 rows=67 loops=1)
                     Buckets: 1024  Batches: 1  Memory Usage: 7kB
                     ->  Seq Scan on sobj_fields  (cost=0.00..1.67 rows=67
width=64) (actual time=0.004..0.014 rows=67 loops=1)
         ->  Hash  (cost=6.98..6.98 rows=398 width=20) (actual
time=0.304..0.304 rows=398 loops=1)
               Buckets: 1024  Batches: 1  Memory Usage: 21kB
               ->  Seq Scan on sobj_object_classes  (cost=0.00..6.98
rows=398 width=20) (actual time=0.010..0.105 rows=398 loops=1)
   ->  Hash  (cost=3.99..3.99 rows=199 width=16) (actual time=0.099..0.099
rows=199 loops=1)
         Buckets: 1024  Batches: 1  Memory Usage: 10kB
         ->  Seq Scan on recipient_ids  (cost=0.00..3.99 rows=199 width=16)
(actual time=0.004..0.032 rows=199 loops=1)
 Planning time: 5.022 ms
 Execution time: 91.046 ms

Since the two versions of the view are equivalent but have such dramatically
different performance, and the execution plan is so much better with the
original view when I disable seq scans, it seemed like this might be worth
reporting as a possible bug despite the "poor performance is not necessarily
a bug" caveat.