从pgbench性能测试结果中发现SQL延迟的规律

本文涉及的产品
性能测试 PTS,5000VUM额度
简介: 偶然从网友的这篇博客中发现pgbench的TPC-B测试结果中有一个比较奇怪的地方 http://blog.chinaunix.net/uid-20802110-id-4889543.
偶然从网友的这篇博客中发现pgbench的TPC-B测试结果中有一个比较奇怪的地方
http://blog.chinaunix.net/uid-20802110-id-4889543.html
-------------------------------------------
-bash-4.1$ /usr/pgsql-9.4/bin/pgbench -c 800 -t 5 -j 4  -r pgbench
starting vacuum...end.
transaction type: TPC-B (sort of)
scaling factor: 1
query mode: simple
number of clients: 800
number of threads: 4
number of transactions per client: 5
number of transactions actually processed: 4000/4000
latency average: 0.000 ms
tps = 217.188339 (including connections establishing)
tps = 243.570070 (excluding connections establishing)
statement latencies in milliseconds:
0.007152 \set nbranches 1 * :scale
0.001217 \set ntellers 10 * :scale
0.000891 \set naccounts 100000 * :scale
0.001649 \setrandom aid 1 :naccounts
0.000924 \setrandom bid 1 :nbranches
0.000974 \setrandom tid 1 :ntellers
0.002318 \setrandom delta -5000 5000
43.159543 BEGIN;
67.412356 UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
19.172284 SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
2483.177474 UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;                          -----延迟非常明显,可以从此入手
37.104961 UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
0.466527 INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
3.609726 END;
-------------------------------------------

为什么说它奇怪?因为这个大的延迟无疑应该是高并发争用导致的。但是pgbench_tellers中有10条记录,pgbench_branches中只有一条记录,按道理对pgbench_branches的争用比pgbench_tellers还厉害,为什么pgbench_branches反而很快呢?


于是,我在自己的环境中,逐步增加并发数再现了一下这个问题。

并发数为1

点击(此处)折叠或打开

[chenhj@node2 ~]$ pgbench -c 1 -j 1 -t 10 -r pgbench
starting vacuum...end.
transaction type: TPC-B (sort of)
scaling factor: 1
query mode: simple
number of clients: 1
number of threads: 1
number of transactions per client: 10
number of transactions actually processed: 10/10
tps = 701.016474 (including connections establishing)
tps = 792.832792 (excluding connections establishing)
statement latencies in milliseconds:
    0.002800    \set nbranches 1 * :scale
    0.000500    \set ntellers 10 * :scale
    0.000400    \set naccounts 100000 * :scale
    0.000600    \setrandom aid 1 :naccounts
    0.000600    \setrandom bid 1 :nbranches
    0.000500    \setrandom tid 1 :ntellers
    0.000400    \setrandom delta -5000 5000
    0.052700    BEGIN;
    0.272300    UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
    0.139800    SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
    0.157700    UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
    0.133500    UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
    0.118500    INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
    0.369200    END;
除了pgbench_accounts外稍微慢点以外,其它几个表的更新时间差不多。

并发数为4

点击(此处)折叠或打开

  1. [chenhj@node2 ~]$ pgbench -c 4 -j 4 -t 10 -r pgbench
  2. starting vacuum...end.
  3. transaction type: TPC-B (sort of)
  4. scaling factor: 1
  5. query mode: simple
  6. number of clients: 4
  7. number of threads: 4
  8. number of transactions per client: 10
  9. number of transactions actually processed: 40/40
  10. tps = 1271.779219 (including connections establishing)
  11. tps = 1460.440323 (excluding connections establishing)
  12. statement latencies in milliseconds:
  13. 0.002700    \set nbranches 1 * :scale
  14. 0.000500    \set ntellers 10 * :scale
  15. 0.000425    \set naccounts 100000 * :scale
  16. 0.000675    \setrandom aid 1 :naccounts
  17. 0.000425    \setrandom bid 1 :nbranches
  18. 0.000325    \setrandom tid 1 :ntellers
  19. 0.000600    \setrandom delta -5000 5000
  20. 0.081725    BEGIN;
  21. 0.248250    UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
  22. 0.136400    SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
  23. 0.436850    UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
  24. 0.961600    UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
  25. 0.111075    INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
  26. 0.462825    END;
现在最慢的是pgbench_branches,因为4个并发连接都要争抢它。但是总体的tps比1并发时提高了不少。

并发数为10

点击(此处)折叠或打开

  1. [chenhj@node2 ~]$ pgbench -c 10 -j 10 -t 10 -r pgbench
  2. starting vacuum...end.
  3. transaction type: TPC-B (sort of)
  4. scaling factor: 1
  5. query mode: simple
  6. number of clients: 10
  7. number of threads: 10
  8. number of transactions per client: 10
  9. number of transactions actually processed: 100/100
  10. tps = 1318.322040 (including connections establishing)
  11. tps = 1517.142190 (excluding connections establishing)
  12. statement latencies in milliseconds:
  13.     0.002500    \set nbranches 1 * :scale
  14.     0.000550    \set ntellers 10 * :scale
  15.     0.000480    \set naccounts 100000 * :scale
  16.     0.000570    \setrandom aid 1 :naccounts
  17.     0.000440    \setrandom bid 1 :nbranches
  18.     0.000350    \setrandom tid 1 :ntellers
  19.     0.000600    \setrandom delta -5000 5000
  20.     0.069060    BEGIN;
  21.     0.270230    UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
  22.     0.276860    SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
  23.     1.880150    UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
  24.     2.661570    UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
  25.     0.175470    INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
  26.     0.419380    END;
现在最慢的还是pgbench_branches,但pgbench_tellers也明显慢了起来。总体的tps和并发数为4时相比有所增加,但不明显。(测试用的环境是VM,分配给VM的CPU是2核)。

并发数为20
点击( 此处 )折叠或打开
  1. [chenhj@node2 ~]$ pgbench -c 20 -j 10 -t 10 -r pgbench
  2. starting vacuum...end.
  3. transaction type: TPC-B (sort of)
  4. scaling factor: 1
  5. query mode: simple
  6. number of clients: 20
  7. number of threads: 10
  8. number of transactions per client: 10
  9. number of transactions actually processed: 200/200
  10. tps = 1294.808465 (including connections establishing)
  11. tps = 1499.957626 (excluding connections establishing)
  12. statement latencies in milliseconds:
  13.     0.002695    \set nbranches 1 * :scale
  14.     0.000545    \set ntellers 10 * :scale
  15.     0.000550    \set naccounts 100000 * :scale
  16.     0.000640    \setrandom aid 1 :naccounts
  17.     0.000450    \setrandom bid 1 :nbranches
  18.     0.000605    \setrandom tid 1 :ntellers
  19.     0.000505    \setrandom delta -5000 5000
  20.     0.200460    BEGIN;
  21.     0.386675    UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
  22.     0.238615    SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
  23.     5.735790    UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
  24.     3.869125    UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
  25.     0.116305    INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
  26.     0.516330    END;
现在最慢的变成 pgbench_tellers了, 总体的 tps也开始下降。

并发数为100

点击(此处)折叠或打开

  1. [chenhj@node2 ~]$ pgbench -c 100 -j 10 -t 10 -r pgbench
  2. starting vacuum...end.
  3. transaction type: TPC-B (sort of)
  4. scaling factor: 1
  5. query mode: simple
  6. number of clients: 100
  7. number of threads: 10
  8. number of transactions per client: 10
  9. number of transactions actually processed: 1000/1000
  10. tps = 994.032821 (including connections establishing)
  11. tps = 1175.266424 (excluding connections establishing)
  12. statement latencies in milliseconds:
  13.     0.002603    \set nbranches 1 * :scale
  14.     0.000715    \set ntellers 10 * :scale
  15.     0.000610    \set naccounts 100000 * :scale
  16.     0.000682    \setrandom aid 1 :naccounts
  17.     0.000485    \setrandom bid 1 :nbranches
  18.     0.000488    \setrandom tid 1 :ntellers
  19.     0.000547    \setrandom delta -5000 5000
  20.     0.364759    BEGIN;
  21.     0.730818    UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
  22.     0.322968    SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
  23.     63.065841    UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
  24.     7.542918    UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
  25.     0.152586    INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
  26.     0.740661    END;
pgbench_tellers越发慢的明显了。

并发数为500

点击(此处)折叠或打开

  1. [chenhj@node2 ~]$ pgbench -c 500 -j 10 -t 10 -r pgbench
  2. starting vacuum...end.
  3. transaction type: TPC-B (sort of)
  4. scaling factor: 1
  5. query mode: simple
  6. number of clients: 500
  7. number of threads: 10
  8. number of transactions per client: 10
  9. number of transactions actually processed: 5000/5000
  10. tps = 396.234567 (including connections establishing)
  11. tps = 414.176788 (excluding connections establishing)
  12. statement latencies in milliseconds:
  13.     0.003855    \set nbranches 1 * :scale
  14.     0.001171    \set ntellers 10 * :scale
  15.     0.000693    \set naccounts 100000 * :scale
  16.     0.000980    \setrandom aid 1 :naccounts
  17.     0.000886    \setrandom bid 1 :nbranches
  18.     0.000596    \setrandom tid 1 :ntellers
  19.     0.000603    \setrandom delta -5000 5000
  20.     0.746502    BEGIN;
  21.     7.766349    UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
  22.     1.093415    SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
  23.     1002.415717    UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
  24.     22.612090    UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
  25.     0.213186    INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
  26.     1.627372    END;
不仅对pgbench_tellers的更新慢的离谱,总的tps也下降的非常厉害,还不到峰值时的3分之1。(这也说明了,控制好到达DB的连接数多么重要。)

那么,为什么更新 pgbench_tellers比更新 pgbench_branches还慢呢?稍微想了想,终于明白了。
更新 pgbench_tellers的SQL语句在更新pgbench_branches的SQL语句前面执行,所以 pgbench_tellers已经帮 pgbench_branches挡住了绝大部分的并发。导致实际到达 pgbench_branches的并发数不是500而只有10,所以 pgbench_branches的更新很快。下面验证一下这个假设。

把pgbench的TCP-B测试SQL写到一个脚本里再测

点击(此处)折叠或打开

  1. [chenhj@node2 ~]$ cat test.sql
  2. \set nbranches 1 * :scale
  3. \set ntellers 10 * :scale
  4. \set naccounts 100000 * :scale
  5. \setrandom aid 1 :naccounts
  6. \setrandom bid 1 :nbranches
  7. \setrandom tid 1 :ntellers
  8. \setrandom delta -5000 5000
  9. BEGIN;
  10. UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
  11. SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
  12. UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
  13. UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
  14. INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
  15. END;
  16. [chenhj@node2 ~]$ pgbench -c 500 -j 10 -t 10 -r -f test.sql pgbench
  17. starting vacuum...end.
  18. transaction type: Custom query
  19. scaling factor: 1
  20. query mode: simple
  21. number of clients: 500
  22. number of threads: 10
  23. number of transactions per client: 10
  24. number of transactions actually processed: 5000/5000
  25. tps = 386.651133 (including connections establishing)
  26. tps = 403.524141 (excluding connections establishing)
  27. statement latencies in milliseconds:
  28.     0.002743 \set nbranches 1 * :scale
  29.     0.000700 \set ntellers 10 * :scale
  30.     0.001121 \set naccounts 100000 * :scale
  31.     0.000941 \setrandom aid 1 :naccounts
  32.     0.000488 \setrandom bid 1 :nbranches
  33.     0.000479 \setrandom tid 1 :ntellers
  34.     0.000695 \setrandom delta -5000 5000
  35.     0.669572 BEGIN;
  36.     7.178750 UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
  37.     1.119658 SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
  38.     1010.879585 UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
  39.     23.284097 UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
  40.     0.176437 INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
  41.     1.609216 END;
测试结果和之前没有用脚本时一致。

把脚本中的 更新pgbench_branches 的SQL语句移到 更新 pgbench_tellers的SQL语句 的前面再测

点击(此处)折叠或打开

  1. [chenhj@node2 ~]$ cat test2.sql
  2. \set nbranches 1 * :scale
  3. \set ntellers 10 * :scale
  4. \set naccounts 100000 * :scale
  5. \setrandom aid 1 :naccounts
  6. \setrandom bid 1 :nbranches
  7. \setrandom tid 1 :ntellers
  8. \setrandom delta -5000 5000
  9. BEGIN;
  10. UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
  11. SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
  12. UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
  13. UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
  14. INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
  15. END;
  16. [chenhj@node2 ~]$ pgbench -c 500 -j 10 -t 10 -r -f test2.sql pgbench
  17. starting vacuum...end.
  18. transaction type: Custom query
  19. scaling factor: 1
  20. query mode: simple
  21. number of clients: 500
  22. number of threads: 10
  23. number of transactions per client: 10
  24. number of transactions actually processed: 5000/5000
  25. tps = 228.028143 (including connections establishing)
  26. tps = 233.288608 (excluding connections establishing)
  27. statement latencies in milliseconds:
  28.     0.004425    \set nbranches 1 * :scale
  29.     0.000828    \set ntellers 10 * :scale
  30.     0.001644    \set naccounts 100000 * :scale
  31.     0.000938    \setrandom aid 1 :naccounts
  32.     0.000534    \setrandom bid 1 :nbranches
  33.     0.000507    \setrandom tid 1 :ntellers
  34.     0.000540    \setrandom delta -5000 5000
  35.     1.262434    BEGIN;
  36.     9.896378    UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
  37.     1.454215    SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
  38.     1880.677017    UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
  39.     0.879294    UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
  40.     0.291396    INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
  41.     4.006580    END;
现在最慢的SQL变成pgbench_branches的更新了,验证了我的猜测,也算是 真相大白了。但是,从测试结果中还可以发现,先更新 pgbench_branches比后更新pgbench_branches相比, 总体的tps又有一个大幅度的下降,从403降到233。如果反过来考虑这件事,就是, 调整SQL的执行顺序有时候也可以作为一种性能调优的手段。








相关实践学习
通过性能测试PTS对云服务器ECS进行规格选择与性能压测
本文为您介绍如何利用性能测试PTS对云服务器ECS进行规格选择与性能压测。
相关文章
|
6月前
|
SQL 存储 数据库
Python 的安全性和测试:什么是 SQL 注入攻击?如何防范 SQL 注入?
Python 的安全性和测试:什么是 SQL 注入攻击?如何防范 SQL 注入?
91 1
|
6月前
|
SQL 数据库
SQL 中的 NULL 值:定义、测试和处理空数据,以及 SQL UPDATE 语句的使用
NULL 值是指字段没有值的情况。如果表中的字段是可选的,那么可以插入新记录或更新记录而不向该字段添加值。此时,该字段将保存为 NULL 值。需要注意的是,NULL 值与零值或包含空格的字段不同。具有 NULL 值的字段是在记录创建期间留空的字段。
113 0
|
SQL 关系型数据库 数据挖掘
软件测试|教你学会SQL LEFT JOIN的使用
软件测试|教你学会SQL LEFT JOIN的使用
64 0
|
SQL 存储 关系型数据库
软件测试|SQL JOIN的用法,你会了吗?
软件测试|SQL JOIN的用法,你会了吗?
74 0
|
6月前
|
SQL 安全 关系型数据库
接上篇文章,在测试宝塔 WAF 的未授权访问漏洞时无意间还发现了一个 SQL 注入漏洞
接上篇文章,在测试宝塔 WAF 的未授权访问漏洞时无意间还发现了一个 SQL 注入漏洞,品相还不错,可执行任意 SQL 语句。 总之,吃了一惊,一个防 SQL 注入的工具居然也有 SQL 注入漏洞。 请看这段代码
573 8
|
4月前
|
SQL 安全 关系型数据库
使用SQLMap进行SQL注入测试
使用SQLMap进行SQL注入测试
|
6月前
|
SQL 测试技术 网络安全
Python之SQLMap:自动SQL注入和渗透测试工具示例详解
Python之SQLMap:自动SQL注入和渗透测试工具示例详解
676 0
|
6月前
|
SQL 关系型数据库 MySQL
Hive【基础知识 02-1】【Hive CLI 命令行工具使用】【准备阶段-建库、建表、导入数据、编写测试SQL脚本并上传HDFS】
【4月更文挑战第7天】Hive【基础知识 02-1】【Hive CLI 命令行工具使用】【准备阶段-建库、建表、导入数据、编写测试SQL脚本并上传HDFS】
85 0
|
6月前
|
SQL 数据挖掘 关系型数据库
「SQL面试题库」 No_87 学生们参加各科测试的次数
「SQL面试题库」 No_87 学生们参加各科测试的次数
|
11月前
|
SQL 网络安全 数据库
2021年中职“网络安全“江西省赛题—B-4:SQL注入测试(PL)
2021年中职“网络安全“江西省赛题—B-4:SQL注入测试(PL)
85 2