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