跳转至

查看历史sql资源使用

查看SQL执行统计信息(pg_stat_statements扩展)

此扩展提供了SQL执行统计视图,包括如下信息:

  • SQL的调用次数,总的耗时,最快执行时间,最慢执行时间,平均执行时间,执行时间的方差(看出抖动),select返回行数或者insert/update/delete处理行数。
  • SQL的第一次调用的真实SQL,和真实SQL计划,创建此记录的时间戳
  • SQL的最近一次执行的开始时间戳,最近一次执行的消耗时间。

  • shared buffer的使用情况,命中,未命中,产生脏块,驱逐脏块。

  • local buffer的使用情况,命中,未命中,产生脏块,驱逐脏块。

  • temp buffer的使用情况,读了多少脏块,驱逐脏块。

  • 一条记录特点:忽略常量后相同的SQL会被记录成一条记录

  • csv日志中记录queryid列,记录忽略常量的SQL的hash值,且coordinator和executor保持相同queryId

  • sdaudit审计日志同样记录queryid列,queryid列会记录在log_event,audit_history_statements两个表中。

本扩展会在数据库初始化时默认安装

配置参数
pg_stat_statements.max (integer)
pg_stat_statements.max是由该模块跟踪的语句的最大数目(即pg_stat_statements视图中行的最大数量)。如果观测到的可区分的语句超过这个数量,最少被执行的语句的信息将会被丢弃。默认值为 5000。这个参数只能在服务器启动时设置。
pg_stat_statements.track (enum)
pg_stat_statements.track控制哪些语句会被该模块计数。指定top可以跟踪顶层语句(那些直接由客户端发出的语句),指定all还可以跟踪嵌套的语句(例如在函数中调用的语句),集群中不建议设置成all,all会导致executor日志中无法记录coordinator上的顶层语句。指定none可以禁用语句统计信息收集。默认值是top。 只有超级用户能够改变这个设置。
pg_stat_statements.track_utility (boolean)
pg_stat_statements.track_utility控制该模块是否会跟踪工具命令。工具命令是除了SELECT、INSERT、 UPDATE和DELETE之外所有的其他命令。默认值是on。 只有超级用户能够改变这个设置。
pg_stat_statements.save (boolean)
pg_stat_statements.save指定是否在服务器关闭之后还保存语句统计信息。如果被设置为off,那么关闭后不保存统计信息并且在服务器启动时也不会重新载入统计信息。默认值为on。这个参数只能在seaboxsql.conf文件中或者在服务器命令行上设置。该模块要求与pg_stat_statements.max成比例的额外共享内存。注意只要该模块被载入就会消耗这么多的内存,即便pg_stat_statements.track被设置为none。
pg_stat_statements.track_min_duration (integer)
pg_stat_statements.track_min_duration指定被记录语句执行时间最小值(单位秒),当语句的执行时间大于此值时,此语句本次执行的统计信息才会被记录.默认值为0,表示语句的所有执行过程的统计信息都会被记录。只有超级用户能够改变这个设置
pg_stat_statements.discard_policy (enum)
pg_stat_statements统计记录达到pg_stat_statements.max(默认5000条)后,指定淘汰策略,支持两种淘汰策略
  • calls (默认) 优先淘汰调用次数少的记录

  • max_time 优先淘汰执行时间短的记录,如果时间一致(精确到秒),再优先淘汰调用次数少的记录,注意精确到S,小于1S的时间值为0,还是按calls淘汰

推荐的配置
  • 推荐如下配置,pg_stat_statements.max配置参数需要重起集群,其他参数不需要重新启动
# seaboxsql.conf

-- 此项默认已经配置,不用修改
shared_preload_libraries = 'pg_stat_statements'

-- 此项默认为5000,占用约1M共享内存。如需记录更多内容,则调整后需要重起服务才能生效。
pg_stat_statements.max = 5000

-- 此项默认为none(禁用 pg_stat_statements), 如需开启, 建议设为 top
pg_stat_statements.track = 'top'

-- 根据实际情况配置,单位为S,短SQL 也关注则修改为0
pg_stat_statements.track_min_duration = 10

-- 淘汰策略推荐配置成max_time, 慢SQL避免淘汰,后期分析完,可以使用pg_stat_statements_reset(0,0,queryid)删除指定SQL
pg_stat_statements.discard_policy = 'max_time'
  • 集群配置修改建议 :通过seabox config 和 seabox notify reload 修改配置。
cl@test-4 $ seabox config -c pg_stat_statements.track -v 'top'
cl@test-4 $ seabox config -c pg_stat_statements.track_min_duration -v 10
cl@test-4 $ seabox config -c pg_stat_statements.discard_policy -v 'max_time'
cl@test-4 $ seabox notify reload                                         
字段说明
名称 类型 描述
userid oid 执行该语句的用户的 OID
dbid oid 在其中执行该语句的数据库的 OID
queryid bigint 内部哈希码,从语句的解析树计算得来
query text 模板形式,常量以1,2..形式代替
real_query text 第一次执行时的真实SQL
queryplan text 第一次执行时的真实SQL计划,如果没有计划则NULL,例如vacuum,copy,DDL等。
create_time timestamp with time zone 这条记录的创建时间戳
last_start_time timestamp with time zone 最近一次执行的开始时间戳
last_time double precision 最近一次执行的耗时,以豪秒为单位
calls bigint 被执行的次数
total_time double precision 在该语句中花费的总时间,以毫秒计
min_time double precision 在语句中花费的最短时间,以毫秒为单位
max_time double precision 在语句中花费的最长时间,以毫秒为单位
max_time_start_time timestamp with time zone 花费的最长时间语句的开始时间戳
mean_time double precision 在语句中花费的平均时间,以毫秒为单位
stddev_time double precision 在语句中花费的标准偏差时间,以毫秒为单位
rows bigint 该语句检索或影响的行总数
shared_blks_hit bigint 该语句造成的共享块缓冲命中总数
shared_blks_read bigint 该语句读取的共享块的总数
shared_blks_dirtied bigint 该语句弄脏的共享块的总数
shared_blks_written bigint 该语句写入的共享块的总数
local_blks_hit bigint 该语句造成的本地块缓冲命中总数
local_blks_read bigint 该语句读取的本地块的总数
local_blks_dirtied bigint 该语句弄脏的本地块的总数
local_blks_written bigint 该语句写入的本地块的总数
temp_blks_read bigint 该语句读取的临时块的总数
temp_blks_written bigint 该语句写入的临时块的总数
blk_read_time double precision 该语句花在读取块上的总时间,以毫秒计(如果track_io_timing 被启用,否则为零)
blk_write_time double precision 该语句花在写入块上的总时间,以毫秒计(如果track_io_timing 被启用,否则为零
  • 一些限制
  • shared_blks的统计: heap表支持共享内存,列存表不支持共享内存,所以这里shared_blks相关统计不适用列存统计
  • local_blks 任何情况都没有数字不支持
  • temp_blks的统计: PG引擎支持 VE引擎不支持。
使用示例
  • pg_stat_statements视图使用示例1:基本功能
-- 为了演示方便,设置了记录最小执行1S的SQL,防止其他SQL后台SQL干扰

seaboxsql=# show pg_stat_statements.track_min_duration;
-[ RECORD 1 ]-------------------------+--
pg_stat_statements.track_min_duration | 1

Time: 1.667 ms

-- 为了演示,首先清空pg_stat_statements视图内容

seaboxsql=# \x
Expanded display is on.
seaboxsql=# select pg_stat_statements_reset();
-[ RECORD 1 ]------------+-
pg_stat_statements_reset | 

Time: 2.685 ms
seaboxsql=# select * from pg_stat_statements;
(0 rows)

-- 翻倍t1表两次,此时pg_stat_statements表有一条记录,执行次数为2次,同时记录总时间,最大,最小时间 和总影响行数
-- 注意集群层只有时间记录和影响行的记录,没有shared_blk等相关统计信息,executor有相应的统计信息可以使用Utility模式登陆查询

seaboxsql=# insert into t1 select * from t1;
INSERT 0 10240000
Time: 9511.063 ms (00:09.511)
seaboxsql=# select * from pg_stat_statements;
-[ RECORD 1 ]-------+--------------------------------
userid              | 10
dbid                | 15362
queryid             | -8868872951518543902
query               | insert into t1 select * from t1
real_query          | insert into t1 select * from t1
queryplan           | Insert on t1  (cost=0.00..112.30 rows=10230 width=4)                       +
                    |   ->  Seq Scan on t1 t1_1  (cost=0.00..112.30 rows=10230 width=4)
create_time         | 2023-08-03 15:10:24.834458+08
last_start_time     | 2023-08-03 15:16:24.834458+08
last_time           | 9511.011
calls               | 1
total_time          | 9491.598292
min_time            | 9491.598292
max_time            | 9491.598292
mean_time           | 9491.598292
stddev_time         | 0
rows                | 10240000
shared_blks_hit     | 0
shared_blks_read    | 0
shared_blks_dirtied | 0
shared_blks_written | 0
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  - 

Time: 4.159 ms

seaboxsql=# insert into t1 select * from t1;
INSERT 0 20480000
Time: 22465.502 ms (00:22.466)

seaboxsql=# select * from pg_stat_statements;
-[ RECORD 1 ]-------+--------------------------------
userid              | 10
dbid                | 15362
queryid             | -8868872951518543902
query               | insert into t1 select * from t1
real_query          | insert into t1 select * from t1
queryplan           | Insert on t1  (cost=0.00..112.30 rows=10230 width=4)                       +
                    |   ->  Seq Scan on t1 t1_1  (cost=0.00..112.30 rows=10230 width=4)
create_time         | 2023-08-03 15:10:24.834458+08
last_start_time     | 2023-08-03 15:18:24.834458+08
last_time           | 22456.932105
calls               | 2
total_time          | 31948.530397000002
min_time            | 9491.598292
max_time            | 22456.932105
max_time_start_time | 2023-08-03 15:18:24.834458+08
mean_time           | 15974.265198500001
stddev_time         | 6482.666906499999
rows                | 30720000
shared_blks_hit     | 0
shared_blks_read    | 0
shared_blks_dirtied | 0
shared_blks_written | 0
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


-- executor有和coordinator的queryid相同的查询记录,但是query列为空 ,同时shared_blk等统计数据可能为非零

seaboxsql=# select * from pg_stat_statements where queryid = -8868872951518543902; 
-[ RECORD 1 ]-------+---------------------
userid              | 10
dbid                | 15362
queryid             | -8868872951518543902
query               | 
real_query          |
queryplan           |
create_time         | 2023-08-03 15:10:24.834458+08
last_start_time     | 2023-08-03 15:18:24.834458+08
last_time           | 22110.932105
calls               | 5
total_time          | 39172.907427
min_time            | 1130.869944
max_time            | 22163.271961
max_time_start_time | 2023-08-03 15:10:24.834458+08
mean_time           | 7834.581485399999
stddev_time         | 7708.686553041409
rows                | 13364224
shared_blks_hit     | 13399946
shared_blks_read    | 10057
shared_blks_dirtied | 18499
shared_blks_written | 16370
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
  • pg_stat_statements视图使用示例2:忽略常量相同的SQL,多次执行, 产生一条相同记录,
-- 忽略常量相同的SQL ,多次执行, 产生一条相同记录,

seaboxsql=# select pg_stat_statements_reset();
 pg_stat_statements_reset 
--------------------------
 
(1 row)

Time: 2.774 ms
seaboxsql=# select sum(c1)  from t1 where c1 > 10 limit 10;
     sum      
--------------
 204820254720
(1 row)

-- 查询pg_stat_statements,存在一条
-- queryid: query tree的hash值。
-- query字段:进行了常量替换,并把query字符串保存在SDDATA/sd_stat_tmp/pgss_query_texts.stat 中,共享内存中记录query字符串在文件中的位置和长度
-- real_query字段: query第一次执行时对应的真实SQL语句。

-- queryplan字段: query第一次执行时对应的真实SQL计划

-- last_start_time字段:  query最近执行的开始时间
-- last_time字段:  query最近执行的消耗时间
-- create_time字段: 这条记录的创建时间
-- calls :代表被调用多少次

seaboxsql=# \x
Expanded display is on.
seaboxsql=# select * from pg_stat_statements;
-[ RECORD 1 ]-------+-----------------------------------------------
userid              | 10
dbid                | 15362
queryid             | -7163204341675381197
query               | select sum(c1)  from t1 where c1 > $1 limit $2
real_query          | select sum(c1)  from t1 where c1 > 10 limit 10
queryplan           | Limit  (cost=146.40..146.41 rows=1 width=8)                                +
                    |   ->  Aggregate  (cost=146.40..146.41 rows=1 width=8)                      +
                    |         ->  Seq Scan on t1  (cost=0.00..137.88 rows=3410 width=4)          +
                    |               Filter: (c1 > 10)
create_time         | 2023-08-03 15:24:13.107722+08
last_start_time     | 2023-08-03 15:24:13.107722+08
last_time           | 6321.770174
calls               | 1
total_time          | 6321.770174
min_time            | 6321.770174
max_time            | 6321.770174
max_time_start_time | 2023-08-03 15:24:13.107722+08
mean_time           | 6321.770174
stddev_time         | 0
rows                | 1
shared_blks_hit     | 0
shared_blks_read    | 0
shared_blks_dirtied | 0
shared_blks_written | 0
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


-- 更换常量值,执行同样SQL,
seaboxsql=# select sum(c1)  from t1 where c1 > 20 limit 100;
-[ RECORD 1 ]-----
sum | 204819619840


-- 查询pg_stat_statements,只有一条记录,相应的统计数据累计,calls也累计

Time: 6011.575 ms (00:06.012)
seaboxsql=# select * from pg_stat_statements;
-[ RECORD 1 ]-------+-----------------------------------------------
userid              | 10
dbid                | 15362
queryid             | -7163204341675381197
query               | select sum(c1)  from t1 where c1 > $1 limit $2
real_query          | select sum(c1)  from t1 where c1 > 10 limit 10
queryplan           | Limit  (cost=146.40..146.41 rows=1 width=8)                                +
                    |   ->  Aggregate  (cost=146.40..146.41 rows=1 width=8)                      +
                    |         ->  Seq Scan on t1  (cost=0.00..137.88 rows=3410 width=4)          +
                    |               Filter: (c1 > 10)
create_time         | 2023-08-03 15:24:13.107722+08
last_start_time     | 2023-08-03 15:24:13.107722+08
last_time           | 6008.840969999999
calls               | 2
total_time          | 12330.611143999999
min_time            | 6008.840969999999
max_time            | 6321.770174
max_time_start_time | 2023-08-03 15:24:13.107722+08
mean_time           | 6165.305571999999
stddev_time         | 156.46460200000024
rows                | 2
shared_blks_hit     | 0
shared_blks_read    | 0
shared_blks_dirtied | 0
shared_blks_written | 0
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
  • pg_stat_statements_reset函数使用示例
-- pg_stat_statement_reset(),清空所有记录
seaboxsql=# select pg_stat_statements_reset();
-[ RECORD 1 ]------------+-
pg_stat_statements_reset | 


-- pg_stat_statement_reset()也可以传入queryid 删除指定记录

seaboxsql=# select pg_stat_statements_reset(0,0,-8868872951518543902);
-[ RECORD 1 ]------------+-
pg_stat_statements_reset | 

seaboxsql=# select  pg_stat_statements where queryid = -8868872951518543902; 
(0 rows)
  • 日志变更(增加queryid字段)使用示例

  • queryid只打印在csv日志中,普通txt日志不会打印。

  • corrdinator和executor会同时记录一个语句的queryid,参见如下例子演示使用方法。

```sql

– 开启日志收集功能和csv日志

cl@test-4 ~/code/seaboxmpp2/build (mlz_res_monitor?) $ seabox config -c logging_collector -v 'on';
cl@test-4 ~/code/seaboxmpp2/build (mlz_res_monitor?) $ seabox config -c log_statement -v "all";
cl@test-4 ~/code/seaboxmpp2/build (mlz_res_monitor?) $ seabox config -c log_destination -v "'csvlog'";
cl@test-4 ~/code/seaboxmpp2/build (mlz_res_monitor?) $ seabox config -c log_duration -v on;
cl@test-4 ~/code/seaboxmpp2/build (mlz_res_monitor?) $ seabox restart -a

– 在coordinator运行如下SQL

seaboxsql=# insert into t1 select * from generate_series(1,1000); INSERT 0 1000

– pg_stat_statements 已经查到此SQL

seaboxsql=# select * from pg_stat_statements where query like '%generate%'; userid | dbid | queryid | query | calls | total_time | min_time | max_time | mean_time | stddev_time | rows | shared_blks_hit | shared_blks_read | shared_blks_dirtied | shared_b lks_written | local_blks_hit | local_blks_read | local_blks_dirtied | local_blks_written | temp_blks_read | temp_blks_written | blk_read_time | blk_write_time --------+-------+----------------------+-----------------------------------------------------+-------+------------+----------+----------+-----------+-------------+------+-----------------+------------------+---------------------+--------- ------------+----------------+-----------------+--------------------+--------------------+----------------+-------------------+---------------+---------------- 10 | 15362 | -5157636531780210393 | insert into t1 select * from generate_series(1,2) | 1 | 0.000863 | 0.000863 | 0.000863 | 0.000863 | 0 | 0 | 0 | 0 | 0 |
0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 (1 row)

– coordinator日志,在SQL结束时 ,记录了queryid-5157636531780210393

2022-12-13 18:37:59.777 CST,10,"cl","seaboxsql",16933,"[local]",639855a6.4225,118,"idle",2022-12-13 18:36:22 CST,6/36,0,con2251799813685262 ,cmd51 ,,exec-1 ,slice-1 ,dx0 ,x0 ,sx1 ,LOG,00000,"statement: insert into t1 select * from generate_series(1,1000);",,,,,,,,,"ssql" 2022-12-13 18:37:59.791 CST,10,"cl","seaboxsql",16933,"[local]",639855a6.4225,120,"INSERT",2022-12-13 18:36:22 CST,6/0,0,con2251799813685262 ,cmd52 ,queryid-5157636531780210393,exec-1 ,slice-1 ,dx0 ,x0 ,sx0 ,LOG,00000,"duration: 14.679 ms

– executor上可以查到相同的queryid, 可能有多条记录(多slice等情况)

2022-12-13 18:37:59.787 CST,10,"cl","seaboxsql",18006,"10.10.0.7:64262",639855f3.4656,12,"idle",2022-12-13 18:37:39 CST,2/22,0,con2251799813685262 ,cmd52 ,queryid-5157636531780210393,exec0 ,slice0 ,dx60001 ,x0 ,sx1 ,LOG,00000,"statement: insert into t1 select * from generate_series(1,1000);",,,,,,"insert into t1 select * from generate_series(1,1000);",,,"" 2022-12-13 18:37:59.790 CST,10,"cl","seaboxsql",18006,"10.10.0.7:64262",639855f3.4656,14,"MPPEXEC INSERT",2022-12-13 18:37:39 CST,2/22,768,con2251799813685262 ,cmd52 ,queryid-5157636531780210393,exec0 ,slice0 ,dx60001 ,x768 ,sx1 ,LOG,00000,"duration: 2.685 ms",,,,,,,,,"" 2022-12-13 18:37:59.790 CST,10,"cl","seaboxsql",18006,"10.10.0.7:64262",639855f3.4656,16,"idle in transaction",2022-12-13 18:37:39 CST,2/22,768,con2251799813685262 ,cmd0 ,queryid-5157636531780210393,exec0 ,slice-1 ,dx60001 ,x768 ,sx1 ,LOG,00000,"DTM protocol command 'Distributed Prepare' for gid = 60001",,,,,,,,,"" 2022-12-13 18:37:59.791 CST,10,"cl","seaboxsql",18006,"10.10.0.7:64262",639855f3.4656,18,"idle",2022-12-13 18:37:39 CST,2/0,0,con2251799813685262 ,cmd0 ,queryid-5157636531780210393,exec0 ,slice-1 ,dx60001 ,x0 ,sx0 ,LOG,00000,"DTM protocol command 'Distributed Commit Prepared' for gid = 60001",,,,,,,,,""

```