This is the mail archive of the
systemtap@sourceware.org
mailing list for the systemtap project.
The linetimes.stp example to see which lines of code are expensive.
- From: William Cohen <wcohen at redhat dot com>
- To: SystemTAP <systemtap at sources dot redhat dot com>
- Date: Tue, 11 May 2010 12:14:51 -0400
- Subject: The linetimes.stp example to see which lines of code are expensive.
This Monday I wrote up a script that instruments a function on a per line basis and records the amount of time that each line takes. The script should make it easier to see what is going on with in a function. If you want to take a look at the script, it has been check in with the following commit:
http://sources.redhat.com/git/gitweb.cgi?p=systemtap.git;a=commit;h=e985df18d54c57bcd14bbed0ec420d353e767198
Below is an example run of the script for the do_unlinkat() function on a Fedora 12 machine. Is shows the avg and max time for each line of the function. The following table shows the number of times each line executes. Any suggestions for improvements to the script would be appreciated.
-Will
$ stap linetimes.stp kernel do_unlinkat
^C
do_unlinkat called 11
region avg(us) max(us)
kernel.statement("do_unlinkat@fs/namei.c:2315") 5 8
kernel.statement("do_unlinkat@fs/namei.c:2322") 13 16
kernel.statement("do_unlinkat@fs/namei.c:2323") 9 11
kernel.statement("do_unlinkat@fs/namei.c:2324") 9 11
kernel.statement("do_unlinkat@fs/namei.c:2327") 8 10
kernel.statement("do_unlinkat@fs/namei.c:2330") 8 10
kernel.statement("do_unlinkat@fs/namei.c:2332") 8 10
kernel.statement("do_unlinkat@fs/namei.c:2333") 8 10
kernel.statement("do_unlinkat@fs/namei.c:2335") 8 9
kernel.statement("do_unlinkat@fs/namei.c:2337") 7 8
kernel.statement("do_unlinkat@fs/namei.c:2339") 7 8
kernel.statement("do_unlinkat@fs/namei.c:2340") 7 8
kernel.statement("do_unlinkat@fs/namei.c:2342") 7 8
kernel.statement("do_unlinkat@fs/namei.c:2343") 6 8
kernel.statement("do_unlinkat@fs/namei.c:2348") 35 60
kernel.statement("do_unlinkat@fs/namei.c:2350") 6 9
kernel.statement("do_unlinkat@fs/namei.c:2352") 6 9
kernel.statement("do_unlinkat@fs/namei.c:2354") 6 9
kernel.statement("do_unlinkat@fs/namei.c:2355") 5 9
kernel.statement("do_unlinkat@fs/namei.c:2356") 828 6966
kernel.statement("do_unlinkat@fs/namei.c:2358") 6 10
kernel.statement("do_unlinkat@fs/namei.c:2359") 5 11
kernel.statement("do_unlinkat@fs/namei.c:2360") 5 10
kernel.statement("do_unlinkat@fs/namei.c:2366") 5 12
control flow graph information
=======================
kernel.statement("do_unlinkat@fs/namei.c:2315") 11
kernel.statement("do_unlinkat@fs/namei.c:2322") 11
kernel.statement("do_unlinkat@fs/namei.c:2323") 11
kernel.statement("do_unlinkat@fs/namei.c:2324") 11
kernel.statement("do_unlinkat@fs/namei.c:2327") 11
kernel.statement("do_unlinkat@fs/namei.c:2330") 11
kernel.statement("do_unlinkat@fs/namei.c:2332") 11
kernel.statement("do_unlinkat@fs/namei.c:2333") 11
kernel.statement("do_unlinkat@fs/namei.c:2335") 11
kernel.statement("do_unlinkat@fs/namei.c:2337") 11
kernel.statement("do_unlinkat@fs/namei.c:2339") 11
kernel.statement("do_unlinkat@fs/namei.c:2340") 11
kernel.statement("do_unlinkat@fs/namei.c:2342") 11
kernel.statement("do_unlinkat@fs/namei.c:2343") 11
kernel.statement("do_unlinkat@fs/namei.c:2348") 11
kernel.statement("do_unlinkat@fs/namei.c:2350") 11
kernel.statement("do_unlinkat@fs/namei.c:2352") 11
kernel.statement("do_unlinkat@fs/namei.c:2354") 11
kernel.statement("do_unlinkat@fs/namei.c:2355") 11
kernel.statement("do_unlinkat@fs/namei.c:2356") 11
kernel.statement("do_unlinkat@fs/namei.c:2358") 11
kernel.statement("do_unlinkat@fs/namei.c:2359") 11
kernel.statement("do_unlinkat@fs/namei.c:2360") 11
kernel.statement("do_unlinkat@fs/namei.c:2366") 11