[Android] ioblameでお手軽にディスクIOをプロファイルする

ioblameとは？

AOSPに含まれるAndroid用のIOプロファイラ。
system/extras/ioblame/ioblame.shにある。
adb接続可能なPCで実行することで、path/PIDごとにどれだけのIOが発生したかを出力してくれる。

なお、動作確認およびソースコードの確認はAndroid8.1.0(API level27)で行っている。

出力例

出力例を見るのがもっともわかりやすいと思うので、
ChromeでYoutube動画を再生中に10秒間ioblameを実行した結果を以下に載せる。
たった10秒だが、473KB書き込まれていて、そのうちの大半(464KB)がキャッシュデータであることがわかる。

Writes :
_______

FILE VIEW:
File: /data/com.android.chrome/app_chrome/Default/.com.google.Chrome.8qtZ02
            TaskSchedulerFo Writes: 9 KB
            Total Writes: 9 KB i_size: 8 KB
File: /data/com.android.chrome/cache/Cache/03ad4e2cbb9103d8_0
            TaskSchedulerFo Writes: 5 KB
            Total Writes: 5 KB i_size: 725 bytes
File: /data/com.android.chrome/cache/Cache/3f428aadfc44830d_0
            TaskSchedulerFo Writes: 459 KB
            Total Writes: 459 KB i_size: 96 KB
Grand Total File DATA KB Writes 473
PID VIEW:
PID: TaskSchedulerFo
            /data/com.android.chrome/app_chrome/Default/.com.google.Chrome.8qtZ02 Writes: 9 KB i_size: 8 KB
            /data/com.android.chrome/cache/Cache/03ad4e2cbb9103d8_0 Writes: 5 KB i_size: 725 bytes
            /data/com.android.chrome/cache/Cache/3f428aadfc44830d_0 Writes: 459 KB i_size: 96 KB
            Total Writes: 473 KB
Grand Total File DATA KB Writes 473
WRITE DELTA: Total Blockdev Writes KB - Total File Data Writes KB = 235 KB
Total (ALL) Write IOs dm-0 = 48

だいたいは見たままだが、ちょっと迷うかもしれない項目について補足しておくと、

• i_size: 最終的なファイルサイズ。

• WRITE DELTA: アプリから明示的にwriteしていないがblockdeviceに発生しているIO。
  例えばファイルシステムのメタデータの更新やjournalファイルの更新に相当する。

• Write IOs: 集計中に発生したwriteの回数。

使い方

起動オプション

• -r: 読み出しサイズのパスごとの集計情報を出力する。
• -w: 書き込みサイズのパスごとの集計情報を出力する。
• -v: PIDごとの集計情報も出力する。-rか-wと併用する。
• -p: writepagesの総量を集計する。ただし、f2fsしかサポートしていないことに加えて、writepages時点では書き込み元プロセスがわからないためパスごとの集計のみ。

前述の出力例は、base ioblame.sh -w -v。

プロファイリングの停止方法

デフォルトでは30日後に勝手にスクリプトが停止する。
が、SIGINTをtrapしているので、テストシーケンスが終わったらCtrl-Cで止めればいい。

また、スクリプト中にはdo_somethingという関数が用意されている。
もしテストシーケンスがadb等で記述可能なら、do_somethingの中身を書き換えることで効果確認をほぼ自動化できる。

system/extras/ioblame/ioblame.sh

do_something() {
    # Arrange things so that the first SIGINT will kill the
    # child process (sleep), but will return to the parent.
    trap 'catch_sigint'  INT
    echo "OK to kill sleep when test is done"
    sleep 30d
#    adb shell "am start -W -n com.android.chrome/com.google.android.apps.chrome.Main"
#    adb shell "am start -W -n com.google.android.gm/.ConversationListActivityGmail"
}

Trouble Shooting1. Unknown Device

ioblame.shはgetprop ro.product.nameでAndroid deviceのモデル名を取得し、
そのモデル名からプロファイル対象のブロックデバイス名を決め打っている。
そんなにたくさんサポートしていないので、Unknown Deviceと言われたら素直に追加するしかない。

下記は、確認したemulator環境(Pixel_3a_XL_API_27)に対応するための修正。

残念ながらblock_deviceには一つしか指定できない。
ここでは/dataにマウントされていたdm-0を指定している。

diff --git a/ioblame.sh b/ioblame.sh
index cdd1d30..7e1b04c 100755
--- a/ioblame.sh
+++ b/ioblame.sh
@@ -56,6 +56,9 @@ getmodel() {
        volantis | volantisg)
            get_volantis_devnames
            ;;
+       sdk_gphone_x86)
+           get_sdk_gphone_x86_devnames
+           ;;
        *)
            echo Unknown Device $model
            exit 1
@@ -92,6 +95,11 @@ get_angler_devnames () {
     bdev_set=true
 }

+get_sdk_gphone_x86_devnames() {
+    bdev_set=true
+    block_device=dm-0
+}
+
 disk_stats_before() {
     if [ $bdev_set == true ]; then
        DISKSTATS=`adb shell 'cat /proc/diskstats' | fgrep -w $block_device `

$ adb shell 'grep "/data " /proc/mounts'
/dev/block/dm-0 /data ext4 rw,seclabel,nosuid,nodev,noatime,errors=panic,data=ordered 0 0

Trouble Shooting2. unexpected operator

ioblame.shはshebangがshになっている。
Ubuntu16.04だとデフォルトshはdashだが、dashではtestコマンドがbuiltinで==に対応していない。
ioblame.shでは==を多用しているのでunexpected operatorエラーが大量に出る。
起動時にbash ioblame.shとすることで回避可能。

実装

プロセス・パスごとのIO情報は、event ftraceを使って得たトレースログを解析して得ている。
使うeventは、android_fs_dataread_start, android_fs_datawrite_start, android_fs_writepagesの３種類。

blockdeviceのIO情報は、/proc/diskstatsをテスト開始・テスト終了時点で取得し、差分を比較している。

あとはもうゴリゴリshellスクリプトで集計してる。おっふ必須。

参考

ioblame.sh - AOSP
README - AOSP
iostats - kernel.org