IOshark support to parse Linux filesystem ftraces.

IOshark support to input filesystem ftracepooints (readpage(s))
to capture and replay mmap'ed IO (which aren't captured by strace).
The new script collect-straces-ftraces.sh enables the necessary
tracepoints, and collects ftraces and straces compiles these into
intermediate bytecodes which ioshark_bench can then execute.

Test: Generate several monkey based workloads, and use the script
mentioned above to generate bytecodes and feed those into
ioshark_bench.

Change-Id: Iae57f5fdcdce0fedfd85c8d64ee006cc8b5b470d
Signed-off-by: Mohan Srinivasan <srmohan@google.com>

12 files changed, 497 insertions, 60 deletions

diff --git a/ioshark/Android.mk b/ioshark/Android.mk
index f760d7b6..a647d755 100644
--- a/ioshark/Android.mk
+++ b/ioshark/Android.mk
@@ -42,4 +42,3 @@ LOCAL_MODULE := dump_ioshark_filenames
 LOCAL_MODULE_TAGS := debug
 include $(BUILD_HOST_EXECUTABLE)
 
-
diff --git a/ioshark/README b/ioshark/README
index ee2f426b..0c50fec3 100644
--- a/ioshark/README
+++ b/ioshark/README
@@ -3,11 +3,11 @@ can find more documentation on IOshark at :
 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 :
 ----------
@@ -25,3 +25,6 @@ seen in the original straces.
 -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.
diff --git a/ioshark/collect-straces-ftraces.sh b/ioshark/collect-straces-ftraces.sh
new file mode 100644
index 00000000..6e83a248
--- /dev/null
+++ b/ioshark/collect-straces-ftraces.sh
@@ -0,0 +1,202 @@
+#!/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
diff --git a/ioshark/collect-straces.sh b/ioshark/collect-straces.sh
index d8a73055..21a39393 100755
--- a/ioshark/collect-straces.sh
+++ b/ioshark/collect-straces.sh
@@ -41,11 +41,17 @@ compile_tracefiles()
 	    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
@@ -58,7 +64,6 @@ compile_tracefiles()
 
 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
@@ -88,4 +93,5 @@ tar xf trace.tar
 compile_tracefiles
 
 # tar up the .wl files just created
+rm -f wl.tar
 tar cf wl.tar ioshark_filenames *.wl
diff --git a/ioshark/compile-only.sh b/ioshark/compile-only.sh
new file mode 100644
index 00000000..634b4741
--- /dev/null
+++ b/ioshark/compile-only.sh
@@ -0,0 +1,121 @@
+#!/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
diff --git a/ioshark/compile_ioshark.c b/ioshark/compile_ioshark.c
index 97c77c90..f35d595a 100644
--- a/ioshark/compile_ioshark.c
+++ b/ioshark/compile_ioshark.c
@@ -79,7 +79,8 @@ struct flags_map_s fileop_map[] = {
 	{ "openat", IOSHARK_OPEN },
 	{ "fsync", IOSHARK_FSYNC },
 	{ "fdatasync", IOSHARK_FDATASYNC },
-	{ "close", IOSHARK_CLOSE }
+	{ "close", IOSHARK_CLOSE },
+	{ "ftrace", IOSHARK_MAPPED_PREAD }
 };
 
 struct in_mem_file_op {
@@ -94,40 +95,122 @@ void usage(void)
 	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);
@@ -287,6 +370,35 @@ get_prw64_offset_len(char *buf,
 	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)
 {
@@ -401,25 +513,6 @@ map_syscall(char *syscall)
 			  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
@@ -440,7 +533,8 @@ int main(int argc, char **argv)
 	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) {
@@ -459,8 +553,8 @@ int main(int argc, char **argv)
 			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",
@@ -473,9 +567,13 @@ int main(int argc, char **argv)
 			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);
@@ -529,6 +627,16 @@ int main(int argc, char **argv)
 			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;
 		}
diff --git a/ioshark/ioshark_bench.c b/ioshark/ioshark_bench.c
index 95ba854d..f44e73e4 100644
--- a/ioshark/ioshark_bench.c
+++ b/ioshark/ioshark_bench.c
@@ -45,8 +45,8 @@
 
 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;
@@ -185,7 +185,8 @@ create_files(struct thread_state_s *state)
 		 */
 		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",
@@ -395,7 +396,6 @@ do_io(struct thread_state_s *state)
 	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;
@@ -434,9 +434,8 @@ do_io(struct thread_state_s *state)
 			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);
@@ -689,7 +688,7 @@ main(int argc, char **argv)
 			verbose = 1;
 			break;
  	        default:
-                        usage();
+			usage();
 		}
 	}
 
@@ -778,7 +777,6 @@ main(int argc, char **argv)
 		}
 		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");
diff --git a/ioshark/monkey-strace+fstrace.tgz b/ioshark/monkey-strace+fstrace.tgz
new file mode 100644
index 00000000..6f023010
--- /dev/null
+++ b/ioshark/monkey-strace+fstrace.tgz
diff --git a/ioshark/monkeystracebig.tgz b/ioshark/monkeystracebig.tgz
new file mode 100644
index 00000000..e2ab7bc7
--- /dev/null
+++ b/ioshark/monkeystracebig.tgz
diff --git a/ioshark/monkeytrace1.tar.gz b/ioshark/monkeytrace1.tar.gz
deleted file mode 100644
index ae313dd8..00000000
--- a/ioshark/monkeytrace1.tar.gz
+++ /dev/null
diff --git a/ioshark/monkeytrace2.tar.gz b/ioshark/monkeytrace2.tar.gz
deleted file mode 100644
index e5b8268c..00000000
--- a/ioshark/monkeytrace2.tar.gz
+++ /dev/null
diff --git a/ioshark/wl.tar b/ioshark/wl.tar
index c945faea..a004ad12 100644
--- a/ioshark/wl.tar
+++ b/ioshark/wl.tar