simple query running long time within a long transaction.

From: "James Pang (chaolpan)" <chaolpan(at)cisco(dot)com>
To: "pgsql-performance(at)lists(dot)postgresql(dot)org" <pgsql-performance(at)lists(dot)postgresql(dot)org>
Subject: simple query running long time within a long transaction.
Date: 2023-11-17 08:10:45
Message-ID: CO1PR11MB51856BF6EAD19EBEF9E59CB5D6B7A@CO1PR11MB5185.namprd11.prod.outlook.com
Views: Whole Thread | Raw Message | Download mbox | Resend email
Thread:
Lists: pgsql-performance

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

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Andreas Kretschmer 2023-11-17 09:17:18 Re: simple query running long time within a long transaction.
Previous Message Lincoln Swaine-Moore 2023-11-09 18:00:24 Re: Awkward Join between generate_series and long table