LOCAL_MODULE_TAGS := debug
include $(BUILD_HOST_EXECUTABLE)
-
https://docs.google.com/a/google.com/document/d/1Bhq7iNPVc_JzwRrkmZqcPjMvWgpHX0r3Ncq-ZsRNOBA/edit?usp=sharing
The short summary of what IOshark is : IOshark has 2 components, one
-is a strace compiler that takes straces fed into it and compiles this
-into bytecodes (stored in *.wl files). The compiler runs on a Linux
-host. The second component (which runs on the device) is the tester
-that takes as input the bytecode files (*.wl files) and executes them
-on the device.
+is a strace+ftrace compiler that takes straces and select ftraces fed
+into it and compiles this into bytecodes (stored in *.wl files). The
+compiler runs on a Linux host. The second component (which runs on the
+device) is the tester that takes as input the bytecode files (*.wl
+files) and executes them on the device.
How to Run :
----------
-t <N> : Limit to N threads. By default (without this option), IOshark
will launch as many threads as there are input files, so 1 thread/file.
-v : verbose. Chatty mode.
+-s : One line summary.
+-q : Don't create the files in read-only partitions like /system and
+/vendor. Instead do reads on those files.
--- /dev/null
+#!/bin/sh
+
+# This function just re-writes the timestamp of the strace entries to be
+# seconds.usecs since boot. To match the timestamping of ftrace (so we can
+# merge them later).
+process_strace()
+{
+ strace=$1
+ # parse in data/system/vendor and parse out /sys/devices/system/...
+ egrep '\/system\/|\/data\/|\/vendor\/' $strace | egrep -v '\/sys\/devices\/system\/' > bar
+ fgrep -v '= -1' bar > foo
+ mv foo bar
+ # begin_time is seconds since epoch
+ begin_time=`cat trace.begin`
+ # replace seconds since epoch with SECONDS SINCE BOOT in the
+ # strace files
+ awk -v begin="$begin_time" '{ printf "%f strace ", $1 - begin; $1=""; print $0}' bar > $2
+ rm bar
+}
+
+#
+# This function processes the ftrace file, removing the fields that we don't care
+# about, breaks up the ftrace file into one file per pid.
+# Input : One single fstrace file.
+# Output : Multiple fstrace.pid files.
+prep_fstrace()
+{
+ # Remove leading junk
+ fgrep android_fs_data $1 | sed 's/^.* \[.*\] //' | sed s/://g | sed s/,//g > foo
+ # Sanitize the filenames, removing spaces within the filename etc
+ sed 's/android_fs_dataread_start/read/' foo > bar1
+ mv bar1 bar
+ # First column is timestamp SECONDS SINCE BOOT
+ awk '{ print $2, "ftrace", $3, $5, $7, $9, $13 }' bar > foo
+ #awk '{ s ="" ; for (i=2; i <= NF ; i++) s = s $i " "; print s}' bar > foo
+ rm bar
+ # Get all the uniq pids
+ awk '{print $7}' foo | sort | uniq > pidlist
+ for i in `cat pidlist`
+ do
+ awk -v pid=$i '{ if (pid == $7) print $0}' foo > fstrace.$i
+ done
+ rm pidlist
+ rm foo
+}
+
+# Merge straces and ftraces.
+# The goal here is to catch mmap'ed IO (reads) that won't be in the
+# strace file. The algorithm is to look for mmaps in the strace file,
+# use the files tha are mmap'ed to search in the ftraces to pick up
+# tracepoints from there, and merge those with the straces.
+# The output of this function is a set of parsed_input_trace.<pid>
+# files, that can then be compiled into .wl files
+merge_compile()
+{
+ for stracefile in trace.*
+ do
+ if [ $stracefile == trace.begin ] || [ $stracefile == trace.tar ];
+ then
+ continue
+ fi
+ # Get the pid from the strace filename (pid is the extension)
+ pid=${stracefile##*.}
+ process_strace $stracefile foo.$pid
+ if ! [ -s foo.$pid ]; then
+ rm foo.$pid
+ continue
+ fi
+ #
+ # If we have matching strace and ftrace files, then look for mmaps in
+ # the strace pluck the corresponding entries for the mmap (mmaped IO)
+ # from the ftrace and merge them into the strace
+ #
+ if [ -f fstrace.$pid ]; then
+ fgrep mmap foo.$pid > bar
+ if [ -s bar ]; then
+ # Get all the unique mmap'ed filenames from the strace
+ awk '{ print $7 }' bar | sed 's/^[^<]*<//g' | sed 's/>,//g' > mapped_files
+ # Pluck all the lines from the ftrace corresponding to the mmaps
+ cat /dev/null > footemp
+ for j in `sort mapped_files | uniq`
+ do
+ # Merge the readpage(s) traces from the ftrace into strace
+ # for this mmaped file.
+ grep -w $j fstrace.$pid > foobar
+ if [ $? == 0 ]; then
+ sort foo.$pid foobar >> footemp
+ fi
+ rm foobar
+ done
+ rm mapped_files
+ if [ -s footemp ]; then
+ mv footemp parsed_input_trace.$pid
+ else
+ mv foo.$pid parsed_input_trace.$pid
+ fi
+ else
+ mv foo.$pid parsed_input_trace.$pid
+ fi
+ rm bar
+ else
+ mv foo.$pid parsed_input_trace.$pid
+ fi
+ echo compiling parsed_input_trace.$pid
+ compile_ioshark parsed_input_trace.$pid $pid.wl
+ rm parsed_input_trace.$pid
+ rm -f foo.$pid
+ done
+}
+
+catch_sigint()
+{
+ echo "signal INT received, killing streaming trace capture"
+ ps_line=`ps -ef | grep trace_pipe | grep adb `
+ if [ $? == 0 ]; then
+ echo Killing `echo $ps_line | awk '{s = ""; for (i=8; i <= NF ; i++) s = s $i " "; print s}' `
+ kill `echo $ps_line | awk '{print $2}' `
+ fi
+ ps_line=`ps -ef | grep strace | grep adb `
+ if [ $? == 0 ]; then
+ echo Killing `echo $ps_line | awk '{s = ""; for (i=8; i <= NF ; i++) s = s $i " "; print s}' `
+ kill `echo $ps_line | awk '{print $2}' `
+ fi
+}
+
+enable_tracepoints()
+{
+ adb shell "echo 1 > /sys/kernel/debug/tracing/events/android_fs/android_fs_dataread_start/enable"
+ adb shell "echo 1 > /sys/kernel/debug/tracing/tracing_on"
+}
+
+disable_tracepoints()
+{
+ adb shell "echo 0 > /sys/kernel/debug/tracing/events/android_fs/android_fs_dataread_start/enable"
+ adb shell "echo 0 > /sys/kernel/debug/tracing/tracing_on"
+}
+
+kill_traces()
+{
+ ps_line=`ps -ef | grep trace_pipe | grep adb `
+ if [ $? == 0 ]; then
+ echo Killing `echo $ps_line | awk '{s = ""; for (i=8; i <= NF ; i++) s = s $i " "; print s}' `
+ kill `echo $ps_line | awk '{print $2}' `
+ fi
+ ps_line=`ps -ef | grep strace | grep adb `
+ if [ $? == 0 ]; then
+ echo Killing `echo $ps_line | awk '{s = ""; for (i=8; i <= NF ; i++) s = s $i " "; print s}' `
+ kill `echo $ps_line | awk '{print $2}' `
+ fi
+}
+
+catch_sigint()
+{
+ echo "signal INT received, killing streaming trace capture"
+ kill_traces
+}
+
+# main() starts here
+
+adb root && adb wait-for-device
+
+enable_tracepoints
+
+trap 'catch_sigint' INT
+
+adb shell 'ps' | grep zygote > zygote_pids
+fgrep -v grep zygote_pids > bar
+mv bar zygote_pids
+pid1=`grep -w zygote zygote_pids | awk '{print $2}' `
+pid2=`grep -w zygote64 zygote_pids | awk '{print $2}' `
+rm -f zygote_pids
+
+adb shell "date +%s > /data/local/tmp/trace.begin ; strace -p $pid1,$pid2 -o /data/local/tmp/trace -q -qq -f -ff -y -ttt -e trace=mmap2,read,write,pread64,pwrite64,fsync,fdatasync,openat,close,lseek,_llseek" &
+adb shell "cat /sys/kernel/debug/tracing/trace_pipe" > fstrace &
+
+echo "^C this when done with the test"
+
+wait
+
+adb shell 'monkey -p com.android.alarmclock -p com.android.chrome -p com.android.calculator -p com.android.calendar -p com.google.android.calendar -p com.google.android.camera -p com.android.contacts -p com.google.android.gm -p com.android.im -p com.android.launcher -p com.google.android.apps.maps -p com.android.mms -p com.google.android.music -p com.android.phone -p com.google.android.youtube -p com.android.email -p com.google.android.voicesearch -c android.intent.category.LAUNCHER --throttle 200 --ignore-security-exceptions --ignore-crashes --ignore-timeouts -v -v -v 25000'
+
+kill_traces
+
+disable_tracepoints
+
+rm -f trace.*
+rm -f fstrace.*
+rm -f *.wl
+rm -f parsed*
+
+# Get the tracefiles from the device
+adb shell 'cd /data/local/tmp ; tar cvf trace.tar trace.*'
+adb pull /data/local/tmp/trace.tar
+tar xf trace.tar
+
+# Pre-process the ftrace file
+prep_fstrace fstrace
+# Merge the ftrace file(s) with the strace files
+merge_compile
+
+# tar up the .wl files just created
+tar cf wl.tar ioshark_filenames *.wl
egrep -v '\/sys\/devices\/system\/' bar > bar0
mv bar0 bar
fgrep -v '= -1' bar > foo
- mv foo bar
+ rm bar
+ # begin_time is seconds since epoch
+ begin_time=`cat trace.begin`
+ # replace seconds since epoch with SECONDS SINCE BOOT in the
+ # strace files
+ awk -v begin="$begin_time" '{ printf "%f strace ", $1 - begin; $1=""; print $0}' foo > bar
if [ -s bar ]
then
echo parsing $i
- compile_ioshark bar $i.wl
+ pid=${i##*.}
+ compile_ioshark bar $pid.wl
rm -f bar
else
rm -f $i bar
adb root && adb wait-for-device
-#adb shell 'ps -ef' | grep zygote > zygote_pids
adb shell 'ps' | grep zygote > zygote_pids
fgrep -v grep zygote_pids > bar
compile_tracefiles
# tar up the .wl files just created
+rm -f wl.tar
tar cf wl.tar ioshark_filenames *.wl
--- /dev/null
+#!/bin/sh
+
+# This function just re-writes the timestamp of the strace entries to be
+# seconds.usecs since boot. To match the timestamping of ftrace (so we can
+# merge them later).
+process_strace()
+{
+ strace=$1
+ # parse in data/system/vendor and parse out /sys/devices/system/...
+ egrep '\/system\/|\/data\/|\/vendor\/' $strace | egrep -v '\/sys\/devices\/system\/' > bar
+ fgrep -v '= -1' bar > foo
+ mv foo bar
+ # begin_time is seconds since epoch
+ begin_time=`cat trace.begin`
+ # replace seconds since epoch with SECONDS SINCE BOOT in the
+ # strace files
+ awk -v begin="$begin_time" '{ printf "%f strace ", $1 - begin; $1=""; print $0}' bar > $2
+ rm bar
+}
+
+#
+# This function processes the ftrace file, removing the fields that we don't care
+# about, breaks up the ftrace file into one file per pid.
+# Input : One single fstrace file.
+# Output : Multiple fstrace.pid files.
+prep_fstrace()
+{
+ # Remove leading junk
+ fgrep android_fs_data $1 | sed 's/^.* \[.*\] //' | sed s/://g | sed s/,//g > foo
+ sed 's/android_fs_dataread_start/read/' foo > bar1
+ mv bar1 bar
+ # First column is timestamp SECONDS SINCE BOOT
+ awk '{ print $2, "ftrace", $3, $5, $7, $9, $13 }' bar > foo
+ rm bar
+ # Get all the uniq pids
+ awk '{print $7}' foo | sort | uniq > pidlist
+ for i in `cat pidlist`
+ do
+ awk -v pid=$i '{ if (pid == $7) print $0}' foo > fstrace.$i
+ done
+ rm pidlist
+ rm foo
+}
+
+# Merge straces and ftraces.
+# The goal here is to catch mmap'ed IO (reads) that won't be in the
+# strace file. The algorithm is to look for mmaps in the strace file,
+# use the files tha are mmap'ed to search in the ftraces to pick up
+# tracepoints from there, and merge those with the straces.
+# The output of this function is a set of parsed_input_trace.<pid>
+# files, that can then be compiled into .wl files
+merge_compile()
+{
+ for stracefile in trace.*
+ do
+ if [ $stracefile == trace.begin ] || [ $stracefile == trace.tar ];
+ then
+ continue
+ fi
+ # Get the pid from the strace filename (pid is the extension)
+ pid=${stracefile##*.}
+ process_strace $stracefile foo.$pid
+ if ! [ -s foo.$pid ]; then
+ rm foo.$pid
+ continue
+ fi
+ #
+ # If we have matching strace and ftrace files, then look for mmaps in
+ # the strace pluck the corresponding entries for the mmap (mmaped IO)
+ # from the ftrace and merge them into the strace
+ #
+ if [ -f fstrace.$pid ]; then
+ fgrep mmap foo.$pid > bar
+ if [ -s bar ]; then
+ # Get all the unique mmap'ed filenames from the strace
+ awk '{ print $7 }' bar | sed 's/^[^<]*<//g' | sed 's/>,//g' > mapped_files
+ # Pluck all the lines from the ftrace corresponding to the mmaps
+ cat /dev/null > footemp
+ for j in `sort mapped_files | uniq`
+ do
+ # Merge the readpage(s) traces from the ftrace into strace
+ # for this mmaped file.
+ grep -w $j fstrace.$pid > foobar
+ if [ $? == 0 ]; then
+ sort foo.$pid foobar >> footemp
+ fi
+ rm foobar
+ done
+ rm mapped_files
+ if [ -s footemp ]; then
+ mv footemp parsed_input_trace.$pid
+ else
+ mv foo.$pid parsed_input_trace.$pid
+ fi
+ else
+ mv foo.$pid parsed_input_trace.$pid
+ fi
+ rm bar
+ else
+ mv foo.$pid parsed_input_trace.$pid
+ fi
+ echo compiling parsed_input_trace.$pid
+ compile_ioshark parsed_input_trace.$pid $pid.wl
+ rm parsed_input_trace.$pid
+ rm -f foo.$pid
+ done
+}
+
+# main() starts here
+
+rm -f *.wl
+rm -f parsed*
+rm ioshark_filenames
+
+# Pre-process the ftrace file
+prep_fstrace fstrace
+# Merge the ftrace file(s) with the strace files
+merge_compile
+
+# tar up the .wl files just created
+tar cf wl-test.tar ioshark_filenames *.wl
{ "openat", IOSHARK_OPEN },
{ "fsync", IOSHARK_FSYNC },
{ "fdatasync", IOSHARK_FDATASYNC },
- { "close", IOSHARK_CLOSE }
+ { "close", IOSHARK_CLOSE },
+ { "ftrace", IOSHARK_MAPPED_PREAD }
};
struct in_mem_file_op {
fprintf(stderr, "%s in_file out_file\n", progname);
}
-u_int64_t
-get_delta_ts(char *buf, struct timeval *start_tv)
+void
+init_prev_time(struct timeval *tv)
+{
+ tv->tv_sec = tv->tv_usec = 0;
+}
+
+/*
+ * delta ts is the time delta from the previous IO in this tracefile.
+ */
+static u_int64_t
+get_delta_ts(char *buf, struct timeval *prev)
{
struct timeval op_tv, tv_res;
sscanf(buf, "%lu.%lu", &op_tv.tv_sec, &op_tv.tv_usec);
- timersub(&op_tv, start_tv, &tv_res);
+ /* First item */
+ if (prev->tv_sec == 0 && prev->tv_usec == 0)
+ tv_res.tv_sec = tv_res.tv_usec = 0;
+ else
+ timersub(&op_tv, prev, &tv_res);
+ *prev = op_tv;
return (tv_res.tv_usec + (tv_res.tv_sec * 1000000));
}
void
-get_pathname(char *buf, char *pathname, enum file_op file_op)
+get_tracetype(char *buf, char *trace_type)
{
- char *s, *s2, save;
+ char *s, *s2;
- if (file_op == IOSHARK_OPEN)
- s = strchr(buf, '"');
- else
- s = strchr(buf, '<');
+ *trace_type = '\0';
+ s = strchr(buf, ' ');
if (s == NULL) {
- fprintf(stderr, "%s: Malformed line: %s\n",
- __func__, buf);
+ fprintf(stderr,
+ "%s Malformed Trace Type ? %s\n",
+ progname, __func__);
exit(EXIT_FAILURE);
}
- s += 1;
- if (file_op == IOSHARK_OPEN)
- s2 = strchr(s, '"');
- else
- s2 = strchr(s, '>');
+ while (*s == ' ')
+ s++;
+ if (sscanf(s, "%s", trace_type) != 1) {
+ fprintf(stderr,
+ "%s Malformed Trace Type ? %s\n",
+ progname, __func__);
+ exit(EXIT_FAILURE);
+ }
+ if (strcmp(trace_type, "strace") != 0 &&
+ strcmp(trace_type, "ftrace") != 0) {
+ fprintf(stderr,
+ "%s Unknown/Missing Trace Type (has to be strace|ftrace) %s\n",
+ progname, __func__);
+ exit(EXIT_FAILURE);
+ }
+ /*
+ * Remove the keyword "strace"/"ftrace" from the buffer
+ */
+ s2 = strchr(s, ' ');
if (s2 == NULL) {
- fprintf(stderr, "%s: Malformed line: %s\n",
- __func__, buf);
+ fprintf(stderr,
+ "%s Malformed Trace Type ? %s\n",
+ progname, __func__);
+ exit(EXIT_FAILURE);
+ }
+ while (*s2 == ' ')
+ s2++;
+ if (*s2 == '\0') {
+ /*
+ * Premature end of input record
+ */
+ fprintf(stderr,
+ "%s Mal-formed strace/ftrace record %s:%s\n",
+ progname, __func__, buf);
exit(EXIT_FAILURE);
}
+ /* strcpy() expects non-overlapping buffers, but bcopy doesn't */
+ bcopy(s2, s, strlen(s2) + 1);
+}
+
+void
+get_pathname(char *buf, char *pathname, enum file_op file_op)
+{
+ char *s, *s2, save;
+
+ if (file_op == IOSHARK_MAPPED_PREAD) {
+ s = strchr(buf, '/');
+ if (s == NULL) {
+ fprintf(stderr, "%s: Malformed line: %s\n",
+ __func__, buf);
+ exit(EXIT_FAILURE);
+ }
+ s2 = strchr(s, ' ');
+ if (s2 == NULL) {
+ fprintf(stderr, "%s: Malformed line: %s\n",
+ __func__, buf);
+ exit(EXIT_FAILURE);
+ }
+ } else {
+ if (file_op == IOSHARK_OPEN)
+ s = strchr(buf, '"');
+ else
+ s = strchr(buf, '<');
+ if (s == NULL) {
+ fprintf(stderr, "%s: Malformed line: %s\n",
+ __func__, buf);
+ exit(EXIT_FAILURE);
+ }
+ s += 1;
+ if (file_op == IOSHARK_OPEN)
+ s2 = strchr(s, '"');
+ else
+ s2 = strchr(s, '>');
+ if (s2 == NULL) {
+ fprintf(stderr, "%s: Malformed line: %s\n",
+ __func__, buf);
+ exit(EXIT_FAILURE);
+ }
+ }
save = *s2;
*s2 = '\0';
strcpy(pathname, s);
sscanf(s_offset + 2, "%ju", offset);
}
+
+void
+get_ftrace_offset_len(char *buf,
+ off_t *offset,
+ u_int64_t *len)
+{
+ char *s_offset;
+
+ s_offset = strchr(buf, '/');
+ if (s_offset == NULL) {
+ fprintf(stderr, "%s: Malformed line 1: %s\n",
+ __func__, buf);
+ exit(EXIT_FAILURE);
+ }
+ s_offset = strchr(s_offset, ' ');
+ if (s_offset == NULL) {
+ fprintf(stderr, "%s: Malformed line 2: %s\n",
+ __func__, buf);
+ exit(EXIT_FAILURE);
+ }
+ while (*s_offset == ' ')
+ s_offset++;
+ if (sscanf(s_offset, "%ju %ju", offset, len) != 2) {
+ fprintf(stderr, "%s: Malformed line 3: %s\n",
+ __func__, buf);
+ exit(EXIT_FAILURE);
+ }
+}
+
void
get_openat_flags_mode(char *buf, char *flags, mode_t *mode)
{
ARRAY_SIZE(fileop_map));
}
-void
-get_start_time(struct timeval *tv)
-{
- FILE *fp;
-
- tv->tv_usec = 0;
- fp = fopen("trace.begin", "r");
- if (fp == NULL) {
- fprintf(stderr, "%s Can't open trace.begin\n",
- __func__);
- exit(EXIT_FAILURE);
- }
- if (fscanf(fp, "%lu", &tv->tv_sec) != 1) {
- fprintf(stderr, "%s Can't read seconds from trace.begin\n",
- __func__);
- exit(EXIT_FAILURE);
- }
-}
-
/*
* For each tracefile, we first create in-memory structures, then once
* we've processed each tracefile completely, we write out the in-memory
struct in_mem_file_op *in_mem_fop;
struct stat st;
char *infile, *outfile;
- struct timeval start_time;
+ struct timeval prev_time;
+ char trace_type[64];
progname = argv[0];
if (argc != 3) {
progname, infile);
exit(EXIT_FAILURE);
}
+ init_prev_time(&prev_time);
init_filename_cache();
- get_start_time(&start_time);
fp = fopen(infile, "r");
if (fp == NULL) {
fprintf(stderr, "%s Can't open %s\n",
s++;
in_mem_fop = malloc(sizeof(struct in_mem_file_op));
disk_file_op = &in_mem_fop->disk_file_op;
- disk_file_op->delta_us = get_delta_ts(s, &start_time);
- get_syscall(s, syscall);
- disk_file_op->file_op = map_syscall(syscall);
+ disk_file_op->delta_us = get_delta_ts(s, &prev_time);
+ get_tracetype(s, trace_type);
+ if (strcmp(trace_type, "strace") == 0) {
+ get_syscall(s, syscall);
+ disk_file_op->file_op = map_syscall(syscall);
+ } else
+ disk_file_op->file_op = map_syscall("ftrace");
get_pathname(s, path, disk_file_op->file_op);
db_node = files_db_add(path);
disk_file_op->fileno = files_db_get_fileno(db_node);
break;
case IOSHARK_CLOSE:
break;
+ case IOSHARK_MAPPED_PREAD:
+ /* Convert a mmap'ed read into a PREAD64 */
+ disk_file_op->file_op = IOSHARK_PREAD64;
+ get_ftrace_offset_len(s,
+ &disk_file_op->prw_offset,
+ (u_int64_t *)&disk_file_op->prw_len);
+ files_db_update_size(db_node,
+ disk_file_op->prw_offset +
+ disk_file_op->prw_len);
+ break;
default:
break;
}
char *progname;
-#define MAX_INPUT_FILES 1024
-#define MAX_THREADS 1024
+#define MAX_INPUT_FILES 8192
+#define MAX_THREADS 8192
struct thread_state_s {
char *filename;
*/
filename =
get_ro_filename(file_state.global_filename_ix);
- assert(filename != NULL);
+ if (quick_mode)
+ assert(filename != NULL);
if (quick_mode == 0 ||
is_readonly_mount(filename, file_state.size) == 0) {
sprintf(path, "file.%d.%d",
void *db_node;
struct ioshark_header header;
struct ioshark_file_operation file_op;
- u_int64_t prev_delay = 0;
int fd;
int i;
char *buf = NULL;
struct timeval start;
(void)gettimeofday(&start, (struct timezone *)NULL);
- usleep(file_op.delta_us - prev_delay);
+ usleep(file_op.delta_us);
update_delta_time(&start, &total_delay_time);
- prev_delay = file_op.delta_us;
}
db_node = files_db_lookup_byfileno(state->db_handle,
file_op.fileno);
verbose = 1;
break;
default:
- usage();
+ usage();
}
}
}
wait_for_threads(num_threads);
update_delta_time(&time_for_pass, &aggregate_file_create_time);
-
/* Do the IOs N times */
for (i = 0 ; i < num_iterations ; i++) {
(void)system("echo 3 > /proc/sys/vm/drop_caches");
OSDN Git Service
