最近在排查 TiDB 性能問題的時(shí)候际歼，通過工具發(fā)現(xiàn)了一些問題惶翻，覺得有必要記錄一下，讓自己繼續(xù)深刻的去理解相關(guān)工具的使用鹅心，也同時(shí)讓同學(xué)們對(duì)類似問題的時(shí)候別再踩坑吕粗。
使用 iostat 定位磁盤問題
在一個(gè)性能測試集群，我們選擇了 AWS c3.4xlarge 機(jī)型旭愧，主要是為了在一臺(tái)機(jī)器的兩塊盤上面分別跑 TiKV颅筋。在測試一段時(shí)間之后，我們發(fā)現(xiàn)有一臺(tái) TiKV 響應(yīng)很慢议泵，但是 RocksDB 并沒有相關(guān)的 Stall 日志占贫，而且慢查詢也沒有。
于是我登上 AWS 機(jī)器肢簿，使用 iostat -d -x -m 5 命令查看，得到如下輸出：
Device: rrqm/s wrqm/s r/s w/s rMB/s wMB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
xvda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
xvdb 8.00 12898.00 543.00 579.00 31.66 70.15 185.84 51.93 54.39 7.03 98.79 0.60 66.80
xvdc 0.00 0.00 206.00 1190.00 10.58 148.62 233.56 106.67 70.90 13.83 80.78 0.56 78.40
上面發(fā)現(xiàn)，兩個(gè)盤 xvdb 和 xvdc 在 wrqm/s 上面差距太大卧惜，當(dāng)然后面一些指標(biāo)也有明顯的差距，這里就不在詳細(xì)的解釋 iostat 的輸出月匣。只是需要注意钻洒，大家通常將目光注意到 util 上面，但有時(shí)候光有 util 是反應(yīng)不了問題的锄开。
于是我繼續(xù)用 fio 進(jìn)行測試素标，fio -ioengine=libaio -bs=4k -direct=1 -thread -rw=write -size=10G -filename=test -name="PingCAP max throughput" -iodepth=4 -runtime=60，發(fā)現(xiàn)兩個(gè)盤的寫入有 2 倍的差距萍悴，xvdb 的寫入竟然只有不到 70 MB头遭，而 xvdc 有 150 MB，所以自然兩個(gè) TiKV 一個(gè)快癣诱，一個(gè)慢了计维。
對(duì)于磁盤來說，通常我們使用的就是 iostat 來進(jìn)行排查狡刘，另外也可以考慮使用 pidstat享潜，iotop 等工具。
使用 perf 定位性能問題
RC3 最重要的一個(gè)功能就是引入 gRPC嗅蔬，但這個(gè)對(duì)于 rust 來說難度太大剑按。最開始疾就，我們使用的是 rust-grpc 庫，但這個(gè)庫并沒有經(jīng)過生產(chǎn)環(huán)境的驗(yàn)證艺蝴，我們還是膽大的引入了猬腰，只是事后證明，這個(gè)冒險(xiǎn)的決定還是傻逼了猜敢，一些試用的用戶跟我們反映 TiKV 時(shí)不時(shí) coredump姑荷，所以我們立刻決定直接封裝 c gRPC。因?yàn)楝F(xiàn)在大部分語言 gRPC 實(shí)現(xiàn)都是基于 c gRPC 的缩擂，所以我們完全不用擔(dān)心這個(gè)庫的穩(wěn)定性鼠冕。
在第一個(gè)版本的實(shí)現(xiàn)中，我們發(fā)現(xiàn)胯盯，rust 封裝的 c gRPC 比 C Plus Plus 的版本差了幾倍的性能懈费，于是我用 perf stat 來分別跑 C Plus Plus 和 rust 的benchmark，得到類似如下的輸出：
Performance counter stats for 'python2.7 tools/run_tests/run_performance_tests.py -r generic_async_streaming_ping_pong -l c++':
216989.551636 task-clock (msec) # 2.004 CPUs utilized
3,659,896 context-switches # 0.017 M/sec
5,078 cpu-migrations # 0.023 K/sec
4,104,965 page-faults # 0.019 M/sec
729,530,805,665 cycles # 3.362 GHz
<not supported> stalled-cycles-frontend
<not supported> stalled-cycles-backend
557,766,492,733 instructions # 0.76 insns per cycle
121,205,705,283 branches # 558.579 M/sec
3,095,509,087 branch-misses # 2.55% of all branches
108.267282719 seconds time elapsed
上面是 C Plus Plus 的結(jié)果博脑，然后在 rust 測試的時(shí)候憎乙，我們發(fā)現(xiàn) context-switch 是 C Plus Plus 的 10 倍，也就是我們進(jìn)行了太多次的線程切換叉趣。剛好我們第一個(gè)版本的實(shí)現(xiàn)是用 rust futures 的 park 和 unpark task 機(jī)制泞边，不停的在 gRPC 自己的 Event Loop 線程和邏輯線程之前切換，但 C Plus Plus 則是直接在一個(gè) Event Loop 線程處理的疗杉。于是我們立刻改成類似 C Plus Plus 架構(gòu)阵谚，沒有了 task 的開銷，然后性能一下子跟 C Plus Plus 的不相伯仲了乡数。
當(dāng)然椭蹄，perf 能做到的還遠(yuǎn)遠(yuǎn)不僅于此，我們通常會(huì)使用火焰圖工具净赴，關(guān)于火焰圖绳矩，網(wǎng)上已經(jīng)有太多的介紹，我們也通過它來發(fā)現(xiàn)了很多性能問題玖翅，這個(gè)后面可以專門來說一下翼馆。
使用 strace 動(dòng)態(tài)追蹤
因?yàn)槲覀冇幸粋€(gè)記錄線程 CPU 的統(tǒng)計(jì)，通常在 Grafana 展示的時(shí)候都是按照線程名字來 group 的金度，并沒有按照線程 ID应媚。但我們也可以強(qiáng)制發(fā)送 SIGUSR1 信號(hào)給 TiKV 在 log 里面 dump 相關(guān)的統(tǒng)計(jì)信息。在測試 TiKV 的時(shí)候猜极，我發(fā)現(xiàn) pd worker 這個(gè) thread 出現(xiàn)了很多不同線程 ID 的 label中姜，也就是說，這個(gè)線程在不停的創(chuàng)建和刪除。
要?jiǎng)討B(tài)追蹤到這個(gè)情況丢胚，使用 strace -f 是一個(gè)不錯(cuò)的方式翩瓜，我同時(shí)觀察 TiKV 自己的輸出 log，發(fā)現(xiàn)當(dāng) TiKV 在處理分裂邏輯携龟，給 PD worker 發(fā)送 message 的時(shí)候兔跌，就有一個(gè)新的線程創(chuàng)建出來。然后在查找對(duì)應(yīng)的代碼峡蟋，發(fā)現(xiàn)我們每次在發(fā)消息的時(shí)候都創(chuàng)建了一個(gè) tokio-timer坟桅，而這個(gè)每次都會(huì)新創(chuàng)建一個(gè)線程。
有時(shí)候蕊蝗，也可以使用 strace -c 來動(dòng)態(tài)的追蹤一段時(shí)間的系統(tǒng)調(diào)用仅乓。在第一版本的 rust gRPC 中，我們?yōu)榱私鉀Q future task 導(dǎo)致的頻繁線程切換匿又，使用 gRPC 自己的 alarm 來喚醒 Event Loop方灾，但發(fā)現(xiàn)這種實(shí)現(xiàn)會(huì)產(chǎn)生大量的信號(hào)調(diào)用，因?yàn)?gRPC 的 alarm 會(huì)發(fā)送一個(gè)實(shí)時(shí)信號(hào)用來喚醒 epoll碌更，后面通過火焰圖也發(fā)現(xiàn)了 Event Loop 很多 CPU 消耗在 alarm 這邊，所以也在開始改進(jìn)洞慎。
這里需要注意痛单，strace 對(duì)性能影響比較大，但對(duì)于內(nèi)部性能測試影響還不大劲腿，不到萬不得已旭绒，不建議長時(shí)間用于生產(chǎn)環(huán)境。
小結(jié)
上面僅僅是三個(gè)最近用工具發(fā)現(xiàn)的問題焦人，當(dāng)然還遠(yuǎn)遠(yuǎn)不止于此挥吵，后續(xù)也會(huì)慢慢補(bǔ)上。其實(shí)對(duì)于性能調(diào)優(yōu)來說花椭，工具只是一個(gè)輔助工具忽匈，最重要的是要有一顆對(duì)問題敏銳的心，不然即使工具發(fā)現(xiàn)了問題矿辽，因?yàn)椴幻翡J直接就忽略了丹允。我之前就是不敏銳栽過太多的坑，所以現(xiàn)在為了刻意提升自己這塊的能力袋倔，直接給自己下了死規(guī)定雕蔽，就是懷疑一切能能懷疑的東西，認(rèn)為所有東西都是有問題的宾娜。即使真的是正常的批狐，也需要找到充足的理由去驗(yàn)證。
