What is it ?
ioblame is a IO profiler. It gives a detailed listing of the list of files that running pids are doing IO to (with the aggregate amount of read/write to each file). The goal is that using this tool, app developers can identify IO heavy paths, and tune them, then iteratively run this tool again to measure improvements/IO reduction.
ioblame is implemented as a collection of kernel filesystem tracepoints, and a script.
What does the output from ioblame look like ?
ioblame gives 2 different views.
File view is the default.
- File view : For each file, it gives a list of pids that are doing IO on that file (it also gives the amount of IO each pid does and the aggregate amount of IO done to the file by all pids).
File: /app/Chrome/Chrome.apk Chrome_ChildIOT Reads: 96 KB Chrome_DBThread Reads: 652 KB Chrome_FileUser Reads: 72 KB Chrome_InProcGp Reads: 732 KB Chrome_IOThread Reads: 1396 KB Compositor Reads: 652 KB CookieMonsterBa Reads: 284 KB CrRendererMain Reads: 17012 KB dboxed_process0 Reads: 512 KB JavaBridge Reads: 128 KB ogle.android.gm Reads: 14996 KB WorkerPool/8556 Reads: 408 KB Total Reads: 36940 KB i_size: 71354 KB File: /app/Gmail2Light/Gmail2Light.apk AsyncTask_#2 Reads: 24 KB Chrome_IOThread Reads: 68 KB ogle.android.gm Reads: 1440 KB Thread-6 Reads: 8 KB Total Reads: 1540 KB i_size: 9736 KB
And ditto for writes.
To enable PID view, use -v
PID: CrRendererMain /app/Chrome/Chrome.apk Reads: 17012 KB i_size: 71354 KB /etc/fonts.xml Reads: 24 KB i_size: 22 KB /fonts/CarroisGothicSC-Regular.ttf Reads: 40 KB i_size: 39 KB /fonts/ComingSoon.ttf Reads: 60 KB i_size: 57 KB /fonts/CutiveMono.ttf Reads: 68 KB i_size: 67 KB /fonts/DancingScript-Bold.ttf Reads: 116 KB i_size: 112 KB /fonts/DancingScript-Regular.ttf Reads: 116 KB i_size: 113 KB /fonts/DroidSansMono.ttf Reads: 108 KB i_size: 105 KB /fonts/NotoColorEmoji.ttf Reads: 204 KB i_size: 7108 KB /fonts/NotoNaskhArabic-Bold.ttf Reads: 116 KB i_size: 113 KB ,,, /fonts/NotoSerif-BoldItalic.ttf Reads: 248 KB i_size: 256 KB /fonts/NotoSerif-Bold.ttf Reads: 244 KB i_size: 242 KB /fonts/NotoSerif-Italic.ttf Reads: 244 KB i_size: 243 KB /fonts/NotoSerif-Regular.ttf Reads: 244 KB i_size: 240 KB /fonts/Roboto-BlackItalic.ttf Reads: 256 KB i_size: 322 KB /fonts/Roboto-Black.ttf Reads: 256 KB i_size: 299 KB /fonts/Roboto-BoldItalic.ttf Reads: 256 KB i_size: 324 KB /fonts/RobotoCondensed-BoldItalic.ttf Reads: 256 KB i_size: 322 KB /fonts/RobotoCondensed-Bold.ttf Reads: 256 KB i_size: 296 KB /fonts/RobotoCondensed-Italic.ttf Reads: 256 KB i_size: 321 KB /fonts/RobotoCondensed-LightItalic.ttf Reads: 256 KB i_size: 324 KB /fonts/RobotoCondensed-Light.ttf Reads: 256 KB i_size: 295 KB /fonts/RobotoCondensed-MediumItalic.ttf Reads: 256 KB i_size: 322 KB /fonts/RobotoCondensed-Medium.ttf Reads: 256 KB i_size: 296 KB /fonts/Roboto-LightItalic.ttf Reads: 256 KB i_size: 324 KB /fonts/Roboto-MediumItalic.ttf Reads: 256 KB i_size: 323 KB /fonts/Roboto-Regular.ttf Reads: 88 KB i_size: 298 KB /fonts/Roboto-ThinItalic.ttf Reads: 256 KB i_size: 321 KB /fonts/Roboto-Thin.ttf Reads: 256 KB i_size: 300 KB /lib/libft2.so Reads: 56 KB i_size: 479 KB /lib/libicuuc.so Reads: 88 KB i_size: 1182 KB Total Reads: 32760 KB
And ditto for writes.
For the -p, writepages option, ioblame does not (and cannot) give you the app/pid that did the original write (since the write most likely happens from a flush thread or VM reclaim). In this mode, we only get the pathname of the file and the amount of data written out.
Finally, it reports the total amount of file data IO done by pids and the total IO done to the block device. So we can look at IO overheads (eg block level prefetching, filesystem metadata overhead etc).
For detailed examples, look at ioblame-gmail-launch.example and ioblame-gmail-run.example.
How do I run ioblame ?
ioblame -r [ I am only interested in reads ] ioblame -w [ I am only interested in writes ] ioblame -p [ I am only interested in writepage(s) - mmap'ed writes ] ioblame -r -w -p [ I am only interested in reads, writes and writepages ] and finally, -v adds the PID view
- The most common way of running ioblame is to start ioblame, then go off and launch the app(s) of interest, do interesting stuff with the app(s), and when finished with the app, hit ^C ONCE on ioblame. Hitting ^C once will cause ioblame to catch the signal, break out of the sleep, terminate its tracing, and process the ftraces and dump out IO stats for the app.
example :
srmohan0.mtv.corp.google.com> sh ioblame.sh -r -w -p Found aosp_gobo Device OK to kill sleep when test is done ^Csignal INT received, killing streaming trace capture
(at this point, run your apps, when done type ^C ONCE) and output will appear on stdout.
- Sometimes, we want to do IO profiling in a different way (instead of running something and then hitting ^C on ioblame). For instance, we might want to do IO profiling related to the launch of an App. This requires you to modify the script slightly, as described in the next paragraph.
If you want to do IO profiling related to App launch, you need to modify 2 functions - prep_to_do_something and do_something. Again examples of changes to these functions clarifies things better :
prep_to_do_something() { adb shell "am force-stop com.google.android.gm" # This line I added for example # stops the running app (gmail) adb shell 'echo 3 > /proc/sys/vm/drop_caches' sleep 1 }
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 1d
# For the purpose of this example, I commented out the above 3 lines that
# make ioblame sleep forever after catching the SIGINT and instead it launches
# gmail, waiting for launch to complete. When launch completes, ioblame will
# stop tracing, and process the traces
adb shell "am start -W -n com.google.android.gm/.ConversationListActivityGmail"
}
Limitations :
The ioblame kernel tracepoints currently only cover the getpage(s) path (so all filesystem reads) and filesystem write() syscalls. There are no tracepoints in the putpage(s) paths. This is because when putpage(s) is called, we most often cannot tell which thread/pid has dirtied the page that is being written out, because the majority of putpage(s) happen from the flush threads or from the pageout threads. The upshot of this is the mmap'ed writes are not reported by ioblame. In practice, while mmap'ed reads are very common, mmap'ed writes are infrequent.
Kernel Patches Required :
ioblame needs the kernel to be patched with these 3 kernel patches. Without these patches, ioblame won't work at all.
commit ae2f6765
Author: Mohan Srinivasan srmohan@google.com
Date: Fri Mar 10 16:08:30 2017 -0800
ANDROID: Replace spaces by '_' for some android filesystem tracepoints.
Andoid files frequently have spaces in them, as do cmdline strings.
Replace these spaces with '_', so tools that parse these tracepoints
don't get terribly confused.
Change-Id: I1cbbedf5c803aa6a58d9b8b7836e9125683c49d1
Signed-off-by: Mohan Srinivasan <srmohan@google.com>
(cherry picked from commit 5035d5f0933758dd515327d038e5bef7e40dbaa7)
commit a2a04ea8 (HEAD -> android-4.4)
Author: Mohan Srinivasan srmohan@google.com
Date: Fri Feb 3 15:48:03 2017 -0800
ANDROID: Refactor fs readpage/write tracepoints.
Refactor the fs readpage/write tracepoints to move the
inode->path lookup outside the tracepoint code, and pass a pointer
to the path into the tracepoint code instead. This is necessary
because the tracepoint code runs non-preemptible. Thanks to
Trilok Soni for catching this in 4.4.
Change-Id: I7486c5947918d155a30c61d6b9cd5027cf8fbe15
Signed-off-by: Mohan Srinivasan <srmohan@google.com>
commit 32cbbe59
Author: Mohan Srinivasan srmohan@google.com
Date: Mon Sep 19 17:33:50 2016 -0700
ANDROID: fs: FS tracepoints to track IO.
Adds tracepoints in ext4/f2fs/mpage to track readpages/buffered
write()s. This allows us to track files that are being read/written
to PIDs.
Change-Id: I26bd36f933108927d6903da04d8cb42fd9c3ef3d
Signed-off-by: Mohan Srinivasan <srmohan@google.com>
The -w (writepages) option requires this additional patch and currently only with f2fs.
commit c60bc59c (HEAD ->
android-mtk-gobo-3.18)
Author: Mohan Srinivasan srmohan@google.com
Date: Fri Sep 8 13:53:01 2017 -0700
Tracepoints in f2fs data writepage(s).
Tracepoints f2fs writepage(s). This is experimental (for now).
Allowing ioblame to track <pathname, amount of data written>
for files.
Signed-off-by: Mohan Srinivasan <srmohan@google.com>
Change-Id: I4c76c6f442e0a2c5872225f8113935f9f368cc64