1What is it ?
2----------
3ioblame is a IO profiler. It gives a detailed listing of the list of
4files that running pids are doing IO to (with the aggregate amount of
5read/write to each file). The goal is that using this tool, app
6developers can identify IO heavy paths, and tune them, then
7iteratively run this tool again to measure improvements/IO reduction.
8
9ioblame is implemented as a collection of kernel filesystem
10tracepoints, and a script.
11
12What does the output from ioblame look like ?
13-------------------------------------------
14ioblame gives 2 different views.
15
16File view is the default.
17
181) File view : For each file, it gives a list of pids that are doing
19IO on that file (it also gives the amount of IO each pid does and
20the aggregate amount of IO done to the file by all pids).
21
22File: /app/Chrome/Chrome.apk
23 Chrome_ChildIOT Reads: 96 KB
24 Chrome_DBThread Reads: 652 KB
25 Chrome_FileUser Reads: 72 KB
26 Chrome_InProcGp Reads: 732 KB
27 Chrome_IOThread Reads: 1396 KB
28 Compositor Reads: 652 KB
29 CookieMonsterBa Reads: 284 KB
30 CrRendererMain Reads: 17012 KB
31 dboxed_process0 Reads: 512 KB
32 JavaBridge Reads: 128 KB
33 ogle.android.gm Reads: 14996 KB
34 WorkerPool/8556 Reads: 408 KB
35 Total Reads: 36940 KB i_size: 71354 KB
36File: /app/Gmail2Light/Gmail2Light.apk
37 AsyncTask_#2 Reads: 24 KB
38 Chrome_IOThread Reads: 68 KB
39 ogle.android.gm Reads: 1440 KB
40 Thread-6 Reads: 8 KB
41 Total Reads: 1540 KB i_size: 9736 KB
42
43And ditto for writes.
44
45To enable PID view, use -v
46
47PID: CrRendererMain
48 /app/Chrome/Chrome.apk Reads: 17012 KB i_size: 71354 KB
49 /etc/fonts.xml Reads: 24 KB i_size: 22 KB
50 /fonts/CarroisGothicSC-Regular.ttf Reads: 40 KB i_size: 39 KB
51 /fonts/ComingSoon.ttf Reads: 60 KB i_size: 57 KB
52 /fonts/CutiveMono.ttf Reads: 68 KB i_size: 67 KB
53 /fonts/DancingScript-Bold.ttf Reads: 116 KB i_size: 112 KB
54 /fonts/DancingScript-Regular.ttf Reads: 116 KB i_size: 113 KB
55 /fonts/DroidSansMono.ttf Reads: 108 KB i_size: 105 KB
56 /fonts/NotoColorEmoji.ttf Reads: 204 KB i_size: 7108 KB
57 /fonts/NotoNaskhArabic-Bold.ttf Reads: 116 KB i_size: 113 KB
58,,,
59 /fonts/NotoSerif-BoldItalic.ttf Reads: 248 KB i_size: 256 KB
60 /fonts/NotoSerif-Bold.ttf Reads: 244 KB i_size: 242 KB
61 /fonts/NotoSerif-Italic.ttf Reads: 244 KB i_size: 243 KB
62 /fonts/NotoSerif-Regular.ttf Reads: 244 KB i_size: 240 KB
63 /fonts/Roboto-BlackItalic.ttf Reads: 256 KB i_size: 322 KB
64 /fonts/Roboto-Black.ttf Reads: 256 KB i_size: 299 KB
65 /fonts/Roboto-BoldItalic.ttf Reads: 256 KB i_size: 324 KB
66 /fonts/RobotoCondensed-BoldItalic.ttf Reads: 256 KB i_size: 322 KB
67 /fonts/RobotoCondensed-Bold.ttf Reads: 256 KB i_size: 296 KB
68 /fonts/RobotoCondensed-Italic.ttf Reads: 256 KB i_size: 321 KB
69 /fonts/RobotoCondensed-LightItalic.ttf Reads: 256 KB i_size: 324 KB
70 /fonts/RobotoCondensed-Light.ttf Reads: 256 KB i_size: 295 KB
71 /fonts/RobotoCondensed-MediumItalic.ttf Reads: 256 KB i_size: 322 KB
72 /fonts/RobotoCondensed-Medium.ttf Reads: 256 KB i_size: 296 KB
73 /fonts/Roboto-LightItalic.ttf Reads: 256 KB i_size: 324 KB
74 /fonts/Roboto-MediumItalic.ttf Reads: 256 KB i_size: 323 KB
75 /fonts/Roboto-Regular.ttf Reads: 88 KB i_size: 298 KB
76 /fonts/Roboto-ThinItalic.ttf Reads: 256 KB i_size: 321 KB
77 /fonts/Roboto-Thin.ttf Reads: 256 KB i_size: 300 KB
78 /lib/libft2.so Reads: 56 KB i_size: 479 KB
79 /lib/libicuuc.so Reads: 88 KB i_size: 1182 KB
80 Total Reads: 32760 KB
81
82And ditto for writes.
83
84For the -p, writepages option, ioblame does not (and cannot) give you
85the app/pid that did the original write (since the write most likely
86happens from a flush thread or VM reclaim). In this mode, we only get
87the pathname of the file and the amount of data written out.
88
89Finally, it reports the total amount of file data IO done by pids and
90the total IO done to the block device. So we can look at IO overheads
91(eg block level prefetching, filesystem metadata overhead etc).
92
93For detailed examples, look at ioblame-gmail-launch.example and
94ioblame-gmail-run.example.
95
96How do I run ioblame ?
97--------------------
98ioblame -r [ I am only interested in reads ]
99ioblame -w [ I am only interested in writes ]
100ioblame -p [ I am only interested in writepage(s) - mmap'ed writes ]
101ioblame -r -w -p [ I am only interested in reads, writes and writepages ]
102and finally, -v adds the PID view
103
1041) The most common way of running ioblame is to start ioblame, then go
105off and launch the app(s) of interest, do interesting stuff with the
106app(s), and when finished with the app, hit ^C ONCE on
107ioblame. Hitting ^C once will cause ioblame to catch the signal, break
108out of the sleep, terminate its tracing, and process the ftraces and
109dump out IO stats for the app.
110
111example :
112
113srmohan0.mtv.corp.google.com> sh ioblame.sh -r -w -p
114Found aosp_gobo Device
115OK to kill sleep when test is done
116^Csignal INT received, killing streaming trace capture
117
118(at this point, run your apps, when done type ^C ONCE) and output will
119appear on stdout.
120
1212) Sometimes, we want to do IO profiling in a different way (instead of
122running something and then hitting ^C on ioblame). For instance, we
123might want to do IO profiling related to the launch of an App. This
124requires you to modify the script slightly, as described in the next
125paragraph.
126
127If you want to do IO profiling related to App launch, you need to modify
1282 functions - prep_to_do_something and do_something. Again examples of
129changes to these functions clarifies things better :
130
131prep_to_do_something() {
132 adb shell "am force-stop com.google.android.gm" # This line I added for example
133 # stops the running app (gmail)
134 adb shell 'echo 3 > /proc/sys/vm/drop_caches'
135 sleep 1
136}
137
138do_something() {
139 # Arrange things so that the first SIGINT will kill the
140 # child process (sleep), but will return to the parent.
141# trap 'catch_sigint' INT
142# echo "OK to kill sleep when test is done"
143# sleep 1d
144 # For the purpose of this example, I commented out the above 3 lines that
145 # make ioblame sleep forever after catching the SIGINT and instead it launches
146 # gmail, waiting for launch to complete. When launch completes, ioblame will
147 # stop tracing, and process the traces
148 adb shell "am start -W -n com.google.android.gm/.ConversationListActivityGmail"
149}
150
151Limitations :
152-----------
153The ioblame kernel tracepoints currently only cover the getpage(s)
154path (so all filesystem reads) and filesystem write() syscalls. There
155are no tracepoints in the putpage(s) paths. This is because when
156putpage(s) is called, we most often cannot tell which thread/pid has
157dirtied the page that is being written out, because the majority of
158putpage(s) happen from the flush threads or from the pageout
159threads. The upshot of this is the mmap'ed writes are not reported by
160ioblame. In practice, while mmap'ed reads are very common, mmap'ed
161writes are infrequent.
162
163Kernel Patches Required :
164-----------------------
165ioblame needs the kernel to be patched with these 3 kernel patches.
166Without these patches, ioblame won't work at all.
167
168commit ae2f6765db98e2fcb99082e336dd8b24e7644620
169Author: Mohan Srinivasan <srmohan@google.com>
170Date: Fri Mar 10 16:08:30 2017 -0800
171
172 ANDROID: Replace spaces by '_' for some android filesystem tracepoints.
173
174 Andoid files frequently have spaces in them, as do cmdline strings.
175 Replace these spaces with '_', so tools that parse these tracepoints
176 don't get terribly confused.
177
178 Change-Id: I1cbbedf5c803aa6a58d9b8b7836e9125683c49d1
179 Signed-off-by: Mohan Srinivasan <srmohan@google.com>
180 (cherry picked from commit 5035d5f0933758dd515327d038e5bef7e40dbaa7)
181
182commit a2a04ea83d2960867324fa059ba1eedc2fc7784e (HEAD -> android-4.4)
183Author: Mohan Srinivasan <srmohan@google.com>
184Date: Fri Feb 3 15:48:03 2017 -0800
185
186 ANDROID: Refactor fs readpage/write tracepoints.
187
188 Refactor the fs readpage/write tracepoints to move the
189 inode->path lookup outside the tracepoint code, and pass a pointer
190 to the path into the tracepoint code instead. This is necessary
191 because the tracepoint code runs non-preemptible. Thanks to
192 Trilok Soni for catching this in 4.4.
193
194 Change-Id: I7486c5947918d155a30c61d6b9cd5027cf8fbe15
195 Signed-off-by: Mohan Srinivasan <srmohan@google.com>
196
197commit 32cbbe59538d2dd0b77822cc27ce32ca487c467d
198Author: Mohan Srinivasan <srmohan@google.com>
199Date: Mon Sep 19 17:33:50 2016 -0700
200
201 ANDROID: fs: FS tracepoints to track IO.
202
203 Adds tracepoints in ext4/f2fs/mpage to track readpages/buffered
204 write()s. This allows us to track files that are being read/written
205 to PIDs.
206
207 Change-Id: I26bd36f933108927d6903da04d8cb42fd9c3ef3d
208 Signed-off-by: Mohan Srinivasan <srmohan@google.com>
209
210The -w (writepages) option requires this additional patch and
211currently only with f2fs.
212
213commit c60bc59c6af4fbdeaf7bbeaebee6b55d9e488324 (HEAD ->
214android-mtk-gobo-3.18)
215Author: Mohan Srinivasan <srmohan@google.com>
216Date: Fri Sep 8 13:53:01 2017 -0700
217
218 Tracepoints in f2fs data writepage(s).
219
220 Tracepoints f2fs writepage(s). This is experimental (for now).
221 Allowing ioblame to track <pathname, amount of data written>
222 for files.
223
224 Signed-off-by: Mohan Srinivasan <srmohan@google.com>
225 Change-Id: I4c76c6f442e0a2c5872225f8113935f9f368cc64
226