Time spent in system time is not useful where a syscall depends on some non-CPU resource, eg. typically open() or stat() to a network drive.
This patch adds a new flag (-w) to produce a summary of the time difference between beginning and end of the system call (ie. latency) This functionality has been useful to profile slow processes that are not CPU-bound. Signed-off-by: Mark Hills <[email protected]> --- NEWS | 3 +++ count.c | 4 ++-- defs.h | 1 + strace.1 | 4 ++++ strace.c | 11 ++++++++++- 5 files changed, 20 insertions(+), 3 deletions(-) diff --git a/NEWS b/NEWS index eed78c2..895649c 100644 --- a/NEWS +++ b/NEWS @@ -1,6 +1,9 @@ Noteworthy changes in release ?.? (????-??-??) ============================================== +* Improvements + * Added -w option to produce stats on syscall latency + Noteworthy changes in release 4.8 (2013-06-03) ============================================== diff --git a/count.c b/count.c index 8395466..cbb92a4 100644 --- a/count.c +++ b/count.c @@ -37,7 +37,7 @@ /* Per-syscall stats structure */ struct call_counts { - /* system time spent in syscall (not wall clock time) */ + /* time may be total latency or system time */ struct timeval time; int calls, errors; }; @@ -72,7 +72,7 @@ count_syscall(struct tcb *tcp, struct timeval *tv) tv_sub(tv, tv, &tcp->etime); /* Spent more wall clock time than spent system time? (usually yes) */ - if (tv_cmp(tv, &tcp->dtime) > 0) { + if (!count_wallclock && tv_cmp(tv, &tcp->dtime) > 0) { static struct timeval one_tick = { -1, 0 }; if (one_tick.tv_sec == -1) { diff --git a/defs.h b/defs.h index 4e06a92..a6ea5a0 100644 --- a/defs.h +++ b/defs.h @@ -548,6 +548,7 @@ extern cflag_t cflag; extern bool debug_flag; extern bool Tflag; extern bool iflag; +extern bool count_wallclock; extern unsigned int qflag; extern bool not_failing_only; extern bool show_fd_path; diff --git a/strace.1 b/strace.1 index 6ca4bda..4d26be5 100644 --- a/strace.1 +++ b/strace.1 @@ -290,6 +290,10 @@ of seconds since the epoch. Show the time spent in system calls. This records the time difference between the beginning and the end of each system call. .TP +.B \-w +Summarise the time difference between the beginning and end of +each system call. The default is to summarise the system time. +.TP .B \-v Print unabbreviated versions of environment, stat, termios, etc. calls. These structures are very common in calls and so the default diff --git a/strace.c b/strace.c index 8a49340..35ee7be 100644 --- a/strace.c +++ b/strace.c @@ -78,6 +78,7 @@ bool need_fork_exec_workarounds = 0; bool debug_flag = 0; bool Tflag = 0; bool iflag = 0; +bool count_wallclock = 0; unsigned int qflag = 0; /* Which WSTOPSIG(status) value marks syscall traps? */ static unsigned int syscall_trap_sig = SIGTRAP; @@ -200,6 +201,7 @@ usage: strace [-CdffhiqrtttTvVxxy] [-I n] [-e expr]...\n\ -p pid... / [-D] [-E var=val]... [-u username] PROG [ARGS]\n\ -c -- count time, calls, and errors for each syscall and report summary\n\ -C -- like -c but also print regular output\n\ +-w -- summarise syscall latency (default is system time)\n\ -d -- enable debug output to stderr\n\ -D -- run tracer process as a detached grandchild, not as parent\n\ -f -- follow forks, -ff -- with output into separate files\n\ @@ -1650,7 +1652,7 @@ init(int argc, char *argv[]) #endif qualify("signal=all"); while ((c = getopt(argc, argv, - "+b:cCdfFhiqrtTvVxyz" + "+b:cCdfFhiqrtTvVwxyz" "D" "a:e:o:O:p:s:S:u:E:P:I:")) != EOF) { switch (c) { @@ -1702,6 +1704,9 @@ init(int argc, char *argv[]) case 'T': Tflag = 1; break; + case 'w': + count_wallclock = 1; + break; case 'x': xflag++; break; @@ -1791,6 +1796,10 @@ init(int argc, char *argv[]) error_msg_and_die("(-c or -C) and -ff are mutually exclusive"); } + if (count_wallclock && !cflag) { + error_msg_and_die("-w must be given with (-c or -C)"); + } + /* See if they want to run as another user. */ if (username != NULL) { struct passwd *pent; -- 1.7.1 ------------------------------------------------------------------------------ Time is money. Stop wasting it! Get your web API in 5 minutes. www.restlet.com/download http://p.sf.net/sfu/restlet _______________________________________________ Strace-devel mailing list [email protected] https://lists.sourceforge.net/lists/listinfo/strace-devel
