ioblame/ioblame.sh

   1 #!/bin/sh -u
   2
   3 parseoptions() {
   4     trace_reads=false
   5     trace_writes=false
   6
   7     while [ $# -ge 1 ]
   8     do
   9         case $1 in
  10             -r)
  11                 trace_reads=true
  12                 ;;
  13             -w)
  14                 trace_writes=true
  15                 ;;
  16             *)
  17                 usage
  18                 ;;
  19             esac
  20         shift
  21     done
  22 }
  23
  24 usage() {
  25     echo "Usage: $0 [-r|-w]"
  26     exit 1
  27 }
  28
  29 getmodel() {
  30     model=`adb shell getprop ro.product.name`
  31     # Releases are inconsistent with various trailing characters, remove them all
  32     model=`echo $model | sed 's/[ \t\r\n]*$//' `
  33     echo Found $model Device
  34
  35     case $model in
  36         aosp_gobo)
  37             get_go_devnames
  38             ;;
  39         marlin | sailfish)
  40             get_marlin_sailfish_devnames
  41             ;;
  42         angler)
  43             get_angler_devnames
  44             ;;
  45         bullhead)
  46             get_bullhead_devnames
  47             ;;
  48         volantis | volantisg)
  49             get_volantis_devnames
  50             ;;
  51         *)
  52             echo Unknown Device $model
  53             exit 1
  54             ;;
  55     esac
  56 }
  57
  58 get_go_devnames () {
  59     # Hardcoding all of the mmcblk0 device for now
  60     block_device=mmcblk0
  61     bdev_set=true
  62 }
  63
  64 get_volantis_devnames() {
  65     bdev_set=true
  66     block_device=mmcblk0
  67 }
  68
  69 get_bullhead_devnames() {
  70     bdev_set=true
  71     block_device=mmcblk0
  72 }
  73
  74 get_marlin_sailfish_devnames() {
  75     bdev_set=true
  76     block_device=sda
  77 }
  78
  79 get_angler_devnames () {
  80     # Get the underlying bdev from the "by-name" mapping
  81     block_device=`adb shell 'find /dev/block/platform -name by-name | xargs ls -l' | grep system | awk '{ print $10 }' `
  82     # extract the last component of the absolute device pathname we got above
  83     block_device=`echo $block_device | awk 'BEGIN { FS ="/" } ; { print $4 }' | sed 's/p.*//g' `
  84     bdev_set=true
  85 }
  86
  87 disk_stats_before() {
  88     if [ $bdev_set == true ]; then
  89         DISKSTATS=`adb shell 'cat /proc/diskstats' | fgrep -w $block_device `
  90         if [ $trace_reads == true ]; then
  91             # Get BEFORE read stats for bdev
  92             BEFORE_RD_IOS=`echo $DISKSTATS | awk '{ print $4 }' `
  93             BEFORE_RD_SECTORS=`echo $DISKSTATS | awk '{ print $6 }' `
  94         fi
  95         if [ $trace_writes == true ]; then
  96             # Get BEFORE write stats for bdev
  97             BEFORE_WR_IOS=`echo $DISKSTATS | awk '{ print $8 }' `
  98             BEFORE_WR_SECTORS=`echo $DISKSTATS | awk '{ print $10 }' `
  99         fi
 100     fi
 101 }
 102
 103 disk_stats_after() {
 104     if [ $bdev_set == true ]; then
 105         DISKSTATS=`adb shell 'cat /proc/diskstats' | fgrep -w $block_device `
 106         if [ $trace_reads == true ]; then
 107             # Get AFTER read stats for bdev
 108             AFTER_RD_IOS=`echo $DISKSTATS | awk '{ print $4 }' `
 109             AFTER_RD_SECTORS=`echo $DISKSTATS | awk '{ print $6 }' `
 110         fi
 111         if [ $trace_writes == true ]; then
 112             # Get BEFORE write stats for bdev
 113             AFTER_WR_IOS=`echo $DISKSTATS | awk '{ print $8 }' `
 114             AFTER_WR_SECTORS=`echo $DISKSTATS | awk '{ print $10 }' `
 115         fi
 116     fi
 117 }
 118
 119 disk_stats_delta_rd() {
 120     file_data_KB=$1
 121     if [ $bdev_set == true ]; then
 122         # Sectors to KB
 123         READ_KB=`expr $AFTER_RD_SECTORS - $BEFORE_RD_SECTORS`
 124         READ_KB=`expr $READ_KB / 2`
 125         echo "Total (ALL) Read KB $block_device = "$READ_KB
 126         BLOCK_MINUS_FILE=`expr $READ_KB - $file_data_KB`
 127         echo "READ DELTA: Total Blockdev Reads KB - Total File Data Reads KB = "$BLOCK_MINUS_FILE KB
 128         echo "Total (ALL) Read IOs $block_device = "`expr $AFTER_RD_IOS - $BEFORE_RD_IOS`
 129     fi
 130 }
 131
 132 disk_stats_delta_wr() {
 133     file_data_KB=$1
 134     if [ $bdev_set == true ]; then
 135         # Sectors to KB
 136         WRITE_KB=`expr $AFTER_WR_SECTORS - $BEFORE_WR_SECTORS`
 137         WRITE_KB=`expr $WRITE_KB / 2`
 138         echo "Total (ALL) Write KB $block_device = "$WRITE_KB
 139         BLOCK_MINUS_FILE=`expr $WRITE_KB - $file_data_KB`
 140         echo "WRITE DELTA: Total Blockdev Writes KB - Total File Data Writes KB = "$BLOCK_MINUS_FILE KB
 141         echo "Total (ALL) Write IOs $block_device = "`expr $AFTER_WR_IOS - $BEFORE_WR_IOS`
 142     fi
 143 }
 144
 145 # For good measure clean up traces and reenable traces
 146 clean_up_tracepoints() {
 147     # This is a good point to check if the Android FS tracepoints are enabled in the
 148     # kernel or not
 149     tracepoint_exists=`adb shell 'if [ -d /sys/kernel/debug/tracing/events/android_fs ]; then echo 0; else echo 1; fi' `
 150     if [ $tracepoint_exists == 1 ]; then
 151         echo "Android FS tracepoints not enabled in kernel. Exiting..."
 152         exit 1
 153     fi
 154     adb shell 'echo 0 > /sys/kernel/debug/tracing/tracing_on'
 155     adb shell 'echo 0 > /sys/kernel/debug/tracing/trace'
 156     if [ $trace_reads == true ]; then
 157         adb shell 'echo 1 > /sys/kernel/debug/tracing/events/android_fs/android_fs_dataread_start/enable'
 158         adb shell 'echo 1 > /sys/kernel/debug/tracing/events/android_fs/android_fs_dataread_end/enable'
 159     fi
 160     if [ $trace_writes == true ]; then
 161         adb shell 'echo 1 > /sys/kernel/debug/tracing/events/android_fs/android_fs_datawrite_start/enable'
 162         adb shell 'echo 1 > /sys/kernel/debug/tracing/events/android_fs/android_fs_datawrite_end/enable'
 163     fi
 164     adb shell 'echo 1 > /sys/kernel/debug/tracing/tracing_on'
 165 }
 166
 167 # stream trace out of trace_pipe
 168 # Start this in the background ('&')
 169 streamtrace_start() {
 170     adb shell cat /sys/kernel/debug/tracing/trace_pipe > trace_saved
 171 }
 172
 173 # When signal is received, the trace_pipe reader will get killed
 174 # Call this (just to make sure anyway)
 175 streamtrace_end() {
 176     ps_line=`ps -ef | grep trace_pipe | grep adb `
 177     if [ $? == 0 ]; then
 178         echo Killing `echo $ps_line | awk '{s = ""; for (i=8; i <= NF ; i++) s = s $i " "; print s}' `
 179         kill `echo $ps_line | awk '{print $2}' `
 180     fi
 181 }
 182
 183 copyout_trace() {
 184     streamtrace_end
 185     if [ $trace_reads == true ]; then
 186         adb shell 'echo 0 > /sys/kernel/debug/tracing/events/android_fs/android_fs_dataread_start/enable'
 187         adb shell 'echo 0 > /sys/kernel/debug/tracing/events/android_fs/android_fs_dataread_end/enable'
 188     fi
 189     if [ $trace_writes == true ]; then
 190         adb shell 'echo 0 > /sys/kernel/debug/tracing/events/android_fs/android_fs_datawrite_start/enable'
 191         adb shell 'echo 0 > /sys/kernel/debug/tracing/events/android_fs/android_fs_datawrite_end/enable'
 192     fi
 193     adb shell 'echo 0 > /sys/kernel/debug/tracing/tracing_on'
 194 }
 195
 196 prep_tracefile_common() {
 197     cp trace_saved $infile
 198     # Strip away all the extraneous stuff first
 199     fgrep $1 $infile | sed 's/^.* \[.*\] //' | sed s/://g | sed s/,//g > foo
 200     mv foo $infile
 201 }
 202
 203 prep_tracefile_rd() {
 204     prep_tracefile_common android_fs_dataread
 205     # Strip away unnecessary stuff so we can compute latencies easily
 206     fgrep android_fs_dataread_start $infile > foo0
 207     # Throw away everything upto and including android_fs_dataread:
 208     cat foo0 | sed -n -e 's/^.*android_fs_dataread_start //p' > foo1
 209     mv foo1 $infile
 210     # At this stage, $infile should the following format :
 211     # entry_name <filename> offset <offset> bytes <bytes> cmdline <cmdline> pid <pid> i_size <i_size> ino <ino>
 212     rm foo0
 213 }
 214
 215 # Latencies not supported for Writes. 'Write End' is just when the data has been
 216 # written back to page cache.
 217 prep_tracefile_wr() {
 218     prep_tracefile_common android_fs_datawrite
 219     fgrep android_fs_datawrite_start $infile > foo0
 220     # Throw away everything upto and including android_fs_datawrite:
 221     cat foo0 | sed -n -e 's/^.*android_fs_datawrite_start //p' > foo1
 222     mv foo1 $infile
 223     # At this stage, $infile should the following format :
 224     # entry_name <filename> offset <offset> bytes <bytes> cmdline <cmdline> pid <pid> i_size <i_size> ino <ino>
 225     rm foo0
 226 }
 227
 228 get_unique_files() {
 229     # Sort first by filename, then by pid
 230     cat $infile | sed s/,//g  | sort -d -k2,2 -k8,8 > foo1
 231     mv foo1 $infile
 232     # $infile now contains lines sorted by <filename, pid>
 233     # How many unique files are there ?
 234     cat $infile | awk '{ print $2 }' > foo1
 235     cat foo1 | uniq > uniq_files
 236     rm foo1
 237 }
 238
 239 get_unique_pids_byfile() {
 240     # How many unique pids are there reading this file ?
 241     cat $1 | awk '{ print $8 }' > foo1
 242     cat foo1 | uniq > uniq_pids_byfile
 243     rm foo1
 244 }
 245
 246 get_unique_pids() {
 247     # Sort first by pid, then by filename
 248     cat $infile | sed s/,//g  | sort -d -k8,8 -k2,2 > foo1
 249     mv foo1 $infile
 250     # $infile now contains lines sorted by <pid, filename>
 251     # How many unique pids are there ?
 252     cat $infile | awk '{ print $8 }' > foo1
 253     cat foo1 | uniq > uniq_pids
 254     rm foo1
 255 }
 256
 257 get_unique_files_bypid() {
 258     # How many unique files are there read by this pid ?
 259     cat $1 | awk '{ print $2 }' > foo1
 260     cat foo1 | uniq > uniq_files_bypid
 261     rm foo1
 262 }
 263
 264 catch_sigint()
 265 {
 266     echo "signal INT received, killing streaming trace capture"
 267     streamtrace_end
 268 }
 269
 270
 271 prep_to_do_something() {
 272 #    adb shell "am force-stop com.android.chrome"
 273 #    adb shell "am force-stop com.google.android.gm"
 274     adb shell 'echo 3 > /proc/sys/vm/drop_caches'
 275     sleep 1
 276 }
 277
 278 do_something() {
 279     # Arrange things so that the first SIGINT will kill the
 280     # child process (sleep), but will return to the parent.
 281     trap 'catch_sigint'  INT
 282     echo "OK to kill sleep when test is done"
 283     sleep 30d
 284 #    adb shell "am start -W -n com.android.chrome/com.google.android.apps.chrome.Main"
 285 #    adb shell "am start -W -n com.google.android.gm/.ConversationListActivityGmail"
 286 }
 287
 288 # Get the aggregate list of files read/written. For each file, break up the IOs by pid
 289 process_files() {
 290     read_write=$1
 291     get_unique_files
 292     list_of_files=`cat uniq_files`
 293     # $list_of_files is a list of all the files involved in IO
 294     #
 295     # Loop over each file that was involved in IO
 296     # Find all the pids doing IO on that file
 297     # Aggregate the IO done by each pid on that file and dump it out
 298     #
 299     grand_total_KB=0
 300     for i in $list_of_files
 301     do
 302         echo "File: $i"
 303         total_file_KB=0
 304         # Get just the tracepoints for this file
 305         fgrep -w "$i" $infile > subtrace
 306         # Get all the pids doing IO on this file
 307         get_unique_pids_byfile subtrace
 308         list_of_pids=`cat uniq_pids_byfile`
 309         # $list_of_pids is a list of all the pids doing IO to file $i
 310         for j in $list_of_pids
 311         do
 312             echo -n "            $j $read_write: "
 313             pid_KB=`fgrep -w "$j" subtrace | awk '{ bytes += $6 } END { print bytes }' `
 314             pid_KB=`expr $pid_KB / 1024`
 315             echo "$pid_KB KB"
 316             total_file_KB=`expr $total_file_KB + $pid_KB`
 317         done
 318         i_size=`tail -n1 subtrace  | awk '{ if ($12 > 1024) printf "%d KB", ($12/1024); else printf "%d bytes", $12; }' `
 319         echo "            Total $read_write: $total_file_KB KB i_size: $i_size"
 320         grand_total_KB=`expr $grand_total_KB + $total_file_KB`
 321     done
 322     echo "Grand Total File DATA KB $read_write $grand_total_KB"
 323 }
 324
 325 # Get the aggregate list of pids. For each pid, break up the IOs by file
 326 process_pids() {
 327     read_write=$1
 328     get_unique_pids
 329     list_of_pids=`cat uniq_pids`
 330     # $list_of_pids is a list of all the pids involved in IO
 331     #
 332     # Loop over each pid that was involved in IO
 333     # Find all the files the pid was doing IO on
 334     # Aggregate the IO done by the pid for each file and dump it out
 335     #
 336     grand_total_KB=0
 337     for i in $list_of_pids
 338     do
 339         echo "PID: $i"
 340         total_pid_KB=0
 341         # Get just the tracepoints for this pid
 342         fgrep -w "$i" $infile > subtrace
 343         # Get all the pids doing IO on this file
 344         get_unique_files_bypid subtrace
 345         list_of_files=`cat uniq_files_bypid`
 346         # $list_of_files is a list of all the files IO'ed by this pid
 347         for j in $list_of_files
 348         do
 349             i_size=`fgrep -w "$j" subtrace | tail -n1 | awk '{ if ($12 > 1024) printf "%d KB", ($12/1024); else printf "%d bytes", $12; }' `
 350             file_KB=`fgrep -w "$j" subtrace | awk '{ bytes += $6 } END { print bytes }' `
 351             file_KB=`expr $file_KB / 1024`
 352             echo "            $j $read_write: $file_KB KB i_size: $i_size"
 353             total_pid_KB=`expr $total_pid_KB + $file_KB`
 354         done
 355         echo "            Total $read_write: $total_pid_KB KB"
 356         grand_total_KB=`expr $grand_total_KB + $total_pid_KB`
 357     done
 358     echo "Grand Total File DATA KB $read_write $grand_total_KB"
 359 }
 360
 361 # main() starts here :
 362
 363 if [ $# -lt 1 ]; then
 364     usage
 365 fi
 366
 367 bdev_set=false
 368 infile=tracefile.$$
 369
 370 parseoptions $@
 371 adb root && sleep 2
 372 getmodel
 373
 374 prep_to_do_something
 375
 376 clean_up_tracepoints
 377 disk_stats_before
 378 # Start streaming the trace into the tracefile
 379 streamtrace_start &
 380
 381 do_something
 382
 383 streamtrace_end
 384 disk_stats_after
 385
 386 copyout_trace
 387
 388 if [ $trace_reads == true ]; then
 389     echo
 390     echo "READS :"
 391     echo "_______"
 392     echo
 393     prep_tracefile_rd
 394     # Get file specific stats - for each file, how many pids read that file ?
 395     echo "FILE VIEW:"
 396     process_files Reads
 397     # Get pid specific stats - for each pid, what files do they do IO on ?
 398     echo "PID VIEW:"
 399     process_pids Reads
 400     disk_stats_delta_rd $grand_total_KB
 401
 402     debug_FileKB_rd=`cat $infile | awk '{ bytes += $6 } END { printf "%d", bytes/1024 }' `
 403     echo Debug Grand Total KB READ $debug_FileKB_rd
 404 fi
 405
 406 if [ $trace_writes == true ]; then
 407     echo
 408     echo "Writes :"
 409     echo "_______"
 410     echo
 411     prep_tracefile_wr
 412     # Get file specific stats - for each file, how many pids read that file ?
 413     echo "FILE VIEW:"
 414     process_files Writes
 415     # Get pid specific stats - for each pid, what files do they do IO on ?
 416     echo "PID VIEW:"
 417     process_pids Writes
 418     disk_stats_delta_wr $grand_total_KB
 419
 420     debug_FileKB_wr=`cat $infile | awk '{ bytes += $6 } END { printf "%d", bytes/1024 }' `
 421     echo Debug Grand Total KB WRITTEN $debug_FileKB_wr
 422 fi
 423
 424 rm -rf tracefile* uniq_* subtrace trace_saved