Обсуждение: simple query running long time within a long transaction.

Поиск
Список
Период
Сортировка

simple query running long time within a long transaction.

От
"James Pang (chaolpan)"
Дата:

Hi,

   We found one simple query manually run very fast(finished in several milliseconds), but there are 2 sessions within long transaction to run same sql with same bind variables took tens of seconds.

Manually run this sql only show <100 shared_blks_hit and very small reads, but for these 2 long running SQL from pg_stat_statements, it show huge shared_blks_hits/reads, and some shared_blks_dirtied/written for this query too.   It’s a very hot table and a lot of sessions update/delete/insert on this table.  It looks like the query have scan huge blocks for MVCC ? any suggestions to tune this case ? any idea why shared_blks_dirtied/written for this query? 

   

 

userid              | 17443

dbid                | 16384

toplevel            | t

queryid             | 6334282481325858045

query               | SELECT xxxx, xxxx FROM test.xxxxx

WHERE  ( ( id1 = $1  ) )  AND  ( ( id2 = $2  ) )  AND  ( ( id3 = $3  ) )

plans               | 0

total_plan_time     | 0

min_plan_time       | 0

max_plan_time       | 0

mean_plan_time      | 0

stddev_plan_time    | 0

calls               | 2142

total_exec_time     | 66396685.619224936

min_exec_time       | 7221.611607

max_exec_time       | 391486.974656

mean_exec_time      | 30997.51896322356

stddev_exec_time    | 31073.83250436726

rows                | 153

shared_blks_hit     | 7133350479

shared_blks_read    | 2783620426

shared_blks_dirtied | 1853702

shared_blks_written | 2329513

local_blks_hit      | 0

local_blks_read     | 0

local_blks_dirtied  | 0

local_blks_written  | 0

temp_blks_read      | 0

temp_blks_written   | 0

blk_read_time       | 0

blk_write_time      | 0

wal_records         | 237750

wal_fpi             | 207790

wal_bytes           | 442879812

 

pid   |  state   |          xact_start           |          query_start          | wait_event_type | wait_event | backend_xid | backend

_xmin                 

---------+------------+-------------------------------+-------------------------------+-----------------+------------+-------------+--------

------                

 3671416 | active | 2023-11-16 06:38:16.802127+00 | 2023-11-16 08:08:15.739509+00 |                 |            |   159763259 |    159763259                 

 3671407 | active | 2023-11-16 06:38:16.807064+00 | 2023-11-16 08:08:17.195405+00 |                 |            |   159764118 |    159763259  

 

--table size

relpages |   reltuples

----------+---------------

  3146219 | 1.9892568e+08

--index size

relpages |   reltuples

----------+---------------

  1581759 | 1.9892568e+08

 

Thanks,

 

James

Re: simple query running long time within a long transaction.

От
Andreas Kretschmer
Дата:

Am 17.11.23 um 09:10 schrieb James Pang (chaolpan):
>
> Hi,
>
>    We found one simple query manually run very fast(finished in 
> several milliseconds), but there are 2 sessions within long 
> transaction to run same sql with same bind variables took tens of seconds.
>
you try to set plan_cache_mode to force_custom_plan, default is auto and 
with that and bind variables pg will use a generic plan.


Regards, Andreas

-- 
Andreas Kretschmer - currently still (garden leave)
Technical Account Manager (TAM)
www.enterprisedb.com

RE: simple query running long time within a long transaction.

От
"James Pang (chaolpan)"
Дата:
Looks like it's not sql issue, manually running still use prepared statements and use same sql plan. 

-----Original Message-----
From: Andreas Kretschmer <andreas@a-kretschmer.de> 
Sent: Friday, November 17, 2023 5:17 PM
To: pgsql-performance@lists.postgresql.org
Subject: Re: simple query running long time within a long transaction.



Am 17.11.23 um 09:10 schrieb James Pang (chaolpan):
>
> Hi,
>
>    We found one simple query manually run very fast(finished in 
> several milliseconds), but there are 2 sessions within long 
> transaction to run same sql with same bind variables took tens of seconds.
>
you try to set plan_cache_mode to force_custom_plan, default is auto and with that and bind variables pg will use a
genericplan.
 


Regards, Andreas

-- 
Andreas Kretschmer - currently still (garden leave)
Technical Account Manager (TAM)
www.enterprisedb.com

Re: simple query running long time within a long transaction.

От
Frits Hoogland
Дата:
Any statement will run using a custom plan at first.
Only a prepared statement creates the memory area in the backend that can hold the custom plan statistics, that is why generic plans only work with prepared statements.
A prepared statement has to run at least 5 times before the planner looks at the plan statistics and determine whether a generic plan would work (=generic plan cost being equal or lower than the average custom plan cost)
That means that the values in the binds/filters also play a role (as far as I know).

Once a generic plan is selected, it doesn’t do the statistics evaluation anymore, and thus the generic plan is fixed until the prepared statement is closed or the session is terminated.
It therefore also cannot choose a different plan based on the bind values anymore.

This means that if you want to manually replay your issue, just issuing it using a prepared statement manually is not exactly what happens in a session.
Such a replay will always use a custom plan.
You have to perform it at least 5 times for the generic plan to be considered.
And because that is evaluated cost based upon the cost of the previous custom plans, the binds (filter values) have to entered correctly too that have lead up to a potential generic plan having been chosen.

Frits Hoogland




On 18 Nov 2023, at 12:13, James Pang (chaolpan) <chaolpan@cisco.com> wrote:

Looks like it's not sql issue, manually running still use prepared statements and use same sql plan.

-----Original Message-----
From: Andreas Kretschmer <andreas@a-kretschmer.de>
Sent: Friday, November 17, 2023 5:17 PM
To: pgsql-performance@lists.postgresql.org
Subject: Re: simple query running long time within a long transaction.



Am 17.11.23 um 09:10 schrieb James Pang (chaolpan):

Hi,

   We found one simple query manually run very fast(finished in
several milliseconds), but there are 2 sessions within long
transaction to run same sql with same bind variables took tens of seconds.

you try to set plan_cache_mode to force_custom_plan, default is auto and with that and bind variables pg will use a generic plan.


Regards, Andreas

--
Andreas Kretschmer - currently still (garden leave)
Technical Account Manager (TAM)
www.enterprisedb.com