2005-07-12 Martin Hunt <hunt@redhat.com>

	* bench/run_bench (do_time): Use ttest instead of "time".
	Fix processor computation.

	* bench/ttest.c: Like "time.c" except takes an argument
	to adjust loop size. Also computes system time + user time
	instead of real time. Added a warmup loop to get
	consistent results from cpus which adjust speed based on load.

	* bench/time.c: Replaced by ttest.c

5 files changed, 95 insertions, 81 deletions

diff --git a/runtime/probes/bench/bench.c b/runtime/probes/bench/bench.c
index adbe01d4..bbdc3170 100644
--- a/runtime/probes/bench/bench.c
+++ b/runtime/probes/bench/bench.c
@@ -37,11 +37,10 @@ static struct kprobe kp[] = {
 
 int probe_start(void)
 {
-  int ret;
-  ret = _stp_register_jprobes (jp, NUM_JPROBES);
+  int ret = _stp_register_jprobes (jp, NUM_JPROBES);
   if (ret >= 0)
     if ((ret = _stp_register_kprobes (kp, NUM_KPROBES)) < 0)
-      _stp_unregister_jprobes (jp, NUM_JPROBES)      ;
+      _stp_unregister_jprobes (jp, NUM_JPROBES);
   return ret;
 }
 
diff --git a/runtime/probes/bench/run_bench b/runtime/probes/bench/run_bench
index 48a60adb..471da231 100755
--- a/runtime/probes/bench/run_bench
+++ b/runtime/probes/bench/run_bench
@@ -1,7 +1,7 @@
 #!/usr/bin/tclsh
 # -*- tcl -*-
 
-proc do_time {module} {  
+proc do_time {module n} {  
   # start kprobes
   if {[catch {exec ../../stpd/stpd -mq $module.ko > xxx &} pid]} {
     puts $pid
@@ -11,7 +11,7 @@ proc do_time {module} {
   exec sleep 2
 
   # get the timings while kprobes running
-  if {[catch {exec ./time} res2]} {
+  if {[catch {exec ./ttest $n} res2]} {
     puts $res2
     exit -1
   }
@@ -25,7 +25,7 @@ proc do_time {module} {
 }
 
 
-set nproc [exec grep processor /proc/cpuinfo | wc -l]
+set nproc [exec grep ^processor /proc/cpuinfo | wc -l]
 if {![catch {exec grep "physical id" /proc/cpuinfo} phyid]} {
     foreach phy [split $phyid \n] {
 	set cpu($phy) 1
@@ -52,7 +52,7 @@ if {[catch {exec ./check_modules} res]} {
 }
 
 # get the timings without kprobes
-if {[catch {exec ./time} res1]} {
+if {[catch {exec ./ttest 4} res1]} {
   puts $res1
   exit -1
 }
@@ -60,7 +60,7 @@ if {[catch {exec ./time} res1]} {
 set r_overhead [lindex $res1 0]
 set w_overhead [lindex $res1 1]
 
-set res2 [do_time bench]
+set res2 [do_time bench 4]
 set t_kprobe [expr [lindex $res2 0] - $r_overhead]
 set t_jprobe [expr [lindex $res2 1] - $w_overhead]
 
@@ -69,7 +69,7 @@ puts "Kprobes overhead = $t_kprobe ns"
 puts "--------------------------------------"
 
 if {[file exists bench_ret.ko]} {
-  set res2 [do_time bench_ret]
+  set res2 [do_time bench_ret 4]
   set t_ret [expr [lindex $res2 0] - $r_overhead]
   set t_entret [expr [lindex $res2 1] - $w_overhead]
   
@@ -78,7 +78,7 @@ if {[file exists bench_ret.ko]} {
   puts "--------------------------------------"
 }
 
-set res2 [do_time bench_multi]
+set res2 [do_time bench_multi 4]
 set t_k2 [expr [lindex $res2 0] - $r_overhead]
 set t_k4 [expr [lindex $res2 1] - $w_overhead]
 
@@ -86,7 +86,7 @@ puts "2 kprobes on same func       = $t_k2 ns"
 puts "4 kprobes on same func       = $t_k4 ns"
 puts "--------------------------------------"
 
-set res2 [do_time bench_io1]
+set res2 [do_time bench_io1 1]
 # subtract function call overhead and kprobe overhead
 set t_printf [expr [lindex $res2 0] - $r_overhead - $t_kprobe]
 set t_print [expr [lindex $res2 1] - $w_overhead - $t_kprobe]
@@ -97,7 +97,7 @@ puts "_stp_print  on 100 chars = $t_print ns"
 puts "--------------------------------------"
 exec sleep 4
 
-set res2 [do_time bench_io2]
+set res2 [do_time bench_io2 1]
 # subtract function call overhead and kprobe overhead
 set t_printf [expr [lindex $res2 0] - $r_overhead - $t_kprobe]
 set t_print [expr [lindex $res2 1] - $w_overhead - $t_kprobe]
@@ -108,3 +108,4 @@ puts "_stp_print  on 100 chars = $t_print ns"
 puts "--------------------------------------"
 
 exec rm xxx
+exec /bin/rm -f stpd_cpu*
diff --git a/runtime/probes/bench/stp b/runtime/probes/bench/stp
index 00236805..c350f4e6 100755
--- a/runtime/probes/bench/stp
+++ b/runtime/probes/bench/stp
@@ -43,4 +43,4 @@ fi
 #../../stpd/stpd $modulename
 
 # no screen, log to files (file logging only if #define STP_NETLINK_ONLY commented out in module)
-../../stpd/stpd -q $modulename
+../../stpd/stpd -mq $modulename
diff --git a/runtime/probes/bench/time.c b/runtime/probes/bench/time.c
deleted file mode 100644
index fb423276..00000000
--- a/runtime/probes/bench/time.c
+++ /dev/null
@@ -1,68 +0,0 @@
-#include <stdio.h>
-#include <sys/types.h>
-#include <sys/stat.h>
-#include <fcntl.h>
-#include <sys/time.h>
-#include <stdlib.h>
-#include <unistd.h>
-
-typedef unsigned long long uint64;
-
-struct timeval t1;
-
-void start(struct timeval *tv)
-{
-  gettimeofday (tv, NULL);
-}
-
-uint64 time_delta(struct timeval *start, struct timeval *stop)
-{
-  uint64 secs, usecs;
-  
-  secs = stop->tv_sec - start->tv_sec;
-  usecs = stop->tv_usec - start->tv_usec;
-  if (usecs < 0) {
-    secs--;
-    usecs += 1000000;
-  }
-  return secs * 1000000 + usecs;
-}
-
-uint64 stop(struct timeval *begin)
-{
-  struct timeval end;
-  gettimeofday (&end, NULL);
-  return time_delta (begin, &end);
-}
-
-
-int main()
-{
-  int fd, i;
-  char buf[1024];
-  uint64 nsecs;
-
-  system ("touch foo");
-  fd = open ("foo", O_RDWR);
-
-  start(&t1);
-  for (i = 0; i < 1000000; i++) {
-    if (read (fd, buf, 0) < 0)
-      perror("read");
-  }
-  nsecs = stop(&t1) / 1000;
-
-  printf("%lld ", nsecs);
-
-  start(&t1);
-  for (i = 0; i < 1000000; i++) {
-    if (write (fd, buf, 0) < 0)
-      perror("write");
-  }
-  nsecs = stop(&t1) / 1000;
-  close (fd);
-
-  printf("%lld\n", nsecs);
-
-  return 0;
-}
diff --git a/runtime/probes/bench/ttest.c b/runtime/probes/bench/ttest.c
new file mode 100644
index 00000000..eed641da
--- /dev/null
+++ b/runtime/probes/bench/ttest.c
@@ -0,0 +1,82 @@
+#include <stdio.h>
+#include <sys/types.h>
+#include <sys/stat.h>
+#include <fcntl.h>
+#include <sys/time.h>
+#include <stdlib.h>
+#include <sys/resource.h>
+#include <unistd.h>
+
+typedef unsigned long long uint64;
+struct rusage rstart;
+
+void start()
+{
+  getrusage (RUSAGE_SELF, &rstart);
+}
+
+uint64 usecs (struct timeval *tv)
+{
+  return tv->tv_sec * 1000000 + tv->tv_usec;
+}
+
+uint64 stop()
+{
+  struct rusage rend;
+  getrusage (RUSAGE_SELF, &rend);
+  uint64 utime = usecs(&rend.ru_utime) - usecs(&rstart.ru_utime);
+  uint64 stime = usecs(&rend.ru_stime) - usecs(&rstart.ru_stime);
+  return utime + stime;
+}
+
+void usage(char *name)
+{
+    printf ("Usage %s [time]\nWhere \"time\" is millions of times to loop.\n", name);
+    exit(1);
+}
+
+int main(int argc, char *argv[])
+{
+  int fd, i, n = 1;
+  char buf[1024];
+  uint64 nsecs;
+
+  if (argc > 2)
+    usage(argv[0]);
+
+  if (argc == 2) {
+    n = strtol(argv[1], NULL, 10);
+    if (n == 0)
+      usage(argv[0]);
+  }
+
+  fd = open ("foo", O_CREAT | O_RDWR);
+
+  /* large warmup time */
+  for (i = 0; i < n * 1000000; i++) {
+    if (write (fd, buf, 0) < 0)
+      perror("write");
+  }
+
+  start();
+  for (i = 0; i < n * 1000000; i++) {
+    if (read (fd, buf, 0) < 0)
+      perror("read");
+  }
+  nsecs = stop() / (n * 1000);
+
+  printf("%lld ", nsecs);
+
+  start();
+  for (i = 0; i < n * 1000000; i++) {
+    if (write (fd, buf, 0) < 0)
+      perror("write");
+  }
+  nsecs = stop() / (n * 1000);
+  close (fd);
+
+  printf("%lld\n", nsecs);
+  unlink("foo");
+
+  return 0;
+}