performance regression with 9.2

This query is a couple orders of magnitude slower the first result is
9.2.1, the second 9.1

=# explain analyze SELECT note_sets."id" AS t0_r0,
note_sets."note_set_source_id" AS t0_r1, note_sets."parent_id" AS t0_r2,
note_sets."business_entity_id" AS t0_r3, note_sets."created_at" AS t0_r4,
note_sets."updated_at" AS t0_r5, note_sets."created_by" AS t0_r6,
note_sets."updated_by" AS t0_r7, note_set_sources."id" AS t1_r0,
note_set_sources."name" AS t1_r1, note_set_sources."code" AS t1_r2,
note_set_sources."description" AS t1_r3, note_set_sources."status" AS
t1_r4, note_set_sources."created_at" AS t1_r5,
note_set_sources."updated_at" AS t1_r6, note_set_sources."created_by" AS
t1_r7, note_set_sources."updated_by" AS t1_r8, notes."id" AS t2_r0,
notes."note_set_id" AS t2_r1, notes."subject" AS t2_r2, notes."text" AS
t2_r3, notes."status" AS t2_r4, notes."is_dissmissable" AS t2_r5,
notes."is_home" AS t2_r6, notes."created_at" AS t2_r7, notes."updated_at"
AS t2_r8, notes."created_by" AS t2_r9, notes."updated_by" AS t2_r10 FROM
note_sets LEFT OUTER JOIN note_set_sources ON note_set_sources.id =
note_sets.note_set_source_id LEFT OUTER JOIN notes ON notes.note_set_id =
note_sets.id AND notes."status" = E'A' WHERE (note_sets.id IN (WITH
RECURSIVE parent_noteset as (SELECT id FROM note_sets where id = 8304085
UNION SELECT note_sets.id FROM parent_noteset parent_noteset, note_sets
note_sets WHERE note_sets.parent_id = parent_noteset.id) SELECT id FROM
parent_noteset))
CareCloud_Prod-# ;

QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Hash Left Join (cost=4704563.58..5126773.60 rows=10184900 width=773)
(actual time=14414.946..14554.962 rows=52 loops=1)
Hash Cond: (public.note_sets.note_set_source_id = note_set_sources.id)
-> Hash Right Join (cost=4704562.22..4986729.86 rows=10184900
width=720) (actual time=14414.908..14554.878 rows=52 loops=1)
Hash Cond: (notes.note_set_id = public.note_sets.id)
-> Seq Scan on notes (cost=0.00..33097.97 rows=883383 width=680)
(actual time=0.021..292.329 rows=882307 loops=1)
Filter: (status = 'A'::bpchar)
Rows Removed by Filter: 862
-> Hash (cost=4497680.97..4497680.97 rows=10184900 width=40)
(actual time=13848.559..13848.559 rows=46 loops=1)
Buckets: 524288 Batches: 4 Memory Usage: 7kB
-> Nested Loop (cost=4496147.89..4497680.97 rows=10184900
width=40) (actual time=13847.537..13848.125 rows=46 loops=1)
-> HashAggregate (cost=4496147.89..4496149.89
rows=200 width=4) (actual time=13847.410..13847.425 rows=46 loops=1)
-> CTE Scan on parent_noteset
(cost=4495503.38..4495900.00 rows=19831 width=4) (actual
time=0.058..13847.350 rows=46 loops=1)
CTE parent_noteset
-> Recursive Union
(cost=0.00..4495503.38 rows=19831 width=4) (actual time=0.057..13847.284
rows=46 loops=1)
-> Index Only Scan using
note_sets_pkey on note_sets (cost=0.00..7.85 rows=1 width=4) (actual
time=0.054..0.055 rows=1 loops=1)
Index Cond: (id = 8304085)
Heap Fetches: 1
-> Hash Join
(cost=0.33..449509.89 rows=1983 width=4) (actual time=2788.672..4615.686
rows=15 loops=3)
Hash Cond:
(note_sets.parent_id = parent_noteset.id)
-> Seq Scan on note_sets
(cost=0.00..373102.99 rows=20369799 width=8) (actual time=0.006..2288.076
rows=20355654 loops=3)
-> Hash (cost=0.20..0.20
rows=10 width=4) (actual time=0.006..0.006 rows=15 loops=3)
Buckets: 1024
Batches: 1 Memory Usage: 1kB
-> WorkTable Scan on
parent_noteset (cost=0.00..0.20 rows=10 width=4) (actual time=0.001..0.003
rows=15 loops=3)
-> Index Scan using note_sets_pkey on note_sets
(cost=0.00..7.65 rows=1 width=40) (actual time=0.014..0.014 rows=1
loops=46)
Index Cond: (id = parent_noteset.id)
-> Hash (cost=1.16..1.16 rows=16 width=53) (actual time=0.010..0.010
rows=16 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 2kB
-> Seq Scan on note_set_sources (cost=0.00..1.16 rows=16
width=53) (actual time=0.004..0.005 rows=16 loops=1)
Total runtime: 14555.254 ms
(29 rows)

CareCloud_Prod=#

# SELECT note_sets."id" AS t0_r0, note_sets."note_set_source_id" AS t0_r1,
note_sets."parent_id" AS t0_r2, note_sets."business_entity_id" AS t0_r3,
note_sets."created_at" AS t0_r4, note_sets."updated_at" AS t0_r5,
note_sets."created_by" AS t0_r6, note_sets."updated_by" AS t0_r7,
note_set_sources."id" AS t1_r0, note_set_sources."name" AS t1_r1,
note_set_sources."code" AS t1_r2, note_set_sources."description" AS t1_r3,
note_set_sources."status" AS t1_r4, note_set_sources."created_at" AS t1_r5,
note_set_sources."updated_at" AS t1_r6, note_set_sources."created_by" AS
t1_r7, note_set_sources."updated_by" AS t1_r8, notes."id" AS t2_r0,
notes."note_set_id" AS t2_r1, notes."subject" AS t2_r2, notes."text" AS
t2_r3, notes."status" AS t2_r4, notes."is_dissmissable" AS t2_r5,
notes."is_home" AS t2_r6, notes."created_at" AS t2_r7, notes."updated_at"
AS t2_r8, notes."created_by" AS t2_r9, notes."updated_by" AS t2_r10 FROM
note_sets LEFT OUTER JOIN note_set_sources ON note_set_sources.id =
note_sets.note_set_source_id LEFT OUTER JOIN notes ON notes.note_set_id =
note_sets.id AND notes."status" = E'A' WHERE (note_sets.id IN (WITH
RECURSIVE parent_noteset as (SELECT id FROM note_sets where id = 8304085
UNION SELECT note_sets.id FROM parent_noteset parent_noteset, note_sets
note_sets WHERE note_sets.parent_id = parent_noteset.id) SELECT id FROM
parent_noteset));

QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Hash Left Join (cost=249847.72..670928.98 rows=10180954 width=1512)
(actual time=692.423..829.258 rows=48 loops=1)
Hash Cond: (public.note_sets.note_set_source_id = note_set_sources.id)
-> Hash Right Join (cost=249846.36..530939.50 rows=10180954 width=718)
(actual time=692.382..829.180 rows=48 loops=1)
Hash Cond: (notes.note_set_id = public.note_sets.id)
-> Seq Scan on notes (cost=0.00..32981.14 rows=878550 width=678)
(actual time=0.027..413.972 rows=878529 loops=1)
Filter: (status = 'A'::bpchar)
-> Hash (cost=43045.44..43045.44 rows=10180954 width=40) (actual
time=22.904..22.904 rows=46 loops=1)
Buckets: 524288 Batches: 4 Memory Usage: 2kB
-> Nested Loop (cost=41106.18..43045.44 rows=10180954
width=40) (actual time=12.319..22.738 rows=46 loops=1)
-> HashAggregate (cost=41106.18..41108.18 rows=200
width=4) (actual time=11.873..11.889 rows=46 loops=1)
-> CTE Scan on parent_noteset
(cost=40459.39..40857.41 rows=19901 width=4) (actual time=0.492..11.843
rows=46 loops=1)
CTE parent_noteset
-> Recursive Union
(cost=0.00..40459.39 rows=19901 width=4) (actual time=0.489..11.822
rows=46 loops=1)
-> Index Scan using
note_sets_pkey on note_sets (cost=0.00..10.50 rows=1 width=4) (actual
time=0.484..0.485 rows=1 loops=1)
Index Cond: (id = 8304085)
-> Nested Loop
(cost=0.00..4005.09 rows=1990 width=4) (actual time=1.534..3.764 rows=15
loops=3)
-> WorkTable Scan on
parent_noteset (cost=0.00..0.20 rows=10 width=4) (actual time=0.000..0.001
rows=15 loops=3)
-> Index Scan using
note_sets_parent_id_idx on note_sets (cost=0.00..398.00 rows=199 width=8)
(actual time=0.216..0.244 rows=1 loops=46)
Index Cond: (parent_id
= parent_noteset.id)
-> Index Scan using note_sets_pkey on note_sets
(cost=0.00..9.67 rows=1 width=40) (actual time=0.234..0.234 rows=1
loops=46)
Index Cond: (id = parent_noteset.id)
-> Hash (cost=1.16..1.16 rows=16 width=794) (actual time=0.020..0.020
rows=16 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 2kB
-> Seq Scan on note_set_sources (cost=0.00..1.16 rows=16
width=794) (actual time=0.012..0.014 rows=16 loops=1)
Total runtime: 829.657 ms
(25 rows)

Dave Cramer

dave.cramer(at)credativ(dot)ca
http://www.credativ.ca