Try to fix test reports with test % over 100%. The problem is we assume there is only one top method but in fact there can be more than one. Examples include starting a profile and then returning from a method, profiling at exit blocks and exceptions.

Author: Charlie Savage

ext/ruby_prof/rp_method.h

@@ -31,7 +31,7 @@ typedef struct
     prof_method_key_t *key;                 /* Method key */
     const char *source_file;                /* The method's source file */
     int line;                               /* The method's line number. */
-    struct prof_call_infos_t *call_infos;          /* Call info objects for this method */
+    struct prof_call_infos_t *call_infos;   /* Call info objects for this method */
     VALUE object;                           /* Cached ruby object */
 	VALUE call_infos2;                      /* Cached array of RubyProf::CallInfo */
 } prof_method_t;

ext/ruby_prof/rp_thread.c

@@ -12,7 +12,6 @@ thread_data_create()
     thread_data_t* result = ALLOC(thread_data_t);
     result->stack = prof_stack_create();
     result->method_table = method_table_create();
-	result->top = NULL;
 	result->object = Qnil;
 	result->methods = Qnil;
     return result;
@@ -42,7 +41,6 @@ static void
 thread_data_free(thread_data_t* thread_data)
 {
 	thread_data_ruby_gc_free(thread_data);
-    thread_data->top = NULL;
     method_table_free(thread_data->method_table);
     prof_stack_free(thread_data->stack);
 
@@ -68,7 +66,6 @@ prof_thread_mark(thread_data_t *thread)
 	if (thread->methods != Qnil)
 		rb_gc_mark(thread->methods);
 
-	prof_method_mark(thread->top);
 	st_foreach(thread->method_table, mark_methods, 0);
 }
 
@@ -179,6 +176,29 @@ switch_thread(void* prof, VALUE thread_id)
     return thread_data;
 }
 
+
+int pause_thread(st_data_t key, st_data_t value, st_data_t data) 
+{
+    thread_data_t* thread_data = (thread_data_t *) value;
+    double measurement = (double) data;
+
+    prof_frame_t* frame = prof_stack_peek(thread_data->stack);
+    prof_frame_pause(frame, measurement);
+
+    return ST_CONTINUE;
+}
+
+int unpause_thread(st_data_t key, st_data_t value, st_data_t data) 
+{
+    thread_data_t* thread_data = (thread_data_t *) value;
+    double measurement = (double) data;
+
+    prof_frame_t* frame = prof_stack_peek(thread_data->stack);
+    prof_frame_unpause(frame, measurement);
+
+    return ST_CONTINUE;
+}
+
 static int
 collect_methods(st_data_t key, st_data_t value, st_data_t result)
 {
@@ -220,24 +240,11 @@ prof_thread_methods(VALUE self)
 	return thread->methods;
 }
 
-/* call-seq:
-   method -> MethodInfo
-
-Returns the top level method for this thread (ie, the starting
-method). */
-static VALUE
-prof_thread_top_method(VALUE self)
-{
-    thread_data_t* thread = prof_get_thread(self);
-	return  prof_method_wrap(thread->top);
-}
-
 void rp_init_thread()
 {
     cRpThread = rb_define_class_under(mProf, "Thread", rb_cObject);
     rb_undef_method(CLASS_OF(cRpThread), "new");
 
     rb_define_method(cRpThread, "id", prof_thread_id, 0);
     rb_define_method(cRpThread, "methods", prof_thread_methods, 0);
-    rb_define_method(cRpThread, "top_method", prof_thread_top_method, 0);
 }

ext/ruby_prof/rp_thread.h

@@ -12,7 +12,6 @@ typedef struct
     VALUE thread_id;                  /* Thread id */
     st_table* method_table;           /* Methods called in the thread */
     prof_stack_t* stack;              /* Stack of frames */
-    prof_method_t* top;               /* The top method called in this thread */
 } thread_data_t;
 
 void rp_init_thread();
@@ -21,6 +20,7 @@ thread_data_t* switch_thread(void* prof, VALUE thread_id);
 void threads_table_free(st_table *table);
 VALUE prof_thread_wrap(thread_data_t *thread);
 void prof_thread_mark(thread_data_t *thread);
-
+int pause_thread(st_data_t key, st_data_t value, st_data_t data);
+int unpause_thread(st_data_t key, st_data_t value, st_data_t data);
 
 #endif //__RP_THREAD__

ext/ruby_prof/ruby_prof.c

@@ -116,10 +116,6 @@ static prof_method_t*
 
 	  method = create_method(event, klass, mid, source_file, line);
       method_table_insert(thread_data->method_table, method->key, method);
-
-	  /* Is this the first method added to the thread? */
-	  if (!thread_data->top)
-		  thread_data->top = method;
     }
     return method;
 }

lib/ruby-prof.rb

@@ -15,6 +15,7 @@
 require 'ruby-prof/method_info'
 require 'ruby-prof/profile'
 require 'ruby-prof/rack'
+require 'ruby-prof/thread'
 
 require 'ruby-prof/printers/abstract_printer'
 require 'ruby-prof/printers/call_info_printer'

lib/ruby-prof/call_info_visitor.rb

@@ -26,8 +26,10 @@ def initialize(thread)
     def visit(&block)
       @block = block
 
-      self.thread.top_method.call_infos.each do |call_info|
-        self.visit_call_info(call_info)
+      self.thread.top_methods.each do |method_info|
+        method_info.call_infos.each do |call_info|
+          self.visit_call_info(call_info)
+        end
       end
     end
 

lib/ruby-prof/printers/call_info_printer.rb

@@ -12,7 +12,7 @@ class CallInfoPrinter < AbstractPrinter
 
     def print_header(thread)
       @output << "Thread ID: #{thread.id}\n"
-      @output << "Total Time: #{thread.top_method.total_time}\n"
+      @output << "Total Time: #{thread.total_time}\n"
       @output << "Sort by: #{sort_method}\n"
       @output << "\n"
     end

lib/ruby-prof/printers/call_stack_printer.rb

@@ -45,20 +45,20 @@ def print(output = STDOUT, options = {})
       print_header
 
       @overall_threads_time = @result.threads.inject(0) do |val, thread|
-        val += thread.top_method.total_time
+        val += thread.total_time
       end
 
       @result.threads.each do |thread|
         @current_thread_id = thread.id
-        @overall_time = thread.top_method.total_time
+        @overall_time = thread.total_time
         @output.print "<div class=\"thread\">Thread: #{thread.id} (#{"%4.2f%%" % ((@overall_time/@overall_threads_time)*100)} ~ #{@overall_time})</div>"
         @output.print "<ul name=\"thread\">"
         thread.methods.each do |m|
           # $stderr.print m.dump
           next unless m.root?
           m.call_infos.each do |ci|
             next unless ci.root?
-            print_stack ci, thread.top_method.total_time
+            print_stack ci, thread.total_time
           end
         end
         @output.print "</ul>"

lib/ruby-prof/printers/dot_printer.rb

@@ -79,7 +79,7 @@ def dot_id(subject)
     end
 
     def print_thread(thread)
-      total_time = thread.top_method.total_time
+      total_time = thread.total_time
       thread.methods.sort_by(&sort_method).reverse_each do |method|
         total_percentage = (method.total_time/total_time) * 100
 

lib/ruby-prof/printers/flat_printer.rb

@@ -28,14 +28,14 @@ def sort_method
 
     def print_header(thread)
       @output << "Thread ID: %d\n" % thread.id
-      @output << "Total: %0.6f\n" % thread.top_method.total_time
+      @output << "Total: %0.6f\n" % thread.total_time
       @output << "Sort by: #{sort_method}\n"
       @output << "\n"
-      @output << " %self     total     self     wait    child    calls   name\n"
+      @output << " %self      total      self      wait     child     calls  name\n"
     end
 
     def print_methods(thread)
-      total_time = thread.top_method.total_time
+      total_time = thread.total_time
       methods = thread.methods.sort_by(&sort_method).reverse
 
       sum = 0
@@ -47,7 +47,7 @@ def print_methods(thread)
         #self_time_called = method.called > 0 ? method.self_time/method.called : 0
         #total_time_called = method.called > 0? method.total_time/method.called : 0
 
-        @output << "%6.2f  %8.2f %8.2f %8.2f %8.2f %8d  %s%s \n" % [
+        @output << "%6.2f  %9.3f %9.3f %9.3f %9.3f %8d  %s%s \n" % [
                       method.self_time / total_time * 100, # %self
                       method.total_time,                   # total
                       method.self_time,                    # self