記一次IO異常捕獲的過程

背景資訊：

遇到一個IO異常飙升的問題，IO起飛後系統響應異常緩慢，看不到現場一直無法定位問題，檢查對應時間點應用日志也沒有發現異常的通路，這種問題怎麼辦呢？
           

1，采集系統IO，确認IO異常發生在系統盤，還是資料盤，使用系統自帶的iostat即可采集

# iostat -d 3  -k -x -t 30
06/12/2018 09:52:33 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
xvda              0.00     0.39    0.08    0.70     1.97     5.41    18.81     0.03   44.14   1.08   0.08
xvdb              0.00     0.00    0.00    0.00     0.00     0.00     8.59     0.00    1.14   1.09   0.00

06/12/2018 09:52:36 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
xvda              0.00     0.00    0.00    0.67     0.00     2.68     8.00     0.00    1.00   0.50   0.03
xvdb              0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00           

每隔3秒采集一次磁盤io，輸出時間，一共采集30次，想一直抓的話把30去掉即可，注意磁盤空餘量

通過這個指令我們可以确認如下資訊：

- 問題發生的時間
- 哪塊盤發生的io
- 磁盤的 IOPS（ r/s     w/s）以及吞吐量（ rkB/s    wkB/s ）
           

2，确認哪塊盤發生了IO還不夠，再抓一下發生IO的程序，需要安裝 iotop 進行捕獲

# iotop -b -o -d 3 -t -qqq -n 30
10:18:41  7024 be/4 root        0.00 B/s    2.64 M/s  0.00 % 93.18 % fio -direct=1 -iodepth=128 -rw=randwrite -ioengine=libaio -bs=1k -size=1G -numjobs=1 -runtime=1000 -group_reporting -filename=iotest -name=Rand_Write_Testing           

每隔3秒采集一次，一共采集30次，靜默模式，隻顯示有io發生的程序

通過這個指令我們可以确認如下資訊：
- 問題發生的時間
- 産生IO的程序id以及程序參數（command）
- 程序産生的吞吐量（如果有多個可以把qqq去掉可顯示總量）
- 程序占用目前IO的百分比
           

俗話說得好，光說不練假把式，我們實操來看一下(涉及使用者程序資訊,沒有得到客戶授權是以以fio為示範)

3， 使用 fio 進行 IO 壓測,詳細參數我就不講了，有興趣的同學看下

塊存儲性能

壓測視窗：

# fio -direct=1 -iodepth=128 -rw=randwrite -ioengine=libaio -bs=1k -size=1G -numjobs=1 -runtime=1000 -group_reporting -filename=iotest -name=Rand_Write_Testing
Rand_Write_Testing: (g=0): rw=randwrite, bs=1K-1K/1K-1K/1K-1K, ioengine=libaio, iodepth=128
fio-2.0.13
Starting 1 process
^Cbs: 1 (f=1): [w] [8.5% done] [0K/2722K/0K /s] [0 /2722 /0  iops] [eta 05m:53s]
fio: terminating on signal 2

Rand_Write_Testing: (groupid=0, jobs=1): err= 0: pid=11974: Tue Jun 12 10:36:30 2018
  write: io=88797KB, bw=2722.8KB/s, iops=2722 , runt= 32613msec
 ......
           

iotop視窗:

# iotop -n 10 -b -o -d 3 -t -qqq
10:36:03 11974 be/4 root        0.00 B/s    2.63 M/s  0.00 % 93.95 % fio -direct=1 -iodepth=128 -rw=randwrite -ioengine=libaio -bs=1k -size=1G -numjobs=1 -runtime=1000 -group_reporting -filename=iotest -name=Rand_Write_Testing
10:36:06 11974 be/4 root        0.00 B/s    2.64 M/s  0.00 % 92.68 % fio -direct=1 -iodepth=128 -rw=randwrite -ioengine=libaio -bs=1k -size=1G -numjobs=1 -runtime=1000 -group_reporting -filename=iotest -name=Rand_Write_Testing
           

iostat視窗:

#  iostat -d 3  -k -x -t 10
Linux 2.6.32-431.23.3.el6.x86_64 (test)     06/12/2018     _x86_64_    (1 CPU)


06/12/2018 10:36:03 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   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
xvdb              0.00    10.80    0.00 2823.69     0.00  2837.63     2.01   132.97   47.00   0.37 104.53

06/12/2018 10:36:06 AM
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
xvda              0.00     0.00    0.00    2.76     0.00    11.03     8.00     0.00    1.62   0.62   0.17
xvdb              0.00    17.24    0.00 2788.28     0.00  2805.17     2.01   131.50   47.20   0.37 103.45
           

通過輸出結果的時間點進行對比分析,相對于 fio 的 IOPS,吞吐量 跟 iotop 以及 iostat 監控到的資料是一緻。是以，看到這，您已經學會怎麼查消耗IO的程序了

注意:為了壓測的慢一些我特意把bs設定為1k,這樣執行的時間會比較久,fio壓測詳見前面的塊存儲性能
           

牧原辣麼長！怎麼可能到這就結束了呢！

心細的同學可能發現 iotop 輸出不帶年月日,如果抓日志的時間超過24小時,時間重複怎麼辦?

彩彈:

# iotop  -b -o -d 1 -qqq |awk '{ print $0"\t" strftime("%Y-%m-%d-%H:%M:%S",systime()) } '
16209 be/4 root        0.00 B/s    2.64 M/s  0.00 % 93.72 % fio -direct=1 -iodepth=128 -rw=randwrite -ioengine=libaio -bs=1k -size=1G -numjobs=1 -runtime=1000 -group_reporting -filename=iotest -name=Rand_Write_Testing    2018-06-12-10:54:10
16209 be/4 root        0.00 B/s    2.63 M/s  0.00 % 93.61 % fio -direct=1 -iodepth=128 -rw=randwrite -ioengine=libaio -bs=1k -size=1G -numjobs=1 -runtime=1000 -group_reporting -filename=iotest -name=Rand_Write_Testing    2018-06-12-10:54:11           

詳細參數就不講了,大家可以看下輸出結果行最後一列是年月日時分秒,那麼 IO 消耗的始作俑者會查了嗎？