測(cè)試場(chǎng)景MySQL 5.7.12主要測(cè)試 不同刷盤(pán)參數(shù) 對(duì)性能的影響, 使用以下三個(gè)場(chǎng)景:sync_binlog=1, innodb_flush_log_at_trx_commit=1, 簡(jiǎn)寫(xiě)為b1e1 (binlog-1-engine-1)sync_binlog=0, innodb_flush_log_at_trx_commit=1, 簡(jiǎn)寫(xiě)為b0e1sync_binlog=0, innodb_flush_log_at_trx_commit=0, 簡(jiǎn)寫(xiě)為b0e0
MySQL 環(huán)境搭建使用 MySQL sandbox, 對(duì)應(yīng)三個(gè)場(chǎng)景的啟動(dòng)參數(shù)如下:1. ./start --sync-binlog=1 --log-bin=bin --server-id=5712 --gtid-mode=ON --enforce-gtid-consistency=1 --log-slave-updates=12. ./start --sync-binlog=0 --log-bin=bin --server-id=5712 --gtid-mode=ON --enforce-gtid-consistency=1 --log-slave-updates=13. ./start --sync-binlog=0 --log-bin=bin --server-id=5712 --gtid-mode=ON --enforce-gtid-consistency=1 --log-slave-updates=1 --innodb-flush-log-at-trx-commit=0
壓力生成使用sysbench:
mysql -h127.0.0.1 -P5712 -uroot -pmsandbox -e"truncate table test.sbtest1"; /opt/sysbench-0.5/dist/bin/sysbench --test=/opt/sysbench-0.5/dist/db/insert.lua --mysql-table-engine=innodb --mysql-host=127.0.0.1 --mysql-user=root --mysql-password=msandbox --mysql-port=5712 --oltp-table-size=1000000 --mysql-db=test --oltp-table-name=stest --num-threads=1 --max-time=30 --max-requests=1000000000 --oltp-auto-inc=off --db-driver=mysql run
性能觀測(cè)工具使用systemtap(簡(jiǎn)稱stap), version 2.7/0.160
基準(zhǔn)在沒(méi)有觀測(cè)壓力的情況下, 對(duì)三種場(chǎng)景分別進(jìn)行基準(zhǔn)測(cè)試, 用以矯正之后測(cè)試的誤差:
場(chǎng)景sysbench事務(wù)數(shù)b1e167546b0e1125699b0e0181612
火焰圖與offcpu火焰圖火焰圖是Brendan Gregg首創(chuàng)的表示性能的圖形方式, 其可以直觀的看到壓力的分布. Brendan提供了豐富的工具生成火焰圖.
火焰圖比較b0e1和b0e0使用stap腳本獲取CPU profile, 并生成火焰圖(火焰圖生成的命令略, 參看Brendan的文檔)
stap腳本
global tids probe process("/home/huangyan/sandboxes/5.7.12/bin/mysqld").function("mysql_execute_command") { if (pid() == target() && tids[tid()] == 0) { tids[tid()] = 1; } } global oncpu probe timer.profile { if (tids[tid()] == 1) { oncpu[ubacktrace()] <<< 1; } } probe timer.s(10) { exit(); } probe end { foreach (i in oncpu+) { print_stack(i); printf("\t%d\n", @count(oncpu[i])); } }
注意:1. 腳本只抓取MySQL的用戶線程的CPU profile, 不抓取后臺(tái)進(jìn)程.2. 腳本只抓取10s, 相當(dāng)于對(duì)整個(gè)sysbench的30s過(guò)程進(jìn)行了短期抽樣.
b0e1生成的火焰圖
性能
在開(kāi)啟觀測(cè)的情況下, 觀察性能:
場(chǎng)景sysbench事務(wù)數(shù)b0e1119274b0e0166424
分析
在生成的火焰圖中, 可以看到:
在b0e1場(chǎng)景中, _ZL27log_write_flush_to_disk_lowv的占比是12.93%, 其絕大部分時(shí)間是用于將innodb的log刷盤(pán).在b0e0場(chǎng)景中, _ZL27log_write_flush_to_disk_lowv的開(kāi)銷被節(jié)省掉, 理論上的事務(wù)數(shù)比例應(yīng)是1-12.93%=87.07%, 實(shí)際事務(wù)數(shù)的比例是119274/166424=71.67%, 誤差較大誤差較大的問(wèn)題, 要引入offcpu來(lái)解決.
offcpu在之前的分析中我們看到理論和實(shí)際的事務(wù)數(shù)誤差較大. 考慮_ZL27log_write_flush_to_disk_lowv的主要操作是IO操作, IO操作開(kāi)始, 進(jìn)程就會(huì)被OS進(jìn)行上下文切換換下臺(tái), 以等待IO操作結(jié)束, 那么只分析CPU profile就忽略了IO等待的時(shí)間, 也就是說(shuō)_ZL27log_write_flush_to_disk_lowv的開(kāi)銷被低估了.
offcpu也是Brendan Gregg提出的概念. 對(duì)于IO操作的觀測(cè), 除了CPU profile(稱為oncpu時(shí)間), 還需要觀測(cè)其上下文切換的代價(jià), 即offcpu時(shí)間.
修改一下stap腳本可以觀測(cè)offcpu時(shí)間. 不過(guò)為了將oncpu和offcpu的時(shí)間顯示在一張火焰圖上作對(duì)比, 我對(duì)于Brendan的工具做了微量修改, 本文將不介紹這些修改.
stap腳本
global tids probe process("/home/huangyan/sandboxes/5.7.12/bin/mysqld").function("mysql_execute_command") { if (pid() == target() && tids[tid()] == 0) { tids[tid()] = 1; } } global oncpu, offcpu, timer_count, first_cpu_id = -1; probe timer.profile { if (first_cpu_id == -1) { first_cpu_id = cpu(); } if (tids[tid()] == 1) { oncpu[ubacktrace()] <<< 1; } if (first_cpu_id == cpu()) { timer_count++; } } global switchout_ustack, switchout_timestamp probe scheduler.ctxswitch { if (tids[prev_tid] == 1) { switchout_ustack[prev_tid] = ubacktrace(); switchout_timestamp[prev_tid] = timer_count; } if (tids[next_tid] == 1 && switchout_ustack[next_tid] != "") { offcpu[switchout_ustack[next_tid]] <<< timer_count - switchout_timestamp[next_tid]; switchout_ustack[next_tid] = ""; } } probe timer.s(10) { exit(); } probe end { foreach (i in oncpu+) { print_stack(i); printf("\t%d\n", @sum(oncpu[i])); } foreach (i in offcpu+) { printf("---"); print_stack(i); printf("\t%d\n", @sum(offcpu[i])); } }
注意: timer.profile的說(shuō)明中是這樣寫(xiě)的:
Profiling timers are available to provide probes that execute on all CPUs at each system tick.
也就是說(shuō)在一個(gè)時(shí)間片中, timer.profile會(huì)對(duì)每一個(gè)CPU調(diào)用一次. 因此代碼中使用了如下代碼, 保證時(shí)間片技術(shù)的正確性:
if (first_cpu_id == cpu()) { timer_count++; }
b0e1生成的帶有offcpu的火焰圖
性能
由于變更了觀測(cè)腳本, 需要重新觀測(cè)性能以減小誤差:
場(chǎng)景sysbench事務(wù)數(shù)b0e1105980b0e0164739
分析
在火焰圖中, 可以看到:1. _ZL27log_write_flush_to_disk_lowv的占比為31.23%2. 理論上的事務(wù)數(shù)比例應(yīng)是1-31.23%=68.77%, 實(shí)際事務(wù)數(shù)的比例是105980/164739=64.33%, 誤差較小.
觀測(cè)誤差的矯正在比較b0e1和b0e0兩個(gè)場(chǎng)景時(shí), 獲得了比較好的結(jié)果. 但同樣的方法在比較b1e1和b0e1兩個(gè)場(chǎng)景時(shí), 出現(xiàn)了一些誤差.
誤差現(xiàn)象b1e1的火焰圖如圖:
其中_ZN13MYSQL_BIN_LOG16sync_binlog_fileEb(sync_binlog的函數(shù))占比為26.52%.
但性能差異為:
場(chǎng)景sysbench事務(wù)數(shù)b1e153752b0e1105980
理論的事務(wù)數(shù)比例為1-26.52%=73.48%, 實(shí)際事務(wù)數(shù)比例為53752/105980=50.71%, 誤差較大.
分析壓力分布首先懷疑壓力轉(zhuǎn)移, 即當(dāng)sync_binlog的壓力消除后, 服務(wù)器壓力被轉(zhuǎn)移到了其它的瓶頸上. 但如果壓力產(chǎn)生了轉(zhuǎn)移, 那么實(shí)際事務(wù)數(shù)比例應(yīng)大于理論事務(wù)數(shù)比例, 即sync_binlog=0帶來(lái)的性能提升更小.
不過(guò)我們還是可以衡量一下壓力分布, 看看b1e1和b0e1的壓力有什么不同, 步驟如下:
修改stap腳本, 在b1e1中不統(tǒng)計(jì)sync_binlog的代價(jià). 生成的火焰圖表示消除sync_binlog代價(jià)后, 理論上的服務(wù)器壓力類型.與b0e1產(chǎn)生的火焰圖做比較.stap腳本
只修改了probe end部分, 略過(guò)對(duì)my_sync堆棧的統(tǒng)計(jì):
probe end { foreach (i in oncpu+) { if (isinstr(sprint_stack(i), "my_sync")) { continue; } print_stack(i); printf("\t%d\n", @sum(oncpu[i])); } foreach (i in offcpu+) { if (isinstr(sprint_stack(i), "my_sync")) { continue; } printf("---"); print_stack(i); printf("\t%d\n", @sum(offcpu[i])); } }
結(jié)果
b1e1, 理論的服務(wù)器壓力圖:
b0e1, 實(shí)際的服務(wù)器壓力圖:
可以看到, 壓力分布是非常類似, 即沒(méi)有發(fā)生壓力分布.
BTW: 這兩張圖的類似, 具有一定隨機(jī)性, 需要做多次試驗(yàn)才能產(chǎn)生這個(gè)結(jié)果.
分析
既然理論和實(shí)際的壓力分布類似, 那么可能發(fā)生的就是壓力的整體等比縮小. 推測(cè)是兩個(gè)場(chǎng)景上的觀測(cè)成本不同, 導(dǎo)致觀測(cè)影響到了所有壓力的觀測(cè).
觀察stap腳本, 其中成本較大的是ctxswitch, 即上下文切換時(shí)的觀測(cè)成本.
上下文切換的觀測(cè)成本如果 “上下文切換的觀測(cè)成本 影響 場(chǎng)景觀測(cè) 的公平性” 這一結(jié)論成立, 那么我們需要解釋兩個(gè)現(xiàn)象:1. b1e1和b0e1的比較, 受到了 上下文切換的觀測(cè)成本 的影響2. b0e1和b0e0的比較, 未受到 上下文切換的觀測(cè)成本 的影響
假設(shè) 上下文切換的觀測(cè)成本 正比于 上下文切換的次數(shù), 那么我們只需要:1. 觀測(cè)每個(gè)場(chǎng)景的上下文切換次數(shù)2. 對(duì)于b1e1和b0e1的比較, 由上下文切換次數(shù)計(jì)算得到理論的降速比, 與實(shí)際的降速比進(jìn)行比較3. 對(duì)于b0e1和b0e0的比較, 由上下文切換次數(shù)計(jì)算得到是否會(huì)帶來(lái)降速.
stap腳本
在probe scheduler.ctxswitch和probe end 增加了 ctxswitch_times 相關(guān)的內(nèi)容:
global ctxswitch_times probe scheduler.ctxswitch { ctxswitch_times++; ... } probe end { ... printf("ctxswitch_times=%d\n", ctxswitch_times); }
結(jié)果
場(chǎng)景sysbench事務(wù)數(shù)上下文切換次數(shù)sync_binlog占比b1e15535282637036.80%b0e1105995693383–b0e0162709675092–
分析結(jié)果:1. b1e1與b0e1的比較1. 理論降速比: 693383/826370 = 83.90%2. 實(shí)際降速比: (實(shí)際的事務(wù)數(shù)比例/由sync_binlog占比推算的理論的事務(wù)數(shù)比例) = (55352/105995)/(1-36.80%) = 0.5222/0.6320 = 82.63%3. 誤差很小. 即b1e1與b0e1的比較中, 理論值和實(shí)際值的誤差來(lái)自于: IO操作的減少導(dǎo)致上下文切換的數(shù)量減小, 使得兩個(gè)場(chǎng)景的觀察成本不同.2. b0e1與b0e0的比較: 上下文切換次數(shù)相近, 即兩個(gè)場(chǎng)景的觀察成本相同.
實(shí)驗(yàn)結(jié)果符合之前的分析.
結(jié)論利用火焰圖, 可以快速診斷出MySQL服務(wù)器級(jí)別的性能瓶頸, 做出合理的參數(shù)調(diào)整對(duì)于IO類型的操作的觀測(cè), 需要考慮oncpu和offcpu兩種情況由于觀測(cè)手段中使用了上下文切換作為觀測(cè)點(diǎn), 那IO操作數(shù)量的不同, 會(huì)引起上下文切換次數(shù)的不同, 從而引起觀測(cè)誤差.