Add iotime.stp, sleeptime.stp, and wait4time.stp examples.

4 files changed, 237 insertions, 0 deletions

diff --git a/examples/ChangeLog b/examples/ChangeLog
index 6d98998d..e5bab38f 100644
--- a/examples/ChangeLog
+++ b/examples/ChangeLog
@@ -1,3 +1,9 @@
+2007-01-11  Will Cohen  <wcohen@redhat.com>
+
+	* iotime.stp:
+	* sleeptime.stp:
+	* wait4time.stp: New examples.
+	
 2007-01-10  Martin Hunt  <hunt@redhat.com>
 
 	* small_demos/top.stp: Use "limit" option in foreach.
diff --git a/examples/iotime.stp b/examples/iotime.stp
new file mode 100644
index 00000000..d36fa321
--- /dev/null
+++ b/examples/iotime.stp
@@ -0,0 +1,112 @@
+/*
+ * Copyright (C) 2006 Daniel Berrange, Red Hat Inc.
+ * Copyright (C) 2007 Will Cohen, Red Hat, Inc.
+ * 
+ * This copyrighted material is made available to anyone wishing to use,
+ * modify, copy, or redistribute it subject to the terms and conditions
+ * of the GNU General Public License v.2.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program; if not, write to the Free Software Foundation,
+ * Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
+ *
+ * Print out the amount of time spent in the read and write systemcall
+ * when a process closes each file is closed. Note that the systemtap 
+ * script needs to be running before the open operations occur for
+ * the script to record data.
+ *
+ * This script could be used to to find out which files are slow to load
+ * on a machine. e.g.
+ *
+ * stap iotime.stp -c 'firefox'
+ *
+ * Output format is:
+ * timestamp pid (executabable) info_type path ...
+ *
+ * 200283135 2573 (cupsd) access /etc/printcap read: 0 write: 7063
+ * 200283143 2573 (cupsd) iotime /etc/printcap time: 69
+ *
+ */
+
+global start
+global entry_io
+global fd_io
+global time_io
+
+function timestamp:long() {
+  return gettimeofday_us() - start
+}
+
+function proc:string() {
+  return sprintf("%d (%s)", pid(), execname())
+}
+
+probe begin {
+ start = gettimeofday_us()
+}
+
+global filenames
+global filehandles
+global fileread
+global filewrite
+
+probe syscall.open {
+  filenames[pid()] = user_string($filename)
+} 
+
+probe syscall.open.return {
+  if ($return != -1) {
+    filehandles[pid(), $return] = filenames[pid()]
+    fileread[pid(), $return] = 0
+    filewrite[pid(), $return] = 0
+  } else {
+    printf("%d %s access %s fail\n", timestamp(), proc(), filenames[pid()])
+  }
+  delete filenames[pid()]
+}
+
+probe syscall.read {
+  if ($count > 0) {
+    fileread[pid(), $fd] += $count
+  }
+  t = gettimeofday_us(); p = pid()
+  entry_io[p] = t
+  fd_io[p] = $fd
+}
+
+probe syscall.read.return {
+  t = gettimeofday_us(); p = pid()
+  fd = fd_io[p]
+  time_io[p,fd] <<< t - entry_io[p]
+}
+
+probe syscall.write {
+  if ($count > 0) {
+    filewrite[pid(), $fd] += $count
+  }
+  t = gettimeofday_us(); p = pid()
+  entry_io[p] = t
+  fd_io[p] = $fd
+}
+
+probe syscall.write.return {
+  t = gettimeofday_us(); p = pid()
+  fd = fd_io[p]
+  time_io[p,fd] <<< t - entry_io[p]
+}
+
+probe syscall.close {
+  if (filehandles[pid(), $fd] != "") {
+    printf("%d %s access %s read: %d write: %d\n",  timestamp(), proc(),
+	filehandles[pid(), $fd], fileread[pid(), $fd], filewrite[pid(), $fd])
+    if (@count(time_io[pid(), $fd]))
+      printf("%d %s iotime %s time: %d\n",  timestamp(), proc(),
+	filehandles[pid(), $fd], @sum(time_io[pid(), $fd]))
+   }
+  delete fileread[pid(), $fd]
+  delete filewrite[pid(), $fd]
+  delete filehandles[pid(), $fd]
+  delete fd_io[pid()]
+  delete entry_io[pid()]
+  delete time_io[pid(),$fd]
+}
diff --git a/examples/sleeptime.stp b/examples/sleeptime.stp
new file mode 100644
index 00000000..3d8dc359
--- /dev/null
+++ b/examples/sleeptime.stp
@@ -0,0 +1,61 @@
+/*
+ * Copyright (C) 2006 Daniel Berrange, Red Hat Inc.
+ * Copyright (C) 2007 Will Cohen, Red Hat, Inc.
+ * 
+ * This copyrighted material is made available to anyone wishing to use,
+ * modify, copy, or redistribute it subject to the terms and conditions
+ * of the GNU General Public License v.2.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program; if not, write to the Free Software Foundation,
+ * Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
+ *
+ * Print out the amount of time spent in the nanosleep and compat_nanosleep
+ * systemcalls. This can help find which processes are waking based on time
+ * rather than some real event than needs to be handled.
+ *
+ * Format is:
+ * 12799538 3389 (xchat) nanosleep: 9547
+ * 12846944 2805 (NetworkManager) nanosleep: 100964
+ * 12947924 2805 (NetworkManager) nanosleep: 100946
+ * 13002925 4757 (sleep) nanosleep: 13000717
+ */
+
+global start
+global entry_nanosleep
+
+function timestamp:long() {
+  return gettimeofday_us() - start
+}
+
+function proc:string() {
+  return sprintf("%d (%s)", pid(), execname())
+}
+
+probe begin {
+ start = gettimeofday_us()
+}
+
+probe syscall.nanosleep {
+  t = gettimeofday_us(); p = pid()
+  entry_nanosleep[p] = t
+}
+
+probe syscall.nanosleep.return {
+  t = gettimeofday_us(); p = pid()
+  elapsed_time = t - entry_nanosleep[p]
+  printf("%d %s nanosleep: %d\n",  timestamp(), proc(), elapsed_time)
+  delete entry_nanosleep[p]
+}
+
+probe syscall.compat_nanosleep ? {
+  t = gettimeofday_us(); p = pid()
+  entry_nanosleep[p] = t
+}
+
+probe syscall.compat_nanosleep.return ? {
+  t = gettimeofday_us(); p = pid()
+  elapsed_time = t - entry_nanosleep[p]
+  printf("%d %s compat_nanosleep: %d\n",  timestamp(), proc(), elapsed_time)
+  delete entry_nanosleep[p]
+}
diff --git a/examples/wait4time.stp b/examples/wait4time.stp
new file mode 100644
index 00000000..04bdec08
--- /dev/null
+++ b/examples/wait4time.stp
@@ -0,0 +1,58 @@
+/*
+ * Copyright (C) 2006 Daniel Berrange, Red Hat Inc.
+ * Copyright (C) 2007 Will Cohen, Red Hat, Inc.
+ * 
+ * This copyrighted material is made available to anyone wishing to use,
+ * modify, copy, or redistribute it subject to the terms and conditions
+ * of the GNU General Public License v.2.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program; if not, write to the Free Software Foundation,
+ * Inc., 59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
+ *
+ * Print out the amount of time spent in the read and write systemcall
+ * when a process closes each file is closed. Note that the script needs
+ * to be running before the open operations occur for the script
+ * to record data.
+ *
+ * Format is:
+ * timestamp pid (executabable) wait4: time_us pid
+ *
+ * 155789807 4196 (ssh) wait4: 12 4197
+ * 158270531 3215 (bash) wait4: 5410460 -1
+ * 158270659 3215 (bash) wait4: 9 -1
+ * 158557461 2614 (sendmail) wait4: 27 -1
+ * 158557487 2614 (sendmail) wait4: 5 -1
+ *
+ */
+
+global start
+global entry_wait4
+global wait4_pid
+
+function timestamp:long() {
+  return gettimeofday_us() - start
+}
+
+function proc:string() {
+  return sprintf("%d (%s)", pid(), execname())
+}
+
+probe begin {
+ start = gettimeofday_us()
+}
+
+probe syscall.wait4 {
+  t = gettimeofday_us(); p = pid()
+  entry_wait4[p] = t
+  wait4_pid[p]=$pid
+}
+
+probe syscall.wait4.return {
+  t = gettimeofday_us(); p = pid()
+  elapsed_time = t - entry_wait4[p]
+  printf("%d %s wait4: %d %d\n",  timestamp(), proc(), elapsed_time,
+	wait4_pid[p])
+  delete entry_wait4[p]
+  delete wait4_pid[p]
+}