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

[fche@redhat.com (Frank Ch. Eigler)]

David_A_Sperry wrote:

> probe kernel.syscall.* {
>         if (execname() == "top")
>                 called[name] = gettimeofday_us()
> }
> probe kernel.syscall.*.return {
>         if (execname() == "top")
>                 ttime[name] +=  gettimeofday_us() - called[name]
> }

Indeed, the "name" value exported from the syscalls tapset has been
changed, for better or for worse.  Plus there are still some
"kernel.syscall.*" stragglers in the syscalls*stp files, so there is
plenty of reason for confusion.

Here's how the script might work today.


probe kernel.syscall.* {
   if (execname() != "top") next
   callee[tid()] = name # saved because .return probe changes name
   calltime[tid()] = gettimeofday_us()
}

probe kernel.syscall.*.return {
   if (execname() != "top") next
   c=calltime[tid()]
   if (!c) next
   delete calltime[tid()]
   ttime[callee[tid()]] <<< gettimeofday_us() - c
}

# Note: code like the above probe pair could go into a higher layer
# standard tapset.

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

global callee, calltime, ttime


- FChE