前言
本文讨论一下KingbaseESV8R6数据库中如何计算数据库连接耗时。有这样一个场景，不借助第三方工具，在数据库服务端计算1000个数据库连接的总耗时，并取得每个连接耗时的平均值。怎样实现呢？我们可以借助kbbench工具。这是Kingbase数据库自带的一款客户端工具。
kbbench介绍
kbbench是一种在KingbaseES上运行基准测试的简单程序。
使用方法参考文档：https://help.kingbase.com.cn/v8/admin/reference/ref-client/sysbench.html?highlight=kbbench
测试
在数据库服务器上执行以下命令，注意在运行以下命令前要执行 kbbench -i 初始化此工具。并根据以上官方文档链接内容仔细阅读kbbench有关参数含义。
1.运行16线程测试1000并发连接耗时。
kingbase7@localhost sys_log]$ kbbench -c 1000 -t1 -j16 -S -n -USYSTEM test
transaction type: <builtin: select only>
scaling factor: 1
query mode: simple
number of clients: 1000
number of threads: 16
number of transactions per client: 1
number of transactions actually processed: 1000/1000
latency average = 9429.563 ms
tps = 106.049455 (including connections establishing)
tps = 107.145527 (excluding connections establishing)
另外开启窗口并执行以下sql，以便观察不同连接数对应的耗时，并计算并发1000个连接的耗时。
select now(),count(*) from sys_stat_activity ;\watch 0.01
在观察窗口中获取到以下信息并计算连接耗时。
Mon 31 Jul 2023 04:46:32 PM CST (every 0.01s)
now | count
-------------------------------+-------
2023-07-31 16:46:32.144347+08 | 10
(1 row)
Mon 31 Jul 2023 04:46:37 PM CST (every 0.01s)
now | count
-------------------------------+-------
2023-07-31 16:46:37.525781+08 | 990
(1 row)
TEST=# select '2023-07-31 16:46:37.525781+08'::timestamp - '2023-07-31 16:46:32.144347+08'::timestamp from dual;
?column?
-------------------------------
+000000000 00:00:05.381434000
(1 row)
1000连接总耗时5.49秒。
TEST=# select 5.381434000/980*1000;
?column?
------------------------
5.49125918367346939000
(1 row)
1000连接平均耗时0.00549秒。
TEST=# select 5.49125918367346939000/1000;
?column?
------------------------
0.00549125918367346939
(1 row)
2.运行60线程测试1000连接并发耗时。
1000个连接耗时测试，60线程耗时和16线程耗时接近。
[kingbase7@localhost sys_log]$ kbbench -c 1000 -t1 -j60 -S -n -USYSTEM test
transaction type: <builtin: select only>
scaling factor: 1
query mode: simple
number of clients: 1000
number of threads: 60
number of transactions per client: 1
number of transactions actually processed: 1000/1000
latency average = 9733.942 ms
tps = 102.733297 (including connections establishing)
tps = 107.095744 (excluding connections establishing)
Mon 31 Jul 2023 04:51:32 PM CST (every 0.01s)
now | count
-------------------------------+-------
2023-07-31 16:51:32.258220+08 | 10
(1 row)
Mon 31 Jul 2023 04:51:37 PM CST (every 0.01s)
now | count
-------------------------------+-------
2023-07-31 16:51:37.993811+08 | 975
(1 row)
TEST=# select '2023-07-31 16:51:37.993811+08'::timestamp - '2023-07-31 16:51:32.258220+08'::timestamp from dual;
?column?
-------------------------------
+000000000 00:00:05.735591000
(1 row)
1000连接总耗时5.94秒
TEST=# select 5.735591000/965*1000;
?column?
------------------------
5.94361761658031088000
(1 row)
1000连接平均耗时0.00594秒
TEST=# select 5.94361761658031088000/1000;
?column?
------------------------
0.00594361761658031088
(1 row)
3.运行200线程测试1000连接并发耗时。
[kingbase7@localhost sys_log]$ kbbench -c 1000 -t1 -j200 -S -n -USYSTEM test
transaction type: <builtin: select only>
scaling factor: 1
query mode: simple
number of clients: 1000
number of threads: 200
number of transactions per client: 1
number of transactions actually processed: 1000/1000
latency average = 4571.092 ms
tps = 218.766089 (including connections establishing)
tps = 260.840335 (excluding connections establishing)
并发线程增多时，建立连接速度加快很多。
Mon 31 Jul 2023 04:59:51 PM CST (every 0.01s)
now | count
-------------------------------+-------
2023-07-31 16:59:51.986852+08 | 10
(1 row)
Mon 31 Jul 2023 04:59:54 PM CST (every 0.01s)
now | count
-------------------------------+-------
2023-07-31 16:59:54.322502+08 | 736
(1 row)
TEST=# select '2023-07-31 16:59:54.322502+08'::timestamp - '2023-07-31 16:59:51.986852+08'::timestamp from dual;
?column?
-------------------------------
+000000000 00:00:02.335650000
(1 row)
1000连接总耗时3.21秒
TEST=# select 2.335650000/726*1000;
?column?
------------------------
3.21714876033057851000
(1 row)
1000连接平均耗时0.00321秒
TEST=# select 3.21714876033057851000/1000;
?column?
------------------------
0.00321714876033057851
(1 row)
4.运行200线程测试1000连接并发耗时,当第一次取消-S参数耗时增加。
[kingbase7@localhost ~]$ kbbench -c 1000 -t1 -j200 -n -USYSTEM test
transaction type: <builtin: TPC-B (sort of)>
scaling factor: 1
query mode: simple
number of clients: 1000
number of threads: 200
number of transactions per client: 1
number of transactions actually processed: 1000/1000
latency average = 25094.861 ms
tps = 39.848796 (including connections establishing)
tps = 42.126236 (excluding connections establishing)
Tue 01 Aug 2023 11:20:22 AM CST (every 0.01s)
now | count
-------------------------------+-------
2023-08-01 11:20:22.635371+08 | 986
(1 row)
Tue 01 Aug 2023 11:20:11 AM CST (every 0.01s)
now | count
-------------------------------+-------
2023-08-01 11:20:11.448474+08 | 10
(1 row)
TEST=# select '2023-08-01 11:20:22.635371+08'::timestamp - '2023-08-01 11:20:11.448474+08'::timestamp from dual;
?column?
-------------------------------
+000000000 00:00:11.186897000
(1 row)
1000连接总耗时11.46秒
TEST=# select 11.186897000/976*1000;
?column?
-------------------------
11.46198463114754098000
(1 row)
1000连接平均耗时0.0114秒
TEST=# select 11.46198463114754098000/1000;
?column?
------------------------
0.01146198463114754098
(1 row)
5.运行200线程测试1000连接并发耗时,当第二次并且以后取消-S参数耗时减少。
Tue 01 Aug 2023 11:39:22 AM CST (every 0.01s)
now | count
-------------------------------+-------
2023-08-01 11:39:22.287548+08 | 811
(1 row)
Tue 01 Aug 2023 11:39:19 AM CST (every 0.01s)
now | count
-------------------------------+-------
2023-08-01 11:39:19.595927+08 | 10
(1 row)
TEST=# select '2023-08-01 11:39:22.287548+08'::timestamp - '2023-08-01 11:39:19.595927+08'::timestamp from dual;
?column?
-------------------------------
+000000000 00:00:02.691621000
(1 row)
1000连接总耗时
TEST=# select 2.691621000/801*1000;
?column?
------------------------
3.36032584269662921000
(1 row)
1000连接平均耗时
TEST=# select 3.36032584269662921000/1000;
?column?
------------------------
0.00336032584269662921
(1 row)
总结
以上测试证明，使用kbbench可计算数据库连接的耗时。当不同参数设定可能会影响耗时，例如-j参数等。这需要根据客户现场的要求进行参数的调整和测试。本次测试模拟1000个会话连接数据库，每个客户端运行1个事务。
为什么取消-S参数后第一次耗时增加，第二次并且以后执行明显耗时减少呢？
首先，取消-S参数意味着客户端不仅仅执行select语句，而是对kbbench_branches，kbbench_history表执行dml操作，这点可以通过kbbench -d参数打印出日志查看。
安装sys_buffercache扩展插件后，通过如下sql查看。第一次执行取消-S操作，kbbench_accounts表等被缓存进shared_buffer，这次经过了物理IO读，读进shared_buffer，所以耗时10s左右，而第二次执行时，shared_buffer中的buffers没有明显增多，所以节省了物理IO时间，直接读缓存会省时不少。建议连接耗时测试不要取消-S参数，因为执行dml操作势必会增加耗时。
create extension sys_buffercache;
select c.relname, count(*) as buffers
from sys_buffercache b
inner join pg_class c on b.relfilenode = pg_relation_filenode(c.oid)
and b.reldatabase in (0, (select oid from pg_database where datname = current_database()))
group by c.relname
order by 2 desc;