Add sleepingBeauties.stp and sleepingBeauties.meta.

3 files changed, 75 insertions, 0 deletions

diff --git a/testsuite/systemtap.examples/ChangeLog b/testsuite/systemtap.examples/ChangeLog
index b337493c..7905119b 100644
--- a/testsuite/systemtap.examples/ChangeLog
+++ b/testsuite/systemtap.examples/ChangeLog
@@ -1,3 +1,7 @@
+2008-06-18  William Cohen  <wcohen@redhat.com>
+
+	* sleepingBeauties.stp, sleepingBeauties.meta: New.
+
 2008-06-17  William Cohen  <wcohen@redhat.com>
 
 	* graphs.stp, graphs.meta: New.
diff --git a/testsuite/systemtap.examples/sleepingBeauties.meta b/testsuite/systemtap.examples/sleepingBeauties.meta
new file mode 100644
index 00000000..95e08361
--- /dev/null
+++ b/testsuite/systemtap.examples/sleepingBeauties.meta
@@ -0,0 +1,13 @@
+title: Generating Backtraces of Threads Waiting for IO Operations
+name: sleepingBeauties.stp
+version: 1.0
+author: anonymous
+keywords: io scheduler
+subsystem: scheduler
+status: production
+exit: user-controlled
+output: trace
+scope: system-wide
+description: The script monitor time threads spend waiting for IO operations (in "D" state) in the wait_for_completion function. If a thread spends over 10ms wall-clock time waiting, information is printed out describing the thread number and executable name. When slow the wait_for_completion function complete, backtraces for the long duration calls are printed out.
+test_check: stap -p4 sleepingBeauties.stp
+test_installcheck: stap sleepingBeauties.stp -c "sleep 1"
diff --git a/testsuite/systemtap.examples/sleepingBeauties.stp b/testsuite/systemtap.examples/sleepingBeauties.stp
new file mode 100644
index 00000000..64c563a3
--- /dev/null
+++ b/testsuite/systemtap.examples/sleepingBeauties.stp
@@ -0,0 +1,58 @@
+#! /usr/bin/stap
+
+function time () { return gettimeofday_ms() }
+global time_name = "ms"
+global boredom = 10 # in time units
+global name, back, backtime, bored
+
+/* Note: the order that the probes are listed should not matter.
+   However, the following order for
+   probe kernel.function("wait_for_completion").return and
+   probe kernel.function("wait_for_completion").call
+   avoids have the kretprobe stuff in the backtrace.
+   for more information see:
+   http://sources.redhat.com/bugzilla/show_bug.cgi?id=6436
+*/
+
+
+probe kernel.function("wait_for_completion").return
+{
+  t=tid()
+
+  if ([t] in bored) {
+    patience = time() - backtime[t]
+    printf ("thread %d (%s) bored for %d %s\n", 
+            t, name[t], patience, time_name)
+  }
+
+  delete bored[t]
+  delete back[t]
+  delete name[t]
+  delete backtime[t]
+}
+
+
+probe kernel.function("wait_for_completion").call
+{ 
+  t=tid()
+  back[t]=backtrace()
+  name[t]=execname()
+  backtime[t]=time()
+  delete bored[t]
+}
+
+
+probe timer.profile {
+  foreach (tid+ in back) {
+    if ([tid] in bored) continue
+
+    patience = time() - backtime[tid]
+    if (patience >= boredom) {
+      printf ("thread %d (%s) impatient after %d %s\n",
+              tid, name[tid], patience, time_name)
+      print_stack (back[tid])
+      printf ("\n")
+      bored[tid] = 1 # defer further reports to wakeup
+    }
+  }
+}