2007-03-14 Martin Hunt <hunt@redhat.com>

	* bench2/bench.rb: Updated to work with new transport
	and new itest.c.
	* bench2/Makefile: Updated for new itest.c
	* bench2/itest.c: Rewritten to use multiple threads
	and automatically divide the workload among the threads.

	* print.c (_stp_print_flush): Move to print_new.c and
	print_old.c.
	* print_new.c: New file containing _stp_print_flush()
	for the new transport.
	* print_old.c: Ditto for old transport.

	* runtime.h (STP_OLD_TRANSPORT): Define
	(errk): Define.
	(MAXSTRINGLEN): Define if not already defined.

	* io.c (_stp_vlog): Use _stp_ctl_write().

6 files changed, 184 insertions, 86 deletions

diff --git a/runtime/bench2/Makefile b/runtime/bench2/Makefile
index 7fcfcfe4..ffb2991a 100644
--- a/runtime/bench2/Makefile
+++ b/runtime/bench2/Makefile
@@ -1,7 +1,7 @@
 all: itest
 
 itest: itest.c
-	gcc -Wall -O3 -o itest itest.c
+	gcc -D_GNU_SOURCE -Wall -Wextra -Wstrict-prototypes -Werror -O3 -o itest itest.c -lpthread
 
 clean:
 	/bin/rm -f itest
diff --git a/runtime/bench2/bench.rb b/runtime/bench2/bench.rb
index 05c6ee3e..a04582d2 100644
--- a/runtime/bench2/bench.rb
+++ b/runtime/bench2/bench.rb
@@ -1,5 +1,5 @@
 # Benchmark Class for SystemTap
-# Copyright (C) 2006 Red Hat Inc.
+# Copyright (C) 2006, 2007 Red Hat Inc.
 #
 # This file is part of systemtap, and is free software.  You can
 # redistribute it and/or modify it under the terms of the GNU General
@@ -11,9 +11,8 @@ MAXFILE = "/sys/devices/system/cpu/cpu0/cpufreq/scaling_max_freq"
 MINFILE = "/sys/devices/system/cpu/cpu0/cpufreq/scaling_min_freq"
 
 # more constants
-PROCFS = 1
-RELAYFS= 2
-UTT = 3
+STREAM = 1
+BULK= 2
 
 at_exit {Bench.done}
 
@@ -22,7 +21,8 @@ class Bench
     @desc = desc
     @code = nil
     @file = nil
-    @trans = 1
+    @trans = STREAM
+    @outfile= "xxx"
     @failures = []
     @results = []
     if @@printed_header == 0
@@ -56,7 +56,7 @@ class Bench
     end
   end
 
-  attr_writer :code, :file, :trans
+  attr_writer :code, :file, :trans, :outfile
   attr_reader :failures, :results
 
   def run
@@ -66,12 +66,10 @@ class Bench
     @@num_threads.each do |threads|
       load
       sum=0
-      threads.times {|cpu| fork {exec "./itest #{threads} > #{@dir}/bench#{cpu}"}}
-      threads.times {Process.waitpid(-1)}	# wait for itest(s) to exit
+      `./itest #{threads} > #{@dir}/bench`
       `sudo killall -HUP staprun`
       Process.wait	# wait for staprun to exit
-      threads.times {|x| sum = sum + `cat #{@dir}/bench#{x}`.split[0].to_i - @@ftime}
-      @results[threads] = sum / (threads * threads)
+      @results[threads] = `cat #{@dir}/bench`.split[0].to_i - @@ftime[threads]
       File.open("#{@dir}/xxx.out") do |file|
 	file.each_line do |line|
 	  m = line.match(/WARNING: There were ([\d]*)/)
@@ -92,10 +90,13 @@ class Bench
       else
 	printf("R")
       end
-      if @trans == RELAYFS
-	printf("R")
-      elsif @trans == UTT
-	printf("U""")
+      if @trans == BULK
+	printf("B")
+      else
+	printf(" ")
+      end
+      if @outfile == "/dev/null"
+	printf("N")
       else
 	printf(" ")
       end
@@ -120,7 +121,7 @@ class Bench
 
   protected
 
-  @@ftime = 0
+  @@ftime = []
   @@printed_header = 0
   @@staprun = nil
   @@runtime = nil
@@ -137,11 +138,9 @@ class Bench
   end
 
   def load
-    args = "-q -b 8"
-    if @trans == RELAYFS then args = "-q" end
-    if @trans == UTT then args = "-lq" end
-    fork do exec "sudo #{@@staprun} #{args} #{@dir}/bench.ko > #{@dir}/xxx 2> #{@dir}/xxx.out" end
-    sleep 5
+    args = "-q"
+    fork do exec "sudo #{@@staprun} #{args} -o #{@outfile} #{@dir}/bench.ko &> #{@dir}/xxx.out" end
+    sleep 10
   end
 
   def compile
@@ -183,6 +182,7 @@ void probe_exit (void)\n{\n  unregister_kprobe (&kp); \n}\n"
 CFLAGS += -I \"#{@@runtime}\"
 obj-m := bench.o
 "
+      if @trans == BULK then makefile << "CFLAGS += -DSTP_BULKMODE" end
       makefile.close
     else
       puts "NO CODE!"
@@ -227,14 +227,15 @@ obj-m := bench.o
     end
     puts "-"*64
     check_cpuspeed
-    @@ftime = `./itest 1`.to_i
-    @@ftime = `./itest 1`.to_i
-    puts "For comparison, function call overhead is #@@ftime nsecs."
-      puts "Times below are nanoseconds per probe and include kprobe overhead."
+    @@num_threads.each do |threads|
+      @@ftime[threads] = `./itest #{threads} 10000000`.to_i
+    end
+    puts "Times below are nanoseconds per probe and include kprobe overhead."
     puts "-"*64
-    puts "+--- S = Script, R = Runtime"
-    puts "|+-- R = Relayfs, U = UTT  \tThreads"
-    printf "|| NAME                 "
+    puts "+---- S = Script, R = Runtime"
+    puts "|+--- B = Bulk"
+    puts "||+-- N = No output\t\t  Threads"
+    printf "||| NAME                 "
     @@num_threads.each {|n| printf("\t    %d",n)}
     printf "\n"
   end
@@ -251,6 +252,8 @@ obj-m := bench.o
   end
 end
 
+#### STAPBENCH ######
+
 class Stapbench < Bench
 
   def run
@@ -260,12 +263,10 @@ class Stapbench < Bench
     @@num_threads.each do |threads|
       load
       sum=0
-      threads.times {|cpu| fork {exec "./itest #{threads} > bench#{cpu}"}}
-      threads.times {Process.waitpid(-1)}	# wait for itest(s) to exit
+      `./itest #{threads} > bench`
       `sudo killall -HUP staprun`
-      Process.wait	# wait for stap to exit
-      threads.times {|x| sum = sum + `cat bench#{x}`.split[0].to_i - @@ftime}
-      @results[threads] = sum / (threads * threads)
+      Process.wait	# wait for staprun to exit
+      @results[threads] = `cat bench`.split[0].to_i - @@ftime[threads]
       File.open("xxx.out") do |file|
 	file.each_line do |line|
 	  m = line.match(/WARNING: There were ([\d]*)/)
@@ -283,9 +284,8 @@ class Stapbench < Bench
 
   def load
     args = "-vv"
-    if @trans == RELAYFS then args = "-bMvv" end
-    if @trans == UTT then args = "-lvv" end
-    fork do exec "stap #{args} bench.stp > xxx 2> xxx.out" end
+    if @trans == BULK then args = "-bvv" end
+    fork do exec "stap #{args} -o #{@outfile} bench.stp &> xxx.out" end
     sleep 10
   end
   
diff --git a/runtime/bench2/itest.c b/runtime/bench2/itest.c
index efba623a..0578cf40 100644
--- a/runtime/bench2/itest.c
+++ b/runtime/bench2/itest.c
@@ -1,3 +1,13 @@
+/*
+ * itest - timed test program for use with bench2
+ * Copyright (C) 2007 Red Hat Inc.
+ *
+ * This file is part of systemtap, and is free software.  You can
+ * redistribute it and/or modify it under the terms of the GNU General
+ * Public License (GPL); either version 2, or (at your option) any
+ * later version.
+ */
+
 #include <stdio.h>
 #include <sys/types.h>
 #include <sys/stat.h>
@@ -6,11 +16,18 @@
 #include <stdlib.h>
 #include <sys/resource.h>
 #include <unistd.h>
+#include <pthread.h>
+#include <semaphore.h>
+#include <sched.h>
 
 typedef unsigned long long uint64;
 struct timeval tstart, tstop;
+pthread_t tester[256];
+sem_t go;
+int ncpus;
+int iterations;
 
-void start()
+void start(void)
 {
   gettimeofday (&tstart, NULL);
 }
@@ -20,7 +37,7 @@ uint64 usecs (struct timeval *tv)
   return tv->tv_sec * 1000000 + tv->tv_usec;
 }
 
-uint64 stop()
+uint64 stop(void)
 {
   gettimeofday (&tstop, NULL);
   return  usecs(&tstop) - usecs(&tstart);
@@ -28,31 +45,115 @@ uint64 stop()
 
 void usage(char *name)
 {
-    printf ("Usage %s [num_threads]\nitest will call sys_getuid() 1000000/num_threads times.\n", name);
-    exit(1);
+  printf ("Usage %s [num_threads] [total_iterations]\n", name);
+  printf("%s will call sys_getuid() total_iterations [default 2,000,000]\n", name);
+  printf("times divided across num_threads [default 1].\n\n");
+  exit(1);
+}
+
+
+void *null_thread (void *data)
+{
+  int cpu;
+  cpu_set_t cpu_mask;
+  int thread_num  = (int)(long)data;
+
+  cpu = thread_num % ncpus;
+  CPU_ZERO(&cpu_mask);
+  CPU_SET(cpu, &cpu_mask);
+  if( sched_setaffinity( 0, sizeof(cpu_mask), &cpu_mask ) < 0 ) {
+    perror("sched_setaffinity");
+  }
+
+
+  // fprintf(stderr, "starting thread %d on cpu %d num=%d\n", thread_num, cpu, iterations);
+  while (sem_wait(&go) == -1) ;
+
+  return NULL;
+}
+
+void *caller_thread (void *data)
+{
+  int i, cpu;
+  cpu_set_t cpu_mask;
+  int thread_num  = (int)(long)data;
+
+  /* Force threads to be distributed across all cpus. */
+  /* The scheduler would probably do the right thing without this. */
+  cpu = thread_num % ncpus;
+  CPU_ZERO(&cpu_mask);
+  CPU_SET(cpu, &cpu_mask);
+  if( sched_setaffinity( 0, sizeof(cpu_mask), &cpu_mask ) < 0 ) {
+    perror("sched_setaffinity");
+  }
+  
+  // fprintf(stderr, "starting thread %d on cpu %d num=%d\n", thread_num, cpu, iterations);
+  while (sem_wait(&go) == -1) ;
+
+  for (i = 0; i < iterations; i++)
+    getuid();
+
+  return NULL;
 }
 
 int main(int argc, char *argv[])
 {
   int i, n = 1;
-  uint64 nsecs;
+  uint64 nsecs, null_usecs, caller_usecs;
+  int total_iterations = 2000000;
 
-  if (argc > 2)
+  if (argc > 3)
     usage(argv[0]);
 
-  if (argc == 2) {
+  if (argc >= 2) {
     n = strtol(argv[1], NULL, 10);
     if (n <= 0)
       usage(argv[0]);
   }
+  if (argc > 2) {
+    total_iterations = strtol(argv[2], NULL, 10);  
+    if (total_iterations < 100000)
+      usage(argv[0]);
+  }
+
+  ncpus = sysconf(_SC_NPROCESSORS_ONLN);
+  sem_init (&go, 0, 0);
+  iterations = total_iterations/n;
+
+  for (i = 0; i < n; i++) {
+    if (pthread_create(&tester[i], NULL, null_thread, (void *)(long)i) < 0) {
+      perror("Error creating thread");
+      return -1;
+    }
+  }
 
   start();
-  for (i = 0; i < 1000000/n; i++)
-    getuid();
+  for (i = 0; i < n; i++)
+    sem_post (&go);
+  
+  for (i = 0; i < n; i++)
+    pthread_join(tester[i], NULL);
+
+  null_usecs = stop();
 
-  nsecs = stop() * n / 1000;
+  for (i = 0; i < n; i++) {
+    if (pthread_create(&tester[i], NULL, caller_thread, (void *)(long)i) < 0) {
+      perror("Error creating thread");
+      return -1;
+    }
+  }
+
+  start();
+  for (i = 0; i < n; i++)
+    sem_post (&go);
+  
+  for (i = 0; i < n; i++)
+    pthread_join(tester[i], NULL);
 
+  caller_usecs = stop();
+  
   /* returns nanosecs per call  */
+  nsecs = ((caller_usecs - null_usecs) * 1000LL) / ((uint64)(n * iterations));
   printf("%lld\n", nsecs);
   return 0;
 }
diff --git a/runtime/bench2/run_bench b/runtime/bench2/run_bench
index dad8c8ae..b77b9497 100755
--- a/runtime/bench2/run_bench
+++ b/runtime/bench2/run_bench
@@ -10,31 +10,21 @@ test.print
 # script test with empty probe
 test0 = Stapbench.new("empty probe")
 test0.code = ""
+test0.trans=BULK
 test0.run
 test0.print
 
-# script test to print 100 chars
-test2a = Stapbench.new("printf 100 chars")
-test2a.code = "printf(\"123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789\\n\")"
-test2a.run
-test2a.print
-
-test2a.trans = RELAYFS
-test2a.run
-test2a.print
-
-# runtime test to print 100 chars
-test2 = Bench.new("printf 100 chars")
-test2.code = "(void)_stp_printf (\"123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789\\n\");
-  _stp_print_flush();"
+# script test to printf 100 chars
+test2 = Stapbench.new("printf 100 chars")
+test2.code = "printf(\"123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789\\n\")"
+test2.trans=BULK
 test2.run
 test2.print
 
-
-# runtime test to print 5 integers
-test3 = Bench.new("printf 5 integers")
-test3.code = "_stp_printf (\"%lld, %lld, %lld, %lld, %lld\\n\", 1LL, 0xffffLL, 0x8000ffffLL, 0xffff000011112222LL, 0x7000000000000000LL);
-  _stp_print_flush();"
+# script test to print 100 chars
+test3 = Stapbench.new("print 100 chars")
+test3.code = "print(\"123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789\\n\")"
+test3.trans=BULK
 test3.run
 test3.print
 
@@ -42,4 +32,5 @@ test3.print
 test4 = Stapbench.new("printf 5 integers")
 test4.code = "printf(\"%d, %d, %d, %d, %d\\n\", 1, 0xffff, 0x8000ffff, 0xffff000011112222, 0x7000000000000000)"
 test4.run
+test4.trans=BULK
 test4.print
diff --git a/runtime/bench2/run_binary_print b/runtime/bench2/run_binary_print
index bbd83180..c42bba98 100755
--- a/runtime/bench2/run_binary_print
+++ b/runtime/bench2/run_binary_print
@@ -1,31 +1,12 @@
 #!/usr/bin/env ruby
 load './bench.rb'
 
-# script test with empty probe
-test0 = Stapbench.new("empty probe")
-test0.code = ""
-test0.run
-test0.print
-
-# script test to binary print 4 integers
-test1 = Stapbench.new("binary printf 4 integers (%8b)")
-test1.code = "printf(\"%8b%8b%8b%8b\", 111,22,333,444)"
-test1.run
-test1.print
-
-# script test to binary print 4 integers
-test2 = Stapbench.new("binary printf 4 integers (%4b)")
-test2.code = "printf(\"%4b%4b%4b%4b\", 111,22,333,444)"
-test2.run
-test2.print
-
-
 # script test to binary print 4 integers
 test3 = Stapbench.new("binary printf 4 integers (%b)")
 test3.code = "printf(\"%b%b%b%b\", 111,22,333,444)"
 test3.run
 test3.print
-test3.trans = RELAYFS
+test3.trans = BULK
 test3.run
 test3.print
 
@@ -34,7 +15,7 @@ test4 = Stapbench.new("_stp_print_binary 4 integers")
 test4.code = "stp_print_binary(4,111,22,333,444)"
 test4.run
 test4.print
-test4.trans = RELAYFS
+test4.trans = BULK
 test4.run
 test4.print
 
diff --git a/runtime/bench2/test_bench b/runtime/bench2/test_bench
new file mode 100755
index 00000000..4bf90744
--- /dev/null
+++ b/runtime/bench2/test_bench
@@ -0,0 +1,25 @@
+#!/usr/bin/env ruby
+load './bench.rb'
+
+
+# script test to printf 100 chars
+test3 = Stapbench.new("printf 100 chars")
+test3.code = "printf(\"123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789\\n\")"
+test3.run
+test3.print
+
+test3.trans = BULK
+test3.run
+test3.print
+
+test3.trans = STREAM
+test3.outfile="/dev/null"
+test3.run
+test3.print
+
+test3.trans = BULK
+test3.outfile="/dev/null"
+test3.run
+test3.print
+
+