ioblame/README

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.

1) 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

1) 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.

2) 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 ae2f6765db98e2fcb99082e336dd8b24e7644620
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 a2a04ea83d2960867324fa059ba1eedc2fc7784e (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 32cbbe59538d2dd0b77822cc27ce32ca487c467d
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 c60bc59c6af4fbdeaf7bbeaebee6b55d9e488324 (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