南大通用GBase 8c是一款多模多态数据库，支持主备式、分布式部署方式。对于故障和性能分析，内部提供丰富的工具和系统表或系统视图支撑实现。本文将介绍如何通过dbe_perf.statement系统视图分析SQL执行时间。

1、概述

dbe_perf.statement 实际上是一个视图，这个视图实际执行的是 get_instr_unique_sql() 内置函数，能够显示分布式CN节点或者主备式主DN节点上执行过的SQL语句的部分时间信息，比如SQL执行总耗时、执行器中的耗时、优化器中执行的耗时等。

它只能在CN或者主备式主节点上执行，不能在备DN上执行。

内置函数get_instr_unique_sql()的数据来自于 g_instance.stat_cxt.UniqueSQLHashtbl 哈希表。哈希表内存有限，所以不能保存所有的sql信息，通过配置 instr_unique_sql_count GUC参数（默认值是 100）可以调整 dbe_perf.statement 能够记录的sql的数据。节点重启后，g_instance.stat_cxt.UniqueSQLHashtbl 哈希表内容会被清空。

2、示例

下面的示例展示了benchmarksql测试中 UPDATE bmsql_warehouse SET w_ytd = w_ytd + $1 WHERE w_id = $2 语句的统计信息。

 

test=# select * from dbe_perf.statement where query ~ 'UPDATE bmsql_warehouse';

执行结果如下：

[ RECORD 1 ]
--------+----------------------------------------------------------------------
node_name            | cn1
node_id              | -1178713634
user_name            | test1
user_id              | 16974
unique_sql_id        | 739002000
query                | UPDATE bmsql_warehouse     SET w_ytd = w_ytd + $1     WHERE w_id = $2
n_calls              | 9339
min_elapse_time      | 150
max_elapse_time      | 26529
total_elapse_time    | 2512361
n_returned_rows      | 0
n_tuples_fetched     | 0
n_tuples_returned    | 0
n_tuples_inserted    | 0
n_tuples_updated     | 0
n_tuples_deleted     | 0
n_blocks_fetched     | 1
n_blocks_hit         | 1
n_soft_parse         | 0
n_hard_parse         | 0
db_time              | 2929210
CPU_time             | 906947
execution_time       | 0
parse_time           | 24
plan_time            | 0
rewrite_time         | 9
pl_execution_time    | 0
pl_compilation_time  | 0
data_io_time         | 0
net_send_info        | {"time":215081， "n_calls":28017， "size":1285855}
net_recv_info        | {"time":1385396， "n_calls":26612， "size":884261}
net_stream_send_info | {"time":0， "n_calls":0， "size":0}
net_stream_recv_info | {"time":0， "n_calls":0， "size":0}
last_updated         | 2022-12-12 13:51:59.767953+08
sort_count           | 0
sort_time            | 0
sort_mem_used        | 0
sort_spill_count     | 0
sort_spill_size      | 0
hash_count           | 0
hash_time            | 0
hash_mem_used        | 0
hash_spill_count     | 0
hash_spill_size      | 0

通过返回信息，可得知：

  • 在测试的这段时间这条sql执行了 9339次。
  • 每次执行的时间是 db_time / n_calls = 313us 实际消耗CPU的时间 CPU_time / n_calls = 97us。
  • 这条sql走lightproxy，所以 plan_time rewrite_time execution_time 都是0。

3、字段解析

  • n_calls

表示这个sql执行的次数，下面的时间都是总的时间，如果要计算平均时间需要除以 n_calls。

  • db_time

表示这个sql 执行的总时间， 用这个时间除以 n_calls 就是每条sql执行的平均时间。这个时间的计时从 ReadCommand 接收到 client的消息开始 (timeInfoRecordStart)， 到给client 发给 ReadyForQuery消息结束 (timeInfoRecordEnd)。

  • CPU_time

这个时间和db_time 的计时类似，和db_time 不同的是，它调用的是 clock_gettime(CLOCK_THREAD_CPUTIME_ID， &tv) API，也就是只计算CPU时间，不计算在内核中sleep的时间。

  • parse_time

统计的是pg_parse_query 函数内生成查询数的时间。

  • plan_time

统计的是 planner 函数 优化器生成执行计划的时间。

  • rewrite_time

统计的是 pg_rewrite_query 函数内查询重写的时间。

  • execution_time

统计的是 PortalRun 函数内执行器消耗的时间。

  • data_io_time

统计的是读取表的block的时间，因为CN上只有元数据，所以这个值很小。

  • net_send_info

统计的是CN向DN发送执行计划或者下推的sql而调用 com_send的次数，消耗的时间，发送数据量的大小。

  • net_recv_info

同net_send_info 统计的是CN调用 com_recv的次数，消耗的时间，接收数据的大小。

4、清除统计信息

如果想清空统计信息，重新开始统计，可调用 reset_unique_sql 内置函数。

reset_unique_sql 有三个入参：第一个入参可选 global 或 local，表示清除全局的或者本地的 sql。 第二个参数是 cleanType 用 all 即可， 第三个参数 cleanValue 用0 即可。

调用完后再查视图就会发现内容已清空。

test=# select reset_unique_sql('local'， 'all'， 0);
-[ RECORD 1 ]----+--
reset_unique_sql | t
test=# select * from dbe_perf.statement where query ~ 'UPDATE bmsql_warehouse';
(No rows)
test=#

以上就是通过系统视图查看SQL执行时间的方法。