Re: Another Newbie question about measuring time in a sys call

[Martin Hunt <hunt@redhat.com>]

Another way that works now is to not use the syscall tapset.

probe kernel.function("sys_*") {
   if (target() != tid()) next
   calltime[tid()] = gettimeofday_us()
}

probe kernel.function("sys_*").return {
   if (target() != tid()) next
   c=calltime[tid()]
   if (!c) next
   delete calltime[tid()]
   ttime[probefunc()] <<< gettimeofday_us() - c
}

probe end {
   printf("\n")
   foreach (x in ttime)
     printf("%s count %d avg %d\n", x,
       @count(ttime[x]), @avg(ttime[x]))
}

global calltime, ttime

----------

Note I change the filter to compare target() to tid(). This allows you
to profile any command with the above code just by using the "-c" option
to stap.

> stap -c ps system_calls.stp
  PID TTY          TIME CMD
19129 pts/6    00:00:00 stpd
19135 pts/6    00:00:00 ps

sys_munmap count 7 avg 14
sys_mprotect count 6 avg 9
sys_mmap2 count 25 avg 8
sys_readlink count 2 avg 20
sys_rt_sigaction count 34 avg 5
sys_read count 231 avg 20
sys_rt_sigprocmask count 7 avg 6
sys_write count 3 avg 17
sys_brk count 6 avg 5
sys_open count 234 avg 12
sys_getdents64 count 2 avg 37
sys_geteuid count 2 avg 5
sys_time count 2 avg 7
sys_lseek count 2 avg 5
sys_ioctl count 2 avg 7
sys_access count 6 avg 8
sys_newuname count 2 avg 8
sys_fcntl64 count 1 avg 5
sys_fstat64 count 13 avg 5
sys_stat64 count 123 avg 9
sys_set_thread_area count 2 avg 6
sys_sigreturn count 1 avg 9
sys_close count 234 avg 6
sys_getpgrp count 1 avg 6
sys_getppid count 1 avg 5
sys_getpid count 1 avg 6
sys_getegid count 1 avg 5
sys_getgid count 1 avg 5
sys_getuid count 1 avg 5

Unfortunately we don't have a way to tell the translator which field to
use to sort the output. Of course you could just pipe the output through
sort.

Martin