RE: Big performance slowdown from 11.2 to 13.3 - Mailing list pgsql-performance

Hello all...

I upgraded to 13.4 and re-ran the various versions of the query. I think I get a mixed bag of results. In the spirit of
closingthis thread, I'll start with the fantastic news and then start a new thread with the other issue I have
isolated.

It looks like the query I submitted initially is now performing very well!!! It's funny but it looks like the query is
consuminga tiny bit over 2.5GB, so my use case was literally a hair above the memory limit that we had discovered.
V13.4takes 54s vs V11.2 takes 74s!! This is quite amazing to have such a performance gain! 25% better. The query was as
follows:

select "iccqa_iccassmt_fk"
     , MAX("iccqar_ans_val") as "iccqar_ans_val"
     , (MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 'DEBRIDEMENT DATE'))::text as "iccqa_DEBRIDEMENT_DATE"
     , (MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 'DEBRIDEMENT THIS VISIT') )::text as
"iccqa_DEBRIDEMENT_THIS_VISIT"
     , (MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 'DEBRIDEMENT TYPE') )::text as "iccqa_DEBRIDEMENT_TYPE"
     , (MAX("iccqar_ans_val") filter (where "iccqar_ques_code"= 'DEPTH (CM)'))::text as "iccqa_DEPTH_CM"
     , ... 50 more columns
from (
-- 'A pivoted view of ICC QA assessments'
select VNAHGEDW_FACTS.AssessmentICCQA_Raw."iccqar_iccassmt_fk" as "iccqa_iccassmt_fk" -- The key identifying an ICC
assessment.
     , VNAHGEDW_FACTS.AssessmentICCQA_Raw."iccqar_ques_code" as "iccqar_ques_code" -- The question long code from the
meta-data.
     , max(VNAHGEDW_FACTS.AssessmentICCQA_Raw."iccqar_ans_val") as "iccqar_ans_val" -- The official answer, if
applicable)from the meta-data. 
  from VNAHGEDW_FACTS.AssessmentICCQA_Raw
 where VNAHGEDW_FACTS.AssessmentICCQA_Raw."iccqar_ques_code" in ('DEBRIDEMENT DATE', 'DEBRIDEMENT THIS VISIT',
'DEBRIDEMENTTYPE', 'DEPTH (CM)', ... 50 more values) 
 group by 1, 2
) T
     group by 1
;

The plans are:

V13.4 - 54s
HashAggregate  (cost=1486844.46..1486846.46 rows=200 width=1764) (actual time=50714.016..53813.049 rows=677899 loops=1)
  Group Key: assessmenticcqa_raw.iccqar_iccassmt_fk
  Batches: 1  Memory Usage: 1196065kB
  Buffers: shared hit=158815
  ->  Finalize HashAggregate  (cost=1100125.42..1113234.54 rows=1310912 width=56) (actual time=14487.522..20498.241
rows=12926549loops=1) 
        Group Key: assessmenticcqa_raw.iccqar_iccassmt_fk, assessmenticcqa_raw.iccqar_ques_code
        Batches: 1  Memory Usage: 2572305kB
        Buffers: shared hit=158815
        ->  Gather  (cost=382401.10..1050966.22 rows=6554560 width=56) (actual time=2891.177..6614.288 rows=12926549
loops=1)
              Workers Planned: 5
              Workers Launched: 5
              Buffers: shared hit=158815
              ->  Partial HashAggregate  (cost=381401.10..394510.22 rows=1310912 width=56) (actual
time=2790.736..3680.249rows=2154425 loops=6) 
                    Group Key: assessmenticcqa_raw.iccqar_iccassmt_fk, assessmenticcqa_raw.iccqar_ques_code
                    Batches: 1  Memory Usage: 417809kB
                    Buffers: shared hit=158815
                    Worker 0:  Batches: 1  Memory Usage: 401425kB
                    Worker 1:  Batches: 1  Memory Usage: 409617kB
                    Worker 2:  Batches: 1  Memory Usage: 393233kB
                    Worker 3:  Batches: 1  Memory Usage: 385041kB
                    Worker 4:  Batches: 1  Memory Usage: 393233kB
                    ->  Parallel Seq Scan on assessmenticcqa_raw  (cost=0.00..362006.30 rows=2585974 width=38) (actual
time=0.042..1600.138rows=2154425 loops=6) 
                          Filter: ((iccqar_ques_code)::text = ANY ('{"DEBRIDEMENT DATE","DEBRIDEMENT THIS
VISIT","DEBRIDEMENTTYPE","DEPTH (CM)","DEPTH DESCRIPTION","DOES PATIENT HAVE PAIN ASSOCIATED WITH THIS WOUND?","DRAIN
PRESENT","DRAINTYPE","EDGE / SURROUNDING TISSUE - MACERATION",EDGES,EPITHELIALIZATION,"EXUDATE AMOUNT","EXUDATE
TYPE","GRANULATIONTISSUE","INDICATE OTHER TYPE OF WOUND CLOSURE","INDICATE TYPE","INDICATE WOUND CLOSURE","IS THIS A
CLOSEDSURGICAL WOUND OR SUSPECTED DEEP TISSUE INJURY?","LENGTH (CM)","MEASUREMENTS TAKEN","NECROTIC TISSUE
AMOUNT","NECROTICTISSUE TYPE",ODOR,"OTHER COMMENTS REGARDING DEBRIDEMENT TYPE","OTHER COMMENTS REGARDING DRAIN
TYPE","OTHERCOMMENTS REGARDING PAIN INTERVENTIONS","OTHER COMMENTS REGARDING PAIN QUALITY","OTHER COMMENTS REGARDING
REASONMEASUREMENTS NOT TAKEN","PAIN FREQUENCY","PAIN INTERVENTIONS","PAIN QUALITY","PERIPHERAL TISSUE
EDEMA","PERIPHERALTISSUE INDURATION","REASON MEASUREMENTS NOT TAKEN","RESPONSE TO PAIN INTERVENTIONS",SHAPE,"SIGNS AND
SYMPTOMSOF INFECTION","SKIN COLOR SURROUNDING WOUND",STATE,"SURFACE AREA (SQ CM)","TOTAL NECROTIC TISSUE ESCHAR","TOTAL
NECROTICTISSUE SLOUGH",TUNNELING,"TUNNELING SIZE(CM)/LOCATION - 12 - 3 O''CLOCK","TUNNELING SIZE(CM)/LOCATION - 3 - 6
O''CLOCK","TUNNELINGSIZE(CM)/LOCATION - 6 - 9 O''CLOCK","TUNNELING SIZE(CM)/LOCATION - 9 - 12
O''CLOCK",UNDERMINING,"UNDERMININGSIZE(CM)/LOCATION - 12 - 3 O''CLOCK","UNDERMINING SIZE(CM)/LOCATION - 3 - 6
O''CLOCK","UNDERMININGSIZE(CM)/LOCATION - 6 - 9 O''CLOCK","UNDERMINING SIZE(CM)/LOCATION - 9 - 12 O''CLOCK","WIDTH
(CM)","WOUNDPAIN LEVEL, WHERE 0 = \"NO PAIN\" AND 10 = \"WORST POSSIBLE PAIN\""}'::text[])) 
                          Rows Removed by Filter: 30428
                          Buffers: shared hit=158815
Planning:
  Buffers: shared hit=3
Planning Time: 0.552 ms
Execution Time: 54241.152 ms



V11.2 - 74s
HashAggregate  (cost=1629249.48..1629251.48 rows=200 width=1764) (actual time=68833.447..73384.374 rows=742896 loops=1)
  Group Key: assessmenticcqa_raw.iccqar_iccassmt_fk
  Buffers: shared read=173985
  ->  Finalize HashAggregate  (cost=1205455.43..1219821.33 rows=1436590 width=56) (actual time=19441.489..28630.297
rows=14176024loops=1) 
        Group Key: assessmenticcqa_raw.iccqar_iccassmt_fk, assessmenticcqa_raw.iccqar_ques_code
        Buffers: shared read=173985
        ->  Gather  (cost=418922.41..1151583.31 rows=7182950 width=56) (actual time=3698.235..8445.971 rows=14176024
loops=1)
              Workers Planned: 5
              Workers Launched: 5
              Buffers: shared read=173985
              ->  Partial HashAggregate  (cost=417922.41..432288.31 rows=1436590 width=56) (actual
time=3559.562..4619.406rows=2362671 loops=6) 
                    Group Key: assessmenticcqa_raw.iccqar_iccassmt_fk, assessmenticcqa_raw.iccqar_ques_code
                    Buffers: shared read=173985
                    ->  Parallel Seq Scan on assessmenticcqa_raw  (cost=0.00..396656.48 rows=2835457 width=38) (actual
time=0.261..1817.102rows=2362671 loops=6) 
                          Filter: ((iccqar_ques_code)::text = ANY ('{"DEBRIDEMENT DATE","DEBRIDEMENT THIS
VISIT","DEBRIDEMENTTYPE","DEPTH (CM)","DEPTH DESCRIPTION","DOES PATIENT HAVE PAIN ASSOCIATED WITH THIS WOUND?","DRAIN
PRESENT","DRAINTYPE","EDGE / SURROUNDING TISSUE - MACERATION",EDGES,EPITHELIALIZATION,"EXUDATE AMOUNT","EXUDATE
TYPE","GRANULATIONTISSUE","INDICATE OTHER TYPE OF WOUND CLOSURE","INDICATE TYPE","INDICATE WOUND CLOSURE","IS THIS A
CLOSEDSURGICAL WOUND OR SUSPECTED DEEP TISSUE INJURY?","LENGTH (CM)","MEASUREMENTS TAKEN","NECROTIC TISSUE
AMOUNT","NECROTICTISSUE TYPE",ODOR,"OTHER COMMENTS REGARDING DEBRIDEMENT TYPE","OTHER COMMENTS REGARDING DRAIN
TYPE","OTHERCOMMENTS REGARDING PAIN INTERVENTIONS","OTHER COMMENTS REGARDING PAIN QUALITY","OTHER COMMENTS REGARDING
REASONMEASUREMENTS NOT TAKEN","PAIN FREQUENCY","PAIN INTERVENTIONS","PAIN QUALITY","PERIPHERAL TISSUE
EDEMA","PERIPHERALTISSUE INDURATION","REASON MEASUREMENTS NOT TAKEN","RESPONSE TO PAIN INTERVENTIONS",SHAPE,"SIGNS AND
SYMPTOMSOF INFECTION","SKIN COLOR SURROUNDING WOUND",STATE,"SURFACE AREA (SQ CM)","TOTAL NECROTIC TISSUE ESCHAR","TOTAL
NECROTICTISSUE SLOUGH",TUNNELING,"TUNNELING SIZE(CM)/LOCATION - 12 - 3 O''CLOCK","TUNNELING SIZE(CM)/LOCATION - 3 - 6
O''CLOCK","TUNNELINGSIZE(CM)/LOCATION - 6 - 9 O''CLOCK","TUNNELING SIZE(CM)/LOCATION - 9 - 12
O''CLOCK",UNDERMINING,"UNDERMININGSIZE(CM)/LOCATION - 12 - 3 O''CLOCK","UNDERMINING SIZE(CM)/LOCATION - 3 - 6
O''CLOCK","UNDERMININGSIZE(CM)/LOCATION - 6 - 9 O''CLOCK","UNDERMINING SIZE(CM)/LOCATION - 9 - 12 O''CLOCK","WIDTH
(CM)","WOUNDPAIN LEVEL, WHERE 0 = \"NO PAIN\" AND 10 = \"WORST POSSIBLE PAIN\""}'::text[])) 
                          Rows Removed by Filter: 31608
                          Buffers: shared read=173985
Planning Time: 22.673 ms
Execution Time: 74110.779 ms


Thank you so much to the whole team to this great work!

I'll send a separate email with the other issue I think I have isolated.

Thank you!
Laurent Hasson


-----Original Message-----
From: ldh@laurent-hasson.com <ldh@laurent-hasson.com>
Sent: Wednesday, July 28, 2021 16:13
To: Tom Lane <tgl@sss.pgh.pa.us>
Cc: Peter Geoghegan <pg@bowt.ie>; David Rowley <dgrowleyml@gmail.com>; Justin Pryzby <pryzby@telsasoft.com>;
pgsql-performance@postgresql.org
Subject: RE: Big performance slowdown from 11.2 to 13.3


-----Original Message-----
From: Tom Lane <tgl@sss.pgh.pa.us>
Sent: Tuesday, July 27, 2021 23:31
To: ldh@laurent-hasson.com
Cc: Peter Geoghegan <pg@bowt.ie>; David Rowley <dgrowleyml@gmail.com>; Justin Pryzby <pryzby@telsasoft.com>;
pgsql-performance@postgresql.org
Subject: Re: Big performance slowdown from 11.2 to 13.3

I wrote:
> Yeah, I wouldn't sweat over the specific value.  The pre-v13 behavior
> was effectively equivalent to hash_mem_multiplier = infinity, so if
> you weren't having any OOM problems before, just crank it up.

Oh, wait, scratch that: the old executor's behavior is accurately described by that statement, but the planner's is
not. The planner will not pick a hashagg plan if it guesses that the hash table would exceed the configured limit
(work_membefore, now work_mem times hash_mem_multiplier).  So raising hash_mem_multiplier to the moon might bias the
v13planner to pick hashagg plans in cases where earlier versions would not have.  This doesn't describe your immediate
problem,but it might be a reason to not just set the value as high as you can. 

BTW, this also suggests that the planner is underestimating the amount of memory needed for the hashagg, both before
andafter. 
That might be something to investigate at some point.

            regards, tom lane


This is very useful to know... all things I'll get to test after 13.4 is released. I'll report back when I am able to.

Thank you,
Laurent.