利用blktrace分析磁盘I/O
原文：https://blog.csdn.net/ygtlovezf/article/details/80528300
blktrace對于分析block I/O是個非常好的工具，本篇文章記錄了如何使用blktrace。
blktrace原理
blktrace是對通用塊層（block layer）的I/O跟蹤機制，它能抓取詳細的I/O請求（request），發(fā)送到用戶空間。
blktrace主要由3部分組成：
內(nèi)核部分
- 記錄內(nèi)核到用戶空間的I/O追蹤信息的程序
- 分析、展示I/O追蹤信息的程序
- 主要在block layer實現(xiàn)，抓取的數(shù)據(jù)通過debugfs來傳遞。每個被跟蹤的設(shè)備都有一個在debugfs掛載目錄的文件。debugfs掛載目錄默認是：/sys/kernel/debug
用官方的一張圖來直觀的展現(xiàn)：
一個I/O請求進入block layer之后，可能會經(jīng)歷下面的過程：
- Remap: 可能被DM(Device Mapper)或MD(Multiple Device, Software RAID) remap到其它設(shè)備
- Split: 可能會因為I/O請求與扇區(qū)邊界未對齊、或者size太大而被分拆(split)成多個物理I/O
- Merge: 可能會因為與其它I/O請求的物理位置相鄰而合并(merge)成一個I/O
- 被I/O Scheduler依照調(diào)度策略發(fā)送給driver
- 被driver提交給硬件，經(jīng)過HBA、電纜（光纖、網(wǎng)線等）、交換機（SAN或網(wǎng)絡(luò)）、最后到達存儲設(shè)備，設(shè)備完成I/O請求之后再把結(jié)果發(fā)回。
blktrace使用
- 安裝blktrace包
yum install blktrace - 追蹤指定設(shè)備的I/O
[root@k8s-slave9 longterm_io] # blktrace -d /dev/sde ^C=== sde ===CPU 0: 38 events, 2 KiB dataCPU 1: 1 events, 1 KiB dataCPU 2: 232 events, 11 KiB dataCPU 3: 2 events, 1 KiB dataCPU 4: 41 events, 2 KiB data...Total: 567 events (dropped 0), 27 KiB data
-d 指定具體的設(shè)備名
上面是抓取一段時間后，Ctrl+C中止的。也可以指定時間：-w
blktrace執(zhí)行完之后，會生產(chǎn)很多文件，每個CPU都會有一個文件，文件名組成：<設(shè)備名>.blktrace.，如下：
[root@k8s-slave9 longterm_io]ls
sde.blktrace.0 sde.blktrace.12 sde.blktrace.16 sde.blktrace.2 sde.blktrace.23 sde.blktrace.27 sde.blktrace.30 sde.blktrace.34 sde.blktrace.38 sde.blktrace.6
...
抓取IO信息，完成了第一步，我們要分析這些I/O，就需要下面的工具。
blkparse分析數(shù)據(jù)
-
解析IO追蹤信息
blkparse是一個會把不同CPU的I/O trace文件合并，并解析、格式化輸出為對用戶可讀友好IO信息的工具。
先把上面生成的所有CPU I/O trace文件合并成一個文件：
[root@k8s-slave9 longterm_io] # blkparse -i sde -d sde.blktrace.bin Input file sde.blktrace.0 added Input file sde.blktrace.1 added Input file sde.blktrace.2 added Input file sde.blktrace.3 added Input file sde.blktrace.4 added ... -----------------------------第一個IO開始8,64 35 1 0.000000000 28378 A W 470236984 + 40 <- (8,65) 470234936 8,64 35 2 0.000000670 28378 Q W 470236984 + 40 [kworker /u82 :1] 8,64 35 3 0.000005125 28378 G W 470236984 + 40 [kworker /u82 :1] 8,64 35 4 0.000005443 28378 P N [kworker /u82 :1] 8,64 35 5 0.000009123 28378 I W 470236984 + 40 [kworker /u82 :1] 8,64 35 6 0.000009978 28378 U N [kworker /u82 :1] 1 8,64 35 7 0.000010638 28378 D W 470236984 + 40 [kworker /u82 :1] 8,64 31 1 0.207382887 0 C W 470236984 + 40 [0] -----------------------------第一個IO完成 -----------------------------第二個IO開始8,64 2 1 10.239998442 4861 A FWFSM 469242512 + 2 <- (8,65) 469240464 8,64 2 2 10.239999862 4861 Q FWFSM 469242512 + 2 [kworker /2 :0H] 8,64 2 3 10.240004505 4861 G FWFSM 469242512 + 2 [kworker /2 :0H] 8,64 2 4 10.240005325 4861 P N [kworker /2 :0H] 8,64 2 5 10.240007109 4861 I FWFSM 469242512 + 2 [kworker /2 :0H] 8,64 2 6 10.240008795 4861 U N [kworker /2 :0H] 1 8,64 4 1 10.482792539 0 D WFSM 469242512 + 2 [swapper /0 ] 8,64 8 1 10.492646670 0 C WFSM 469242512 + 2 [0] -----------------------------第二個IO完成 ... CPU0 (sde): Reads Queued: 1, 8KiB Writes Queued: 3, 172KiB Read Dispatches: 1, 8KiB Write Dispatches: 3, 172KiB Reads Requeued: 0 Writes Requeued: 0 Reads Completed: 1, 8KiB Writes Completed: 3, 172KiB Read Merges: 0, 0KiB Write Merges: 0, 0KiB Read depth: 1 Write depth: 4 IO unplugs: 4 Timer unplugs: 0 ... Total (sde): Reads Queued: 23, 184KiB Writes Queued: 41, 652KiB Read Dispatches: 23, 184KiB Write Dispatches: 36, 653KiB Reads Requeued: 0 Writes Requeued: 0 Reads Completed: 23, 184KiB Writes Completed: 53, 653KiB Read Merges: 0, 0KiB Write Merges: 5, 91KiB IO unplugs: 57 Timer unplugs: 0 Throughput (R /W ): 0KiB /s / 1KiB /s Events (sde): 500 entries Skips: 0 forward (0 - 0.0%)中間那段I/O處理階段說明：
第一列：設(shè)備號 主設(shè)備號，次設(shè)備號
第二列：CPU
第三列：順序號
第五列：時間戳
第六列：PID 進程號
第七列：具體事件
第八列：具體的讀寫操作
W：WriteR：ReadS：SyncFWF：第一個F是Flush，W還是Write，第二個F是FUA（force unit acess）M：MetadataD：DiscardB：Barrier從抓取的I/O來看，所有I2D耗時比較長的都是FWFSM的操作。第九列：磁盤起始塊+操作的塊的數(shù)量
第十列：進程名或具體的命令
通過這些輸出，我們就可以明確看到，每個階段的具體耗時，就可以定位I/O慢在哪個階段，也是需要深入的分析什么原因?qū)е碌摹?/p>
-
具體動作（或事件）的字母代表意義：
- A remap 對于棧式設(shè)備，進來的I/O將被重新映射到I/O棧中的具體設(shè)備
- X split 對于做了Raid或進行了device mapper(dm)的設(shè)備，進來的IO可能需要切割，然后發(fā)送給不同的設(shè)備
- Q queued I/O進入block layer，將要被request代碼處理（即將生成IO請求）
- G get request I/O請求（request）生成，為I/O分配一個request 結(jié)構(gòu)體。
- M back merge 之前已經(jīng)存在的I/O request的終止block號，和該I/O的起始block號一致，就會合并。也就是向后合并
- F front merge 之前已經(jīng)存在的I/O request的起始block號，和該I/O的終止block號一致，就會合并。也就是向前合并
- I inserted I/O請求被插入到I/O scheduler隊列
- S sleep 沒有可用的request結(jié)構(gòu)體，也就是I/O滿了，只能等待有request結(jié)構(gòu)體完成釋放
- P plug 當一個I/O入隊一個空隊列時，Linux會鎖住這個隊列，不處理該I/O，這樣做是為了等待一會，看有沒有新的I/O進來，可以合并
- U unplug 當隊列中已經(jīng)有I/O request時，會放開這個隊列，準備向磁盤驅(qū)動發(fā)送該I/O。
這個動作的觸發(fā)條件是：超時（plug的時候，會設(shè)置超時時間）；或者是有一些I/O在隊列中（多于1個I/O） - D issued I/O將會被傳送給磁盤驅(qū)動程序處理
- C complete I/O處理被磁盤處理完成。
btt分析數(shù)據(jù)
blkparse只是將blktrace數(shù)據(jù)轉(zhuǎn)成可以人工閱讀的格式，由于數(shù)據(jù)量通常很大，人工分析并不輕松。btt是對blktrace數(shù)據(jù)進行自動分析的工具。
-
使用btt解析數(shù)據(jù)，查看I/O的整體情況
[root@k8s-slave9 longterm_io] # btt -i sde.blktrace.bin ==================== All Devices ====================ALL MIN AVG MAX N --------------- ------------- ------------- ------------- -----------Q2Q 0.000002013 7.354920889 30.208019079 63 Q2G 0.000000889 0.000003898 0.000016826 59 G2I 0.000000591 0.000003383 0.000035937 59 Q2M 0.000000333 0.000001295 0.000002440 5 I2D 0.000000503 0.065649284 0.252996244 59 M2D 0.000003840 0.000011816 0.000017717 5 D2C 0.000128883 0.056202494 0.254664063 64 Q2C 0.000131324 0.116730664 0.262633229 64==================== Device Overhead ====================DEV | Q2G G2I Q2M I2D D2C ---------- | --------- --------- --------- --------- ---------( 8, 64) | 0.0031% 0.0027% 0.0001% 51.8462% 48.1472% ---------- | --------- --------- --------- --------- ---------Overall | 0.0031% 0.0027% 0.0001% 51.8462% 48.1472%==================== Device Merge Information ====================DEV | #Q #D Ratio | BLKmin BLKavg BLKmax Total ---------- | -------- -------- ------- | -------- -------- -------- --------( 8, 64) | 64 59 1.1 | 2 28 176 1675 ...第一個表的第一列是具體的I/O階段，第二、三、四列分別是最小耗時、平均耗時、最大耗時（單位：s），第五列是I/O數(shù)。
第二個表是對第一個表做了耗時統(tǒng)計，看看整個I/O階段，哪個階段耗時占用最多。
第三個表是進行合并的信息，但是從內(nèi)容來看，沒有merge信息啊。后面有所有I/O中操作的塊數(shù)量的最小值、平均值、最大值。
IO處理階段：
Q2Q： 相鄰兩次進入通用塊層的I/O間隔
Q2G：I/O進入block layer到I/O請求（request）生成的時間
G2I ：I/O請求生成到被插入I/O請求隊列（request queue）的時間
Q2M：I/O進入block層到該I/O被和已存在的I/O請求合并的時間
I2D ：I/O請求進入request queue隊到分發(fā)到設(shè)備驅(qū)動的時間
M2D：I/O合并成I/O請求到分發(fā)到設(shè)備驅(qū)動的時間
D2C：I/O分到到設(shè)備驅(qū)動到設(shè)備處理完成時間
在上述過程中，Q2M、M2D兩個階段不是必然發(fā)生的，只有可以merge的I/O才會進行合并。
-
生產(chǎn)不同維度的報告
查看所有I/O D2C階段的具體延時： （-l參數(shù)將會分析D2C階段延遲，該參數(shù)后是具體的輸出文件名）
[root@k8s-slave9 longterm_io] # btt -i sde.blktrace.bin -l sde.d2c_latency ==================== All Devices ====================ALL MIN AVG MAX N --------------- ------------- ------------- ------------- -----------Q2Q 0.000002013 7.354920889 30.208019079 63 Q2G 0.000000889 0.000003898 0.000016826 59 G2I 0.000000591 0.000003383 0.000035937 59 Q2M 0.000000333 0.000001295 0.000002440 5 I2D 0.000000503 0.065649284 0.252996244 59 M2D 0.000003840 0.000011816 0.000017717 5 D2C 0.000128883 0.056202494 0.254664063 64 Q2C 0.000131324 0.116730664 0.262633229 64 ...執(zhí)行完上面的命令后，會有如下文件生成：
[root@k8s-slave9 longterm_io] # ls *.dat 8,64_iops_fp.dat 8,64_mbps_fp.dat sde.d2c_latency_8,64_d2c.dat sys_iops_fp.dat sys_mbps_fp.dat如上輸出，可以看到：有這段時間的IOPS統(tǒng)計（8,64_iops_fp.dat、sys_iops_fp.dat）、帶寬統(tǒng)計（8,64_mbps_fp.dat、sys_mbps_fp.dat）、延遲統(tǒng)計（sde.d2c_latency_8,64_d2c.dat）
我們看看這些文件：每個時間點的I /O 個數(shù)： [root@k8s-slave9 longterm_io] # cat sys_iops_fp.dat 0 1 10 1 31 1 40 1 44 1 66 1 70 1 100 5 ...每個時間點的帶寬： [root@k8s-slave9 longterm_io] # cat sys_mbps_fp.dat 0 0.019531 10 0.000977 31 0.031250 40 0.000977 44 0.003906 66 0.015625 70 0.002441 100 0.048828 ...每個時間點的D2C階段延遲： [root@k8s-slave9 longterm_io] # cat sde.d2c_latency_8,64_d2c.dat 0.207383 0.207372 10.492647 0.009854 31.439889 0.207854 40.700689 0.009720 44.381372 0.206810 44.381372 0.206810 66.564038 0.004049 70.907380 0.008502 100.047822 0.207767 ...其中，第一列是時間戳，第二列是具體的內(nèi)容
查看所有I/O的size、offset等信息：（-B參數(shù)將會輸出具體的block號，包括起始block、終止block）
[root@k8s-slave9 longterm_io] # btt -i sde.blktrace.bin -B sde.offset ==================== All Devices ====================ALL MIN AVG MAX N --------------- ------------- ------------- ------------- -----------Q2Q 0.000002013 7.354920889 30.208019079 63 Q2G 0.000000889 0.000003898 0.000016826 59 G2I 0.000000591 0.000003383 0.000035937 59 Q2M 0.000000333 0.000001295 0.000002440 5 I2D 0.000000503 0.065649284 0.252996244 59 M2D 0.000003840 0.000011816 0.000017717 5 D2C 0.000128883 0.056202494 0.254664063 64 Q2C 0.000131324 0.116730664 0.262633229 64 ...上述命令將輸出如下的文件：
[root@k8s-slave9 longterm_io] # ls | grep offset sde.offset_8,64_c.dat sde.offset_8,64_r.dat sde.offset_8,64_w.dat xxx_r.dat：讀操作相關(guān)信息 xxx_w.dat：寫操作相關(guān)信息xxx_c.dat：所有操作，讀寫都有我們看看寫操作：
[root@k8s-slave9 longterm_io] # cat sde.offset_8,64_w.dat0.000010638 470236984 47023702410.482792539 469242512 46924251431.232035019 470237016 47023708040.690968712 469242514 46924251644.174561925 703299792 70329980066.559989117 470237072 47023710470.898878399 469242516 46924252199.840054977 470237096 470237152100.864256898 703277841 703277843...其中第一列是時間戳，第二列是I/O操作的起始block號，第三列是I/O操作的終止block號。
參考
https://www.mimuw.edu.pl/~lichota/09-10/Optymalizacja-open-source/Materialy/10 - Dysk/gelato_ICE06apr_blktrace_brunelle_hp.pdf
http://fibrevillage.com/storage/539-blktrace-and-btt-example-to-debug-and-tune-disk-i-o-on-linux
總結(jié)
以上是生活随笔為你收集整理的利用blktrace分析磁盘I/O的全部內(nèi)容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： 《春雪》第八句是什么
- 下一篇： linux系统 长久记录所有用户所有操作