File syscall_times.pl of Package mmdebug-tools

#!/usr/bin/perl

# Script for parsing syscall trace obtained by enabling
# /sys/kernel/debug/tracing/events/syscalls/sys_{enter,exit}_*
# tracepoints to get time spent in each syscall. The script prints output
# of the form:
# TIMESTAMP     PID   CMD SYSCALL  DURATION
# 113675.072998 10546 cat sys_read 0.000003

my %pnames, %pcalls, %ptimes;

$syscall = "";
while (<STDIN>) {
	chop;
	@fields = split(/  */);
	$fields[1] =~ /^(.*)-([0-9]*$)/;
	$name = $1;
	$pid = $2;
	$time = $fields[4];
	$time =~ s/://;
	$syscall = $fields[5];
#	Syscall begin?
	if ($syscall =~ /sys_[a-z0-9]*\(/) {
		$syscall =~ s/\(.*//;
		if (!exists($pnames{$pid}) || ($name ne '<...>')) {
			$pnames{$pid} = $name;
		}
		$pcalls{$pid} = $syscall;
		$ptimes{$pid} = $time;
#		print "Adding $pid $name $syscall\n";
	} else {
#		Syscall end
		if (exists($pcalls{$pid})) {
			$startsys = $pcalls{$pid};
#			print "Matching $pid $syscall\n";
			if ($startsys eq $syscall) {
				printf("$ptimes{$pid} $pid $pnames{$pid} $syscall %.6f\n", $time-$ptimes{$pid});
			}
			delete $pcalls{$pid};
			delete $ptime{$pid};
		}
	}
}