This is the mail archive of the
systemtap@sourceware.org
mailing list for the systemtap project.
Re: Another Newbie question about measuring time in a sys call
- From: David A Sperry <David_A_Sperry at raytheon dot com>
- To: fche at redhat dot com (Frank Ch. Eigler), Li Guanglei <guanglei at cn dot ibm dot com>
- Cc: systemtap at sources dot redhat dot com
- Date: Wed, 8 Feb 2006 08:46:11 -0500
- Subject: Re: Another Newbie question about measuring time in a sys call
Thanks Frank and Li,
Both of your examples work and are a big help!
Frank, I like your example using tid() instead of pid() and the @ave()
function. I modified your script to add @min() and @max() just to see what
would happen and it worked! I got
syscall ioctl count 38 avg 19 min 16 max 23
syscall gettimeofday count 19 avg 11 min 11 max 12
syscall llseek count 38 avg 10 min 9 max 13
syscall fstat64 count 19 avg 11 min 11 max 13
syscall fcntl64 count 722 avg 11 min 7 max 26
syscall creat count 3211 avg 38 min 33 max 1760
syscall stat64 count 1577 avg 32 min 29 max 80
syscall lseek count 57 avg 9 min 8 max 12
syscall getdents count 38 avg 56 min 29 max 80
>From this quick test I can see that syscall creat has at least one call
that took a long time. Really cool!
Dave
systemtap-owner@sourceware.org wrote on 02/08/2006 07:32:17 AM:
>
> 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