偶然从网友的这篇博客中发现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
除了pgbench_accounts外稍微慢点以外,其它几个表的更新时间差不多。
并发数为4
现在最慢的是pgbench_branches,因为4个并发连接都要争抢它。但是总体的tps比1并发时提高了不少。
并发数为10
现在最慢的还是pgbench_branches,但pgbench_tellers也明显慢了起来。总体的tps和并发数为4时相比有所增加,但不明显。(测试用的环境是VM,分配给VM的CPU是2核)。
并发数为20
点击( 此处 )折叠或打开
现在最慢的变成
pgbench_tellers了,
总体的
tps也开始下降。
并发数为100
pgbench_tellers越发慢的明显了。
并发数为500
不仅对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写到一个脚本里再测
测试结果和之前没有用脚本时一致。
把脚本中的 更新pgbench_branches 的SQL语句移到 更新 pgbench_tellers的SQL语句 的前面再测
现在最慢的SQL变成pgbench_branches的更新了,验证了我的猜测,也算是
真相大白了。但是,从测试结果中还可以发现,先更新
pgbench_branches比后更新pgbench_branches相比,
总体的tps又有一个大幅度的下降,从403降到233。如果反过来考虑这件事,就是,
调整SQL的执行顺序有时候也可以作为一种性能调优的手段。
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;
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;
并发数为4
点击(此处)折叠或打开
- [chenhj@node2 ~]$ pgbench -c 4 -j 4 -t 10 -r pgbench
- starting vacuum...end.
- transaction type: TPC-B (sort of)
- scaling factor: 1
- query mode: simple
- number of clients: 4
- number of threads: 4
- number of transactions per client: 10
- number of transactions actually processed: 40/40
- tps = 1271.779219 (including connections establishing)
- tps = 1460.440323 (excluding connections establishing)
- statement latencies in milliseconds:
- 0.002700 \set nbranches 1 * :scale
- 0.000500 \set ntellers 10 * :scale
- 0.000425 \set naccounts 100000 * :scale
- 0.000675 \setrandom aid 1 :naccounts
- 0.000425 \setrandom bid 1 :nbranches
- 0.000325 \setrandom tid 1 :ntellers
- 0.000600 \setrandom delta -5000 5000
- 0.081725 BEGIN;
- 0.248250 UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
- 0.136400 SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
- 0.436850 UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
- 0.961600 UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
- 0.111075 INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
- 0.462825 END;
并发数为10
点击(此处)折叠或打开
- [chenhj@node2 ~]$ pgbench -c 10 -j 10 -t 10 -r pgbench
- starting vacuum...end.
- transaction type: TPC-B (sort of)
- scaling factor: 1
- query mode: simple
- number of clients: 10
- number of threads: 10
- number of transactions per client: 10
- number of transactions actually processed: 100/100
- tps = 1318.322040 (including connections establishing)
- tps = 1517.142190 (excluding connections establishing)
- statement latencies in milliseconds:
- 0.002500 \set nbranches 1 * :scale
- 0.000550 \set ntellers 10 * :scale
- 0.000480 \set naccounts 100000 * :scale
- 0.000570 \setrandom aid 1 :naccounts
- 0.000440 \setrandom bid 1 :nbranches
- 0.000350 \setrandom tid 1 :ntellers
- 0.000600 \setrandom delta -5000 5000
- 0.069060 BEGIN;
- 0.270230 UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
- 0.276860 SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
- 1.880150 UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
- 2.661570 UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
- 0.175470 INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
- 0.419380 END;
并发数为20
点击( 此处 )折叠或打开
- [chenhj@node2 ~]$ pgbench -c 20 -j 10 -t 10 -r pgbench
- starting vacuum...end.
- transaction type: TPC-B (sort of)
- scaling factor: 1
- query mode: simple
- number of clients: 20
- number of threads: 10
- number of transactions per client: 10
- number of transactions actually processed: 200/200
- tps = 1294.808465 (including connections establishing)
- tps = 1499.957626 (excluding connections establishing)
- statement latencies in milliseconds:
- 0.002695 \set nbranches 1 * :scale
- 0.000545 \set ntellers 10 * :scale
- 0.000550 \set naccounts 100000 * :scale
- 0.000640 \setrandom aid 1 :naccounts
- 0.000450 \setrandom bid 1 :nbranches
- 0.000605 \setrandom tid 1 :ntellers
- 0.000505 \setrandom delta -5000 5000
- 0.200460 BEGIN;
- 0.386675 UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
- 0.238615 SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
- 5.735790 UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
- 3.869125 UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
- 0.116305 INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
- 0.516330 END;
并发数为100
点击(此处)折叠或打开
- [chenhj@node2 ~]$ pgbench -c 100 -j 10 -t 10 -r pgbench
- starting vacuum...end.
- transaction type: TPC-B (sort of)
- scaling factor: 1
- query mode: simple
- number of clients: 100
- number of threads: 10
- number of transactions per client: 10
- number of transactions actually processed: 1000/1000
- tps = 994.032821 (including connections establishing)
- tps = 1175.266424 (excluding connections establishing)
- statement latencies in milliseconds:
- 0.002603 \set nbranches 1 * :scale
- 0.000715 \set ntellers 10 * :scale
- 0.000610 \set naccounts 100000 * :scale
- 0.000682 \setrandom aid 1 :naccounts
- 0.000485 \setrandom bid 1 :nbranches
- 0.000488 \setrandom tid 1 :ntellers
- 0.000547 \setrandom delta -5000 5000
- 0.364759 BEGIN;
- 0.730818 UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
- 0.322968 SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
- 63.065841 UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
- 7.542918 UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
- 0.152586 INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
- 0.740661 END;
并发数为500
点击(此处)折叠或打开
- [chenhj@node2 ~]$ pgbench -c 500 -j 10 -t 10 -r pgbench
- starting vacuum...end.
- transaction type: TPC-B (sort of)
- scaling factor: 1
- query mode: simple
- number of clients: 500
- number of threads: 10
- number of transactions per client: 10
- number of transactions actually processed: 5000/5000
- tps = 396.234567 (including connections establishing)
- tps = 414.176788 (excluding connections establishing)
- statement latencies in milliseconds:
- 0.003855 \set nbranches 1 * :scale
- 0.001171 \set ntellers 10 * :scale
- 0.000693 \set naccounts 100000 * :scale
- 0.000980 \setrandom aid 1 :naccounts
- 0.000886 \setrandom bid 1 :nbranches
- 0.000596 \setrandom tid 1 :ntellers
- 0.000603 \setrandom delta -5000 5000
- 0.746502 BEGIN;
- 7.766349 UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
- 1.093415 SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
- 1002.415717 UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
- 22.612090 UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
- 0.213186 INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
- 1.627372 END;
那么,为什么更新 pgbench_tellers比更新 pgbench_branches还慢呢?稍微想了想,终于明白了。
更新 pgbench_tellers的SQL语句在更新pgbench_branches的SQL语句前面执行,所以 pgbench_tellers已经帮 pgbench_branches挡住了绝大部分的并发。导致实际到达 pgbench_branches的并发数不是500而只有10,所以 pgbench_branches的更新很快。下面验证一下这个假设。
把pgbench的TCP-B测试SQL写到一个脚本里再测
点击(此处)折叠或打开
- [chenhj@node2 ~]$ cat test.sql
- \set nbranches 1 * :scale
- \set ntellers 10 * :scale
- \set naccounts 100000 * :scale
- \setrandom aid 1 :naccounts
- \setrandom bid 1 :nbranches
- \setrandom tid 1 :ntellers
- \setrandom delta -5000 5000
- BEGIN;
- UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
- SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
- UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
- UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
- INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
- END;
- [chenhj@node2 ~]$ pgbench -c 500 -j 10 -t 10 -r -f test.sql pgbench
- starting vacuum...end.
- transaction type: Custom query
- scaling factor: 1
- query mode: simple
- number of clients: 500
- number of threads: 10
- number of transactions per client: 10
- number of transactions actually processed: 5000/5000
- tps = 386.651133 (including connections establishing)
- tps = 403.524141 (excluding connections establishing)
- statement latencies in milliseconds:
- 0.002743 \set nbranches 1 * :scale
- 0.000700 \set ntellers 10 * :scale
- 0.001121 \set naccounts 100000 * :scale
- 0.000941 \setrandom aid 1 :naccounts
- 0.000488 \setrandom bid 1 :nbranches
- 0.000479 \setrandom tid 1 :ntellers
- 0.000695 \setrandom delta -5000 5000
- 0.669572 BEGIN;
- 7.178750 UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
- 1.119658 SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
- 1010.879585 UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
- 23.284097 UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
- 0.176437 INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
- 1.609216 END;
把脚本中的 更新pgbench_branches 的SQL语句移到 更新 pgbench_tellers的SQL语句 的前面再测
点击(此处)折叠或打开
- [chenhj@node2 ~]$ cat test2.sql
- \set nbranches 1 * :scale
- \set ntellers 10 * :scale
- \set naccounts 100000 * :scale
- \setrandom aid 1 :naccounts
- \setrandom bid 1 :nbranches
- \setrandom tid 1 :ntellers
- \setrandom delta -5000 5000
- BEGIN;
- UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
- SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
- UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
- UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
- INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
- END;
- [chenhj@node2 ~]$ pgbench -c 500 -j 10 -t 10 -r -f test2.sql pgbench
- starting vacuum...end.
- transaction type: Custom query
- scaling factor: 1
- query mode: simple
- number of clients: 500
- number of threads: 10
- number of transactions per client: 10
- number of transactions actually processed: 5000/5000
- tps = 228.028143 (including connections establishing)
- tps = 233.288608 (excluding connections establishing)
- statement latencies in milliseconds:
- 0.004425 \set nbranches 1 * :scale
- 0.000828 \set ntellers 10 * :scale
- 0.001644 \set naccounts 100000 * :scale
- 0.000938 \setrandom aid 1 :naccounts
- 0.000534 \setrandom bid 1 :nbranches
- 0.000507 \setrandom tid 1 :ntellers
- 0.000540 \setrandom delta -5000 5000
- 1.262434 BEGIN;
- 9.896378 UPDATE pgbench_accounts SET abalance = abalance + :delta WHERE aid = :aid;
- 1.454215 SELECT abalance FROM pgbench_accounts WHERE aid = :aid;
- 1880.677017 UPDATE pgbench_branches SET bbalance = bbalance + :delta WHERE bid = :bid;
- 0.879294 UPDATE pgbench_tellers SET tbalance = tbalance + :delta WHERE tid = :tid;
- 0.291396 INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES (:tid, :bid, :aid, :delta, CURRENT_TIMESTAMP);
- 4.006580 END;