Summary while strace runs
strace
has the -c
switch which will give you a summary report of the various system calls that were made.
excerpt strace man page
-c Count time, calls, and errors for each system call and report a
summary on program exit. On Linux, this attempts to show system
time (CPU time spent running in the kernel) independent of wall
clock time. If -c is used with -f or -F (below), only aggregate
totals for all traced processes are kept.
Example
$ strace -c systemctl list-unit-files --type=service
...
...
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
51.81 0.001831 1831 1 waitid
8.15 0.000288 7 39 mmap
7.89 0.000279 19 15 read
6.11 0.000216 8 26 mprotect
4.56 0.000161 11 15 open
2.91 0.000103 103 1 connect
2.24 0.000079 79 1 clone
2.15 0.000076 38 2 statfs
2.01 0.000071 4 19 close
1.95 0.000069 5 13 poll
1.90 0.000067 5 14 2 recvmsg
1.70 0.000060 4 16 fstat
0.88 0.000031 8 4 3 stat
0.82 0.000029 29 1 socket
0.65 0.000023 8 3 munmap
0.57 0.000020 5 4 sendto
0.42 0.000015 5 3 ioctl
0.40 0.000014 7 2 lstat
0.40 0.000014 7 2 sendmsg
0.34 0.000012 4 3 brk
0.23 0.000008 8 1 pipe
0.23 0.000008 4 2 fcntl
0.20 0.000007 4 2 rt_sigaction
0.20 0.000007 7 1 1 access
0.20 0.000007 4 2 geteuid
0.17 0.000006 6 1 execve
0.14 0.000005 5 1 getsockname
0.11 0.000004 4 1 dup2
0.11 0.000004 4 1 getresuid
0.11 0.000004 4 1 getresgid
0.11 0.000004 4 1 arch_prctl
0.08 0.000003 3 1 rt_sigprocmask
0.08 0.000003 3 1 getrlimit
0.08 0.000003 3 1 set_tid_address
0.08 0.000003 3 1 set_robust_list
0.00 0.000000 0 4 write
0.00 0.000000 0 1 kill
------ ----------- ----------- --------- --------- ----------------
100.00 0.003534 207 6 total
Analyzing strace logs postmortem
I found this Perl scripts called Strace_analyzer.pl
which sounds like what you're looking for.
Usage
$ ./strace_analyzer_ng_0.03.pl -help
Usage: strace-analyze [OPTION]… [FILE]
Analyzes strace output for IO functions. It creates statistics
on IO functions and performance of the read and write functions.
The strace file should have been run with ‘strace -tt [PROGRAM]
There's an example of the output on the page I linked to above. It's too long to post here. I've posted here on pastebin.com as well.
Alternative to strace, ioapps
I came across this app called ioapps
which can give you a more visual breakdown of what your app is doing when it's running. Perhaps this might be better for what you're trying to accomplish than processing strace
logs.
Usage
$ ioprofiler-trace thunderbird
Once it loads, we just close the thunderbird window and check we have
a trace log called "ioproftrace.log" because that's the default name
of the log (one can specify another name using -o command line
option):
$ ls -l ioproftrace.log
-rw-r--r-- 1 user user 74890554 Apr 4 22:04 ioproftrace.log
It seems OK, so we can run ioprofiler over it:
$ ioprofiler ioproftrace.log
Example GUI
Another alternative to strace, strace+
NOTE: The project, strace+, is no longer being maintained, and in fact many of its features have been merged into the default strace
via the -k
switch. So you might want to make sure your version of strace
is at least up to 4.9, which is when that switch was merged in.
excerpt strace man page
-k Print the execution stack trace of the traced processes after
each system call (experimental).
excerpt from strace+ project page
strace+ is an improved version of strace that collects stack traces
associated with each system call. Since system calls require an
expensive user-kernel context switch, they are often sources of
performance bottlenecks. strace+ allows programmers to do more
detailed system call profiling and determine, say, which call sites
led to costly syscalls and thus have potential for optimization.
strace
the-y
flag, it will automatically label all FDs with what they're pointing to. Still doesn't help for PIDs and the like, but helpful none the less!