存儲IO落盤原理及路徑分析

一、IO落盤原理

一個I/O請求，從應用層到底層塊設備，路徑如下圖所示：

從上圖可以看出IO路徑是很復雜的。我們將IO路徑簡化一下：

一個I/O請求進入block layer之后，可能會經歷下面的過程：

• Remap: 可能被DM(Device Mapper)或MD(Multiple Device, Software RAID) remap到其它設備

• Split: 可能會因為I/O請求與扇區邊界未對齊、或者size太大而被分拆(split)成多個物理I/O

• Merge: 可能會因為與其它I/O請求的物理位置相鄰而合並(merge)成一個I/O

• 被IO Scheduler依照調度策略發送給driver

• 被driver提交給硬件，經過HBA、電纜（光纖、網線等）、交換機（SAN或網絡）、最后到達存儲設備，設備完成IO請求之后再把結果發回。

根據以上步驟對應的時間戳就可以計算出I/O請求在每個階段所消耗的時間：

• Q2Q — time between requests sent to the block layer

• Q2G – 生成IO請求所消耗的時間，包括remap和split的時間；

• G2I – IO請求進入IO Scheduler所消耗的時間，包括merge的時間；

• Q2M — time from a block I/O is queued to the time it gets merged with an existing request

• I2D – IO請求在IO Scheduler中等待的時間；

• D2C – IO請求在driver和硬件上所消耗的時間；

• Q2C – 整個IO請求所消耗的時間(Q2I + I2D + D2C = Q2C)，相當於iostat的await。

用一張圖來表示：

如果I/O性能慢的話，以上指標有助於進一步定位緩慢發生的地方：

• D2C可以作為硬件性能的指標；

• I2D可以作為IO Scheduler性能的指標。

附上event速查表：

注意以下幾點：

• Q2Q是表示兩個reqeusts之間的間隔；而其他都是表示一個request的各個階段的間隔。

• 和第2節中的IO的流程圖一致，分為兩個路徑：上面綠色Q->G->I->D表示一個典型request（沒有被merge的request）特有的階段；下面紅色為Q->M->D表示一個被merge的request特有的階段；黃色部分表示公共階段。

• Q2G一般比較小，若它比較大，說明分配不到struct request，中途經歷了S(sleep)階段。

二、IO路徑分析工具blktrace

由於在iostat輸出中，只能看到service time + wait time，因為對於評估一個磁盤或者雲磁盤而言，service time才是衡量磁盤性能的核心指標和直接指標。很不幸iostat無法提供這個指標，但是blktrace可以。blktrace是一柄神器，很多工具都是基於該神器的：ioprof，seekwatcher，iowatcher，這個工具基本可以滿足我們的對塊設備請求的所有了解。

1 Blktrace工作原理

blktrace是block層的trace機制，它可以跟蹤IO請求的生成、進入隊列、發到driver以及完成等事件。blktrace包含3個組件：

• 一個內核模塊

• 一個把內核模塊跟蹤到的IO信息導出到用戶態的工具(blktrace命令)

• 一些分析和展示IO信息的工具(blkparse, btt命令)

所以廣義的blktrace包含這3個部分，狹義的blktrace只是blktrace命令。本文介紹廣義的blktrace：包括使用blktrace命令導出IO信息，然后使用blkparse和btt分析展示。blktrace命令通過 debug file system 從內核導出數據：

• blktrace從kernel接收數據並通過debug file system的buffer傳遞到用戶態；debug file system默認是/sys/kernel/debug，可以使用blktrace命令的-r選項來覆蓋。buffer的大小和數量默認分別是512KiB和4，可以通過-b和-n來覆蓋。blktrace運行的的時候，可以看見debug file system里有一個block/{device}(默認是/sys/kernel/debug/block/{device})目錄被創建出來，里面有一些trace{cpu}文件。

• blktrace默認地搜集所有trace到的事件，可以使用blktrace命令的-a選項來指定事件。

• blktrace把從內核接收到的數據寫到當前目錄，文件名為{device}.blktrace.{cpu}，內容是二進制數據（對於人來說是不可讀的；blkparse用於解析這些二進制數據）。例如blktrace -d /dev/sdc會生成sdc.blktrace.0, sdc.blktrace.1, … sdc.blktrace.N-1個文件，N為cpu個數。也可使用-o選項來自定義{device}部分，這方便和blkparse結合使用：blktrace的-o參數對應blkparse的-i參數。

• blktrace默認地會一直運行，直到被ctrl-C停掉。可以使用-w選項來指定運行時間，單位是秒。

blktrace會區分兩類請求:

• 文件系統請求(fs requests)：通常是用戶態進程產生的，讀寫disk的特定位置和特定大小的數據。當然，也有可能由內核產生：flush臟頁或sync文件系統的元數據(super block或journal block等)。

• SCSI命令(pc requests)：blktrace直接把SCSI命令發送到用戶態，blkparse可以解析它。

2 Blktrace安裝

yum安裝方式

yum install blktrace

源碼獲取（你也可以從源碼安裝）

git clonegit://git.kernel.org/pub/scm/linux/kernel/git/axboe/blktrace.git bt

cdbt

make

make install

可以查看磁盤上的實時信息：

blktrace -d /dev/sdb -o – | blkparse -i –

這個命令會連綿不絕地出現很多輸出，當你輸入ctrl＋C的時候，會停止。

命令采集信息，待所有信息采集完畢后，統一分析所有采集到的數據。搜集60s信息的命令如下：

blktrace -d /dev/sdb -w 60

首先blkparse可以將對應不同cpu的多個文件聚合成一個文件：

blkparse -i sdb -d sdb.blktrace.bin

利用btt協助分析統計

#btt -i sdb.blktrace.bin -l sdb.d2c_latency

注意：

• D2C: 表征塊設備性能的關鍵指標

• Q2C: 客戶發起請求到收到響應的時間

• D2C 平均時間：0.002494923 秒，即2.49毫秒

• Q2C 平均時間：0.002496605 秒，即2.49毫秒

• 平均下來，D2C 階段消耗時間占比 99.9326%

上述命令其實還會產生一些.dat文件，可以看到iops信息

文件解釋：

sys_mbps_fs.dat: 本次統計中所有設備吞吐量

sys_iops_fp.dat: 中是本次統計中所有設備的IOPS

blktrace 能夠記錄下IO所經歷的各個步驟:

我們一起看下blktrace的輸出參數解釋：

• 第一個字段：8,0 這個字段是設備號 major device ID和minor device ID。

• 第二個字段：3 表示CPU

• 第三個字段：11 序列號

• 第四個字段：0.009507758 Time Stamp是時間偏移

• 第五個字段：PID 本次IO對應的進程ID

• 第六個字段：Event，這個字段非常重要，反映了IO進行到了那一步

• 第七個字段：R表示 Read， W是Write，D表示block，B表示Barrier Operation

• 第八個字段：223490+56，表示的是起始block number 和 number of blocks，即我們常說的Offset 和 Size

• 第九個字段：進程名

其中第六個字段非常有用：每一個字母都代表了IO請求所經歷的某個階段。

Q – 即將生成IO請求 G – IO請求生成 I – IO請求進入IO Scheduler隊列| D – IO請求進入driver| C – IO請求執行完畢

Summary包括CPU和device兩個維度:

其中對於每個CPU或者對於Total：

• Writes Queued：trace時間內，Q(queue)的requests個數；

• Writes Requeued：trace時間內，requeue數。requeue可能來自於multi-layer

• Write Dispatches：trace時間內，block layer發送到driver的requests數；

• Write Merges：trace時間內，merge的requests數；

• Writes Completed：trace時間內，完成的requests數；

• Timer unplugs：超時導致的unplug數？

Writes Queued與Writes Requeued之和是trace時間內block layer接收的requests總數（incomming requests）。Write Dispatches和Write Merges之和是trace時間內block layer發出的（到driver）requests數（outgoing requests）。進等於出，所以：

Writes Queued + Writes Requeued = Write Dispatches + Write Merges

Write Dispatches是block layer發送到driver的requests數，但不是所有發送到driver的都完成了，其中有一部分被requeue了，即：

Write Dispatches = Writes Completed + Writes Requeued

我們來分析一個io過程，將一塊空白的磁盤格式化掛載一個目錄，然后再寫入一個文件

以上就是一次IO請求的生命周期，從actions看到，分別是QGPIUDC

• Q：先產生一個該位置的IO意向插入到io隊列，此時並沒有真正的請求

• G：發送一個實際的Io請求給設備

• P（plugging）：插入：即等待即將到來的更多的io請求進入隊列，以便系統能進行IO優化，減少執行IO請求時花的時間

• I：將IO請求進行調度，到這一步請求已經完全成型（formed）好了

• U (unplugging)：拔出，設備決定不再等待其他的IO請求並使得系統必須響應當前IO請求，將該IO請求傳給設備驅動器。可以看到，在P和U之間會等待IO，然后進行調度。這里會對IO進行一點優化，但是程度很低，因為等待的時間很短，是納秒級別的

• D ：發布剛才送入驅動器的IO請求

• C：結束IO請求，這里會返回一個執行狀態：失敗或者成功，在進程號處為0表示執行成功，反之則反 到此一個IO的周期就結束了

案例分析：

案例一：

把/dev/sde(設備號:8,64)整個盤格式化成ext4，掛載到/mnt並使用fio寫/mnt/fio-test-file (rw=randwrite ioengine=psync bs=4k fsync=1)，同時trace /dev/sde

# blktrace -d /dev/sde -w 60

# blkparse -i sde

......

8,64 11 2944 33.779658276 90790 Q W 7614344 + 24 [fio]

8,64 11 2945 33.779659493 90790 G W 7614344 + 24 [fio]

8,64 11 2946 33.779660124 90790 P N [fio]

8,64 11 2947 33.779661287 90790 I W 7614344 + 24 [fio]

8,64 11 2948 33.779661791 90790 U N [fio] 1

8,64 11 2949 33.779662409 90790 D W 7614344 + 24 [fio]

8,64 11 2950 33.791580458 0 C W 7614344 + 24 [0]

8,64 11 2951 33.791608964 90790 Q WS 7614368 + 8 [fio]

8,64 11 2952 33.791609940 90790 G WS 7614368 + 8 [fio]

8,64 11 2953 33.791610381 90790 P N [fio]

8,64 11 2954 33.791611867 90790 I WS 7614368 + 8 [fio]

8,64 11 2955 33.791612372 90790 U N [fio] 1

8,64 11 2956 33.791612977 90790 D WS 7614368 + 8 [fio]

8,64 11 2957 33.799933777 0 C WS 7614368 + 8 [0]

8,64 13 5709 33.799963426 90708 Q WS 3905206216 + 8 [jbd2/sde-8]

8,64 13 5710 33.799964662 90708 G WS 3905206216 + 8 [jbd2/sde-8]

8,64 13 5711 33.799965100 90708 P N [jbd2/sde-8]

8,64 13 5712 33.799965942 90708 Q WS 3905206224 + 8 [jbd2/sde-8]

8,64 13 5713 33.799966423 90708 M WS 3905206224 + 8 [jbd2/sde-8]

8,64 13 5714 33.799967148 90708 Q WS 3905206232 + 8 [jbd2/sde-8]

......

CPU8 (sde):

Reads Queued: 0, 0KiB Writes Queued: 195, 29,228KiB

Read Dispatches: 0, 0KiB Write Dispatches: 170, 29,228KiB

Reads Requeued: 0 Writes Requeued: 0

Reads Completed: 0, 0KiB Writes Completed: 170, 29,228KiB

Read Merges: 0, 0KiB Write Merges: 25, 100KiB

Read depth: 0 Write depth: 20

IO unplugs: 104 Timer unplugs: 0

CPU9 (sde):

Reads Queued: 0, 0KiB Writes Queued: 991, 16,156KiB

Read Dispatches: 0, 0KiB Write Dispatches: 574, 16,156KiB

Reads Requeued: 0 Writes Requeued: 0

Reads Completed: 0, 0KiB Writes Completed: 574, 16,156KiB

Read Merges: 0, 0KiB Write Merges: 417, 1,668KiB

Read depth: 0 Write depth: 20

IO unplugs: 346 Timer unplugs: 0

......

Total (sde):

Reads Queued: 0, 0KiB Writes Queued: 8,763, 352,192KiB

Read Dispatches: 0, 0KiB Write Dispatches: 5,380, 352,192KiB

Reads Requeued: 0 Writes Requeued: 0

Reads Completed: 0, 0KiB Writes Completed: 5,380, 352,196KiB

Read Merges: 0, 0KiB Write Merges: 3,383, 13,532KiB

IO unplugs: 3,092 Timer unplugs: 0

Throughput (R/W): 0KiB/s / 5,872KiB/s

Events (sde): 39,850 entries

Skips: 0 forward (0 - 0.0%)

我們嘗試把一個特定request的事件給找出來(grep一個特定的起始sector號，而不是grep一個序列號):

# blkparse -i sde | grep -w 7614368

8,64 11 2951 33.791608964 90790 Q WS 7614368 + 8 [fio]

8,64 11 2952 33.791609940 90790 G WS 7614368 + 8 [fio]

8,64 11 2954 33.791611867 90790 I WS 7614368 + 8 [fio]

8,64 11 2956 33.791612977 90790 D WS 7614368 + 8 [fio]

8,64 11 2957 33.799933777 0 C WS 7614368 + 8 [0]

Incomming Requests = Writes Queued + Writes Requeued = 8763 + 0 = 8763

Outgoing Requests = Write Dispatches + Write Merges = 5380 + 3383 = 8763

另外，可以看到各個read指標都為0，因為fio全是寫操作且大小和文件系統block對齊。可以對比還是全寫操作但bs=5k(不再和文件系統block對齊)的情形，這時候read指標就不為0了，因為不對齊，文件系統需要把部分修改的block讀出來，修改然后再寫回去。

案例二：

把/dev/sde(設備號:8,64)分區並把/dev/sde2(設備號:8,66)格式化成ext4，掛載到/mnt並使用fio寫/mnt/fio-test-file (rw=randwrite ioengine=psync bs=4k fsync=1)，同時還是trace /dev/sde：

# blktrace -d /dev/sde -w 60

# blkparse -i sde

8,64 14 1000 21.217022761 96519 D WS 5857775072 + 8 [jbd2/sde2-8]

8,64 14 1001 21.225342198 0 C WS 5857775072 + 8 [0]

8,64 20 1160 21.225404128 98523 A WS 3927579616 + 8 <- (8,66) 20560864

8,64 20 1161 21.225405121 98523 Q WS 3927579616 + 8 [fio]

8,64 20 1162 21.225407092 98523 G WS 3927579616 + 8 [fio]

8,64 20 1163 21.225407687 98523 P N [fio]

8,64 20 1164 21.225409225 98523 I WS 3927579616 + 8 [fio]

8,64 20 1165 21.225410004 98523 U N [fio] 1

8,64 20 1166 21.225411107 98523 D WS 3927579616 + 8 [fio]

8,64 0 1176 21.238455782 0 C WS 3927579616 + 8 [0]

8,64 14 1002 21.238482169 96519 A WS 5857775080 + 8 <- (8,66) 1950756328

8,64 14 1003 21.238482610 96519 Q WS 5857775080 + 8 [jbd2/sde2-8]

8,64 14 1004 21.238483773 96519 G WS 5857775080 + 8 [jbd2/sde2-8]

......

Total (sde):

Reads Queued: 0, 0KiB Writes Queued: 7,558, 339,096KiB

Read Dispatches: 0, 0KiB Write Dispatches: 5,707, 339,096KiB

Reads Requeued: 0 Writes Requeued: 0

Reads Completed: 0, 0KiB Writes Completed: 5,707, 339,096KiB

Read Merges: 0, 0KiB Write Merges: 1,851, 7,404KiB

IO unplugs: 3,402 Timer unplugs: 0

# blkparse -i sde | grep -w 3927579616

8,64 20 1160 21.225404128 98523 A WS 3927579616 + 8 <- (8,66) 20560864

8,64 20 1161 21.225405121 98523 Q WS 3927579616 + 8 [fio]

8,64 20 1162 21.225407092 98523 G WS 3927579616 + 8 [fio]

8,64 20 1164 21.225409225 98523 I WS 3927579616 + 8 [fio]

8,64 20 1166 21.225411107 98523 D WS 3927579616 + 8 [fio]

8,64 0 1176 21.238455782 0 C WS 3927579616 + 8 [0]

案例三：

基於例2的數據，我們找一個merge的請求:

# blkparse -i sde | grep -w M

......

8,64 13 4434 59.194332313 96519 M WS 5857801440 + 8 [jbd2/sde2-8]

# blkparse -i sde | grep -w 5857801440

8,64 13 4432 59.194331558 96519 A WS 5857801440 + 8 <- (8,66) 1950782688

8,64 13 4433 59.194331878 96519 Q WS 5857801440 + 8 [jbd2/sde2-8]

8,64 13 4434 59.194332313 96519 M WS 5857801440 + 8 [jbd2/sde2-8]

這個請求從remap到queued，然后再merge到一個已存在的請求中，之后便追蹤不到了：因為它是其他某個請求的一部分，而不是一個獨立的請求。假如知道它被merge到哪個請求了，去追蹤那個請求，就能知道后續各個階段。另外注意，被合並的情況下，沒有get request (G)階段，而直接被合並了。

通過這三個例子我們可以看出，blktrace可以追蹤到一個特定request的各個階段，及各個階段的耗時。但這太詳細了，我們無法逐一查看各個request。這時btt命令就派上用場了，它可以生成報表。blkparse還有一個功能：把blktrace生成的{device}.blktrace.{cpu}一堆文件dump成一個二進制文件，輸出到-d指定的文件中（忽略標准輸出）。這個功能正好方便btt的使用。

# blkparse -i sde -d sde.blktrace.bin

# ls sde.blktrace.bin

sde.blktrace.bin

參考：

END

全中國只有不到1%的人關注了運維軍團

你是個有眼光的人！

（由於交流群人數已超100人，需要進群的小伙伴可以添加運維小編的微信：）

如果你喜歡我們的文章，請轉發到朋友圈

公眾號

ywjtshare

運維軍團

原文地址：https://www.sohu.com/a/436280134_733939