* THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
* (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF
* THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
- *
- * $Id$
*/
#include "defs.h"
+/* Per-syscall stats structure */
struct call_counts {
+ /* system time spent in syscall (not wall clock time) */
struct timeval time;
int calls, errors;
};
static struct timeval shortest = { 1000000, 0 };
+/* On entry, tv is syscall exit timestamp */
void
count_syscall(struct tcb *tcp, struct timeval *tv)
{
- if (tcp->scno < 0 || tcp->scno >= nsyscalls)
+ struct call_counts *cc;
+ unsigned long scno = tcp->scno;
+
+ if (!SCNO_IN_RANGE(scno))
return;
if (!counts) {
counts = calloc(nsyscalls, sizeof(*counts));
- if (!counts) {
- fprintf(stderr,
- "strace: out of memory for call counts\n");
- exit(1);
- }
+ if (!counts)
+ die_out_of_memory();
}
+ cc = &counts[scno];
- counts[tcp->scno].calls++;
+ cc->calls++;
if (tcp->u_error)
- counts[tcp->scno].errors++;
+ cc->errors++;
+ /* tv = wall clock time spent while in syscall */
tv_sub(tv, tv, &tcp->etime);
-#ifdef LINUX
+
+ /* Spent more wall clock time than spent system time? (usually yes) */
if (tv_cmp(tv, &tcp->dtime) > 0) {
- static struct timeval one_tick;
+ static struct timeval one_tick = { -1, 0 };
- if (one_tick.tv_usec == 0) {
+ if (one_tick.tv_sec == -1) {
/* Initialize it. */
struct itimerval it;
setitimer(ITIMER_REAL, &it, NULL);
getitimer(ITIMER_REAL, &it);
one_tick = it.it_interval;
+//FIXME: this hack doesn't work (tested on linux-3.6.11): one_tick = 0.000000
+//tprintf(" one_tick.tv_usec:%u\n", (unsigned)one_tick.tv_usec);
}
if (tv_nz(&tcp->dtime))
+ /* tv = system time spent, if it isn't 0 */
*tv = tcp->dtime;
else if (tv_cmp(tv, &one_tick) > 0) {
+ /* tv = smallest "sane" time interval */
if (tv_cmp(&shortest, &one_tick) < 0)
*tv = shortest;
else
*tv = one_tick;
}
}
-#endif /* LINUX */
if (tv_cmp(tv, &shortest) < 0)
shortest = *tv;
- tv_add(&counts[tcp->scno].time, &counts[tcp->scno].time, tv);
+ tv_add(&cc->time, &cc->time, tv);
}
static int
else if (strcmp(sortby, "nothing") == 0)
sortfun = NULL;
else {
- fprintf(stderr, "invalid sortby: `%s'\n", sortby);
- exit(1);
+ error_msg_and_die("invalid sortby: '%s'", sortby);
}
}
static void
call_summary_pers(FILE *outf)
{
- int i, j;
+ int i;
int call_cum, error_cum;
struct timeval tv_cum, dtv;
+ double float_tv_cum;
double percent;
- const char *dashes = "-------------------------";
- char error_str[16];
- int *sorted_count = calloc(sizeof(int), nsyscalls);
+ const char *dashes = "----------------";
+ char error_str[sizeof(int)*3];
+ int *sorted_count;
- if (!sorted_count) {
- fprintf(stderr, "strace: out of memory for call summary\n");
- return;
- }
+ fprintf(outf, "%6.6s %11.11s %11.11s %9.9s %9.9s %s\n",
+ "% time", "seconds", "usecs/call",
+ "calls", "errors", "syscall");
+ fprintf(outf, "%6.6s %11.11s %11.11s %9.9s %9.9s %s\n",
+ dashes, dashes, dashes, dashes, dashes, dashes);
+ sorted_count = calloc(sizeof(int), nsyscalls);
+ if (!sorted_count)
+ die_out_of_memory();
call_cum = error_cum = tv_cum.tv_sec = tv_cum.tv_usec = 0;
if (overhead.tv_sec == -1) {
tv_mul(&overhead, &shortest, 8);
error_cum += counts[i].errors;
tv_add(&tv_cum, &tv_cum, &counts[i].time);
}
- if (counts && sortfun)
- qsort((void *) sorted_count, nsyscalls, sizeof(int), sortfun);
- fprintf(outf, "%6.6s %11.11s %11.11s %9.9s %9.9s %s\n",
- "% time", "seconds", "usecs/call",
- "calls", "errors", "syscall");
- fprintf(outf, "%6.6s %11.11s %11.11s %9.9s %9.9s %-16.16s\n",
- dashes, dashes, dashes, dashes, dashes, dashes);
+ float_tv_cum = tv_float(&tv_cum);
if (counts) {
+ if (sortfun)
+ qsort((void *) sorted_count, nsyscalls, sizeof(int), sortfun);
for (i = 0; i < nsyscalls; i++) {
- j = sorted_count[i];
- if (counts[j].calls == 0)
+ double float_syscall_time;
+ int idx = sorted_count[i];
+ struct call_counts *cc = &counts[idx];
+ if (cc->calls == 0)
continue;
- tv_div(&dtv, &counts[j].time, counts[j].calls);
- if (counts[j].errors)
- sprintf(error_str, "%d", counts[j].errors);
- else
- error_str[0] = '\0';
- percent = (100.0 * tv_float(&counts[j].time)
- / tv_float(&tv_cum));
- fprintf(outf, "%6.2f %11.6f %11ld %9d %9.9s %s\n",
- percent, tv_float(&counts[j].time),
- (long) 1000000 * dtv.tv_sec + dtv.tv_usec,
- counts[j].calls,
- error_str, sysent[j].sys_name);
+ tv_div(&dtv, &cc->time, cc->calls);
+ error_str[0] = '\0';
+ if (cc->errors)
+ sprintf(error_str, "%u", cc->errors);
+ float_syscall_time = tv_float(&cc->time);
+ percent = (100.0 * float_syscall_time);
+ if (percent != 0.0)
+ percent /= float_tv_cum;
+ /* else: float_tv_cum can be 0.0 too and we get 0/0 = NAN */
+ fprintf(outf, "%6.2f %11.6f %11lu %9u %9.9s %s\n",
+ percent, float_syscall_time,
+ (long) (1000000 * dtv.tv_sec + dtv.tv_usec),
+ cc->calls,
+ error_str, sysent[idx].sys_name);
}
}
free(sorted_count);
- fprintf(outf, "%6.6s %11.11s %11.11s %9.9s %9.9s %-16.16s\n",
+ fprintf(outf, "%6.6s %11.11s %11.11s %9.9s %9.9s %s\n",
dashes, dashes, dashes, dashes, dashes, dashes);
+ error_str[0] = '\0';
if (error_cum)
- sprintf(error_str, "%d", error_cum);
- else
- error_str[0] = '\0';
- fprintf(outf, "%6.6s %11.6f %11.11s %9d %9.9s %s\n",
- "100.00", tv_float(&tv_cum), "",
+ sprintf(error_str, "%u", error_cum);
+ fprintf(outf, "%6.6s %11.6f %11.11s %9u %9.9s %s\n",
+ "100.00", float_tv_cum, "",
call_cum, error_str, "total");
}
set_personality(i);
if (i)
fprintf(outf,
- "System call usage summary for %u bit mode:\n",
- personality_wordsize[current_personality] * 8);
+ "System call usage summary for %d bit mode:\n",
+ current_wordsize * 8);
call_summary_pers(outf);
}