From: Frank Ch. Eigler Date: Mon, 1 Feb 2010 20:39:01 +0000 (-0500) Subject: new sample for sandeen@redhat.com: fntimes.stp X-Git-Tag: release-1.2~214^2~4 X-Git-Url: https://sourceware.org/git/?a=commitdiff_plain;h=0b12a8cd2ea7700fa9b96930947b7844cca0aab9;p=systemtap.git new sample for sandeen@redhat.com: fntimes.stp --- diff --git a/testsuite/systemtap.examples/profiling/fntimes.meta b/testsuite/systemtap.examples/profiling/fntimes.meta new file mode 100644 index 000000000..4b4ff1ed3 --- /dev/null +++ b/testsuite/systemtap.examples/profiling/fntimes.meta @@ -0,0 +1,6 @@ +title: Show functions taking longer than usual +name: fntimes.stp +keywords: profiling +description: The fntimes.stp script monitors the execution time history of a given function family (assumed non-recursive). Each time (beyond a warmup interval) is then compared to the historical maximum. If it exceeds a certain threshold (250%), a message is printed. +test_check: stap -p4 fntimes.stp 'kernel.function("sys_*")' +test_installcheck: stap fntimes.stp 'kernel.function("sys_*")' -c "sleep 7" diff --git a/testsuite/systemtap.examples/profiling/fntimes.stp b/testsuite/systemtap.examples/profiling/fntimes.stp new file mode 100755 index 000000000..e9daac773 --- /dev/null +++ b/testsuite/systemtap.examples/profiling/fntimes.stp @@ -0,0 +1,30 @@ +#! /usr/bin/stap + +# usage: fntimes.stp FUNCTIONPROBE +# e.g. fntimes.stp 'module("ext4").function("*")' + +global mincount = 100 # training: beneath this number of hits, only collect data +global note_percent = 250 # percent beyond maximum-so-far to generate report for +function time() { return gettimeofday_us() } # time measurement function + +global times, entry + +probe $1.call { + entry[probefunc(),tid()] = time() +} + +probe $1.return { + pf=probefunc() + tid=tid() + if ([pf,tid] in entry) { # seen function entry? + t = time()-entry[pf,tid] # t: elapsed time + delete entry[pf,tid] + if (@count(times[pf]) >= mincount + && t >= @max(times[pf]) * note_percent / 100) { # also consider @avg() + printf("function %s well over %s time (%d vs %d)\n", + pf, "maximum", t, @max(times[pf])) + # also consider: print_backtrace() + } + times[pf] <<< t # (increments @count, updates @max) + } +}