-----Original Message-----
From: Justin Pryzby <pry...@telsasoft.com>
Sent: Thursday, July 22, 2021 12:36
To: l...@laurent-hasson.com
Cc: Tom Lane <t...@sss.pgh.pa.us>; David Rowley <dgrowle...@gmail.com>; Peter
Geoghegan <p...@bowt.ie>; pgsql-performa...@postgresql.org
Subject: Re: Big performance slowdown from 11.2 to 13.3
On Thu, Jul 22, 2021 at 04:30:00PM +0000, l...@laurent-hasson.com wrote:
> Hello Justin,
>
> > log_executor_stats=on; client_min_messages=debug;
>
> Would the results then come in EXPLAIN or would I need to pick something up
> from the logs?
If you're running with psql, and client_min_messages=debug, then it'll show up
as a debug message to the client:
ts=# SET log_executor_stats=on; SET client_min_messages=debug; explain analyze
SELECT 1; SET SET
LOG: EXECUTOR STATISTICS
DETAIL: ! system usage stats:
! 0.000011 s user, 0.000209 s system, 0.000219 s elapsed
! [0.040608 s user, 0.020304 s system total]
! 7808 kB max resident size
...
It can but doesn't have to use "explain" - that just avoids showing the query
output, since it's not what's interesting here.
--
Justin
-------------------------------------------------------------------------------------
Justin,
I tried this but not seeing max resident size data output.
Pepper=# SET log_executor_stats=on; SET client_min_messages=debug; explain
analyze SELECT 1;
SET
SET
LOG: EXECUTOR STATISTICS
DETAIL: ! system usage stats:
! 0.000000 s user, 0.000000 s system, 0.000109 s elapsed
! [494.640625 s user, 19.171875 s system total]
QUERY PLAN
------------------------------------------------------------------------------------
Result (cost=0.00..0.01 rows=1 width=4) (actual time=0.002..0.002 rows=1
loops=1)
Planning Time: 0.041 ms
Execution Time: 0.012 ms
(3 rows)
For my query:
LOG: EXECUTOR STATISTICS
DETAIL: ! system usage stats:
! 169.625000 s user, 5.843750 s system, 175.490088 s elapsed
! [494.640625 s user, 19.171875 s system total]
HashAggregate (cost=1764285.18..1764296.18 rows=200 width=1260) (actual
time=86323.813..174737.442 rows=723659 loops=1)
Group Key: t.iccqa_iccassmt_fk
Buffers: shared hit=364 read=170293, temp written=83229
CTE t
-> HashAggregate (cost=1343178.39..1356985.17 rows=1380678 width=56)
(actual time=22594.053..32519.573 rows=13865785 loops=1)
Group Key: assessmenticcqa_raw.iccqar_iccassmt_fk,
assessmenticcqa_raw.iccqar_ques_code
Buffers: shared hit=364 read=170293
-> Seq Scan on assessmenticcqa_raw (cost=0.00..1240682.76
rows=13666084 width=38) (actual time=0.170..10714.598 rows=13865785 loops=1)
Filter: ((iccqar_ques_code)::text = ANY ('{"DEBRIDEMENT
DATE","DEBRIDEMENT THIS VISIT","DEBRIDEMENT TYPE","DEPTH (CM)","DEPTH
DESCRIPTION","DOE
S PATIENT HAVE PAIN ASSOCIATED WITH THIS WOUND?","DRAIN PRESENT","DRAIN
TYPE","EDGE / SURROUNDING TISSUE - MACERATION",EDGES,EPITHELIALIZATION,"EXUDATE
AMOUNT",
"EXUDATE TYPE","GRANULATION TISSUE","INDICATE OTHER TYPE OF WOUND
CLOSURE","INDICATE TYPE","INDICATE WOUND CLOSURE","IS THIS A CLOSED SURGICAL
WOUND OR SUSPECTE
D DEEP TISSUE INJURY?","LENGTH (CM)","MEASUREMENTS TAKEN","NECROTIC TISSUE
AMOUNT","NECROTIC TISSUE TYPE",ODOR,"OTHER COMMENTS REGARDING DEBRIDEMENT
TYPE","OTHE
R COMMENTS REGARDING DRAIN TYPE","OTHER COMMENTS REGARDING PAIN
INTERVENTIONS","OTHER COMMENTS REGARDING PAIN QUALITY","OTHER COMMENTS
REGARDING REASON MEASUREM
ENTS NOT TAKEN","PAIN FREQUENCY","PAIN INTERVENTIONS","PAIN
QUALITY","PERIPHERAL TISSUE EDEMA","PERIPHERAL TISSUE INDURATION","REASON
MEASUREMENTS NOT TAKEN","R
ESPONSE TO PAIN INTERVENTIONS",SHAPE,"SIGNS AND SYMPTOMS OF INFECTION","SKIN
COLOR SURROUNDING WOUND",STATE,"SURFACE AREA (SQ CM)","TOTAL NECROTIC TISSUE
ESCHAR
","TOTAL NECROTIC TISSUE SLOUGH",TUNNELING,"TUNNELING SIZE(CM)/LOCATION - 12 -
3 O''CLOCK","TUNNELING SIZE(CM)/LOCATION - 3 - 6 O''CLOCK","TUNNELING
SIZE(CM)/LO
CATION - 6 - 9 O''CLOCK","TUNNELING SIZE(CM)/LOCATION - 9 - 12
O''CLOCK",UNDERMINING,"UNDERMINING SIZE(CM)/LOCATION - 12 - 3
O''CLOCK","UNDERMINING SIZE(CM)/LOC
ATION - 3 - 6 O''CLOCK","UNDERMINING SIZE(CM)/LOCATION - 6 - 9
O''CLOCK","UNDERMINING SIZE(CM)/LOCATION - 9 - 12 O''CLOCK","WIDTH (CM)","WOUND
PAIN LEVEL, WHERE
0 = \"NO PAIN\" AND 10 = \"WORST POSSIBLE PAIN\""}'::text[]))
Rows Removed by Filter: 172390
Buffers: shared hit=364 read=170293
-> CTE Scan on t (cost=0.00..27613.56 rows=1380678 width=552) (actual
time=22594.062..40248.874 rows=13865785 loops=1)
Buffers: shared hit=364 read=170293, temp written=83229
Planning Time: 0.728 ms
Execution Time: 175482.904 ms
(15 rows)
