Skip to content

Comparing changes

Choose two branches to see what’s changed or to start a new pull request. If you need to, you can also compare across forks.

Open a pull request

Create a new pull request by comparing changes across two branches. If you need to, you can also compare across forks.
...
  • 14 commits
  • 19 files changed
  • 0 commit comments
  • 2 contributors
View
2 .gitignore
@@ -9,3 +9,5 @@ pkg/
/.idea
*.bundle
*.so
+tmp
+.*.swp
View
3 Gemfile
@@ -0,0 +1,3 @@
+source :rubygems
+gem 'rake'
+gem 'rake-compiler'
View
13 Gemfile.lock
@@ -0,0 +1,13 @@
+GEM
+ remote: http://rubygems.org/
+ specs:
+ rake (0.9.2.2)
+ rake-compiler (0.8.1)
+ rake
+
+PLATFORMS
+ ruby
+
+DEPENDENCIES
+ rake
+ rake-compiler
View
16 ext/ruby_prof/rp_stack.c
@@ -5,6 +5,22 @@
#define INITIAL_STACK_SIZE 8
+inline void
+frame_pause(prof_frame_t *frame, double current_measurement)
+{
+ if (frame && frame_is_unpaused(frame))
+ frame->pause_time = current_measurement;
+}
+
+inline void
+frame_unpause(prof_frame_t *frame, double current_measurement)
+{
+ if (frame && frame_is_paused(frame)) {
+ frame->dead_time += (current_measurement - frame->pause_time);
+ frame->pause_time = -1;
+ }
+}
+
/* Creates a stack of prof_frame_t to keep track
of timings for active methods. */
View
8 ext/ruby_prof/rp_stack.h
@@ -22,10 +22,18 @@ typedef struct
double switch_time; /* Time at switch to different thread */
double wait_time;
double child_time;
+ double pause_time; // Time pause() was initiated
+ double dead_time; // Time to ignore (i.e. total amount of time between pause/resume blocks)
int depth;
unsigned int line;
} prof_frame_t;
+#define frame_is_paused(f) (f->pause_time >= 0)
+#define frame_is_unpaused(f) (f->pause_time < 0)
+inline void frame_pause(prof_frame_t*, double current_measurement);
+inline void frame_unpause(prof_frame_t*, double current_measurement);
+
+
/* Current stack of active methods.*/
typedef struct
{
View
81 ext/ruby_prof/ruby_prof.c
@@ -133,6 +133,7 @@ pop_frame(prof_profile_t* profile, thread_data_t *thread_data)
double measurement = profile->measurer->measure();
double total_time;
double self_time;
+ _Bool frame_paused;
frame = stack_pop(thread_data->stack); // only time it's called
@@ -140,11 +141,13 @@ pop_frame(prof_profile_t* profile, thread_data_t *thread_data)
a method that exits. And it can happen if an exception is raised
in code that is being profiled and the stack unwinds (RubyProf is
not notified of that by the ruby runtime. */
- if (frame == NULL)
+ if (frame == NULL)
return NULL;
/* Calculate the total time this method took */
- total_time = measurement - frame->start_time;
+ frame_paused = frame_is_paused(frame);
+ frame_unpause(frame, measurement);
+ total_time = measurement - frame->start_time - frame->dead_time;
self_time = total_time - frame->child_time - frame->wait_time;
/* Update information about the current method */
@@ -158,6 +161,12 @@ pop_frame(prof_profile_t* profile, thread_data_t *thread_data)
if (parent_frame)
{
parent_frame->child_time += total_time;
+ parent_frame->dead_time += frame->dead_time;
+
+ // Repause parent if currently paused
+ if (frame_paused)
+ frame_pause(parent_frame, measurement);
+
call_info->line = parent_frame->line;
}
@@ -333,6 +342,11 @@ prof_event_hook(rb_event_flag_t event, NODE *node, VALUE self, ID mid, VALUE kla
call_info_table_insert(frame->call_info->call_infos, method->key, call_info);
prof_add_call_info(method->call_infos, call_info);
}
+
+ // Unpause the parent frame. If currently paused then:
+ // 1) The child frame will begin paused.
+ // 2) The parent will inherit the child's dead time.
+ frame_unpause(frame, measurement);
}
/* Push a new frame onto the stack for a new c-call or ruby call (into a method) */
@@ -340,6 +354,8 @@ prof_event_hook(rb_event_flag_t event, NODE *node, VALUE self, ID mid, VALUE kla
frame->call_info = call_info;
frame->call_info->depth = frame->depth;
frame->start_time = measurement;
+ frame->pause_time = profile->paused == Qtrue ? measurement : -1;
+ frame->dead_time = 0;
frame->line = rb_sourceline();
break;
}
@@ -497,6 +513,39 @@ prof_initialize(int argc, VALUE *argv, VALUE self)
return self;
}
+static int pause_thread(st_data_t key, st_data_t value, st_data_t data) {
+ VALUE thread_id = (VALUE)key;
+ thread_data_t* thread_data = (thread_data_t *) value;
+ prof_profile_t* profile = (prof_profile_t*) data;
+
+ prof_frame_t* frame = stack_peek(thread_data->stack);
+ frame_pause(frame, profile->measurement_at_pause_resume);
+
+ return ST_CONTINUE;
+}
+
+static int unpause_thread(st_data_t key, st_data_t value, st_data_t data) {
+ VALUE thread_id = (VALUE)key;
+ thread_data_t* thread_data = (thread_data_t *) value;
+ prof_profile_t* profile = (prof_profile_t*) data;
+
+ prof_frame_t* frame = stack_peek(thread_data->stack);
+ frame_unpause(frame, profile->measurement_at_pause_resume);
+
+ return ST_CONTINUE;
+}
+
+/* call-seq:
+ paused? -> boolean
+
+ Returns whether a profile is currently paused.*/
+static VALUE
+prof_paused(VALUE self)
+{
+ prof_profile_t* profile = prof_get_profile(self);
+ return profile->paused;
+}
+
/* call-seq:
running? -> boolean
@@ -524,6 +573,7 @@ prof_start(VALUE self)
}
profile->running = Qtrue;
+ profile->paused = Qfalse;
profile->last_thread_data = NULL;
@@ -562,9 +612,13 @@ prof_pause(VALUE self)
rb_raise(rb_eRuntimeError, "RubyProf is not running.");
}
- profile->running = Qfalse;
+ if (profile->paused == Qfalse)
+ {
+ profile->paused = Qtrue;
+ profile->measurement_at_pause_resume = profile->measurer->measure();
+ st_foreach(profile->threads_tbl, pause_thread, (st_data_t) profile);
+ }
- prof_remove_hook();
return self;
}
@@ -578,20 +632,17 @@ prof_resume(VALUE self)
prof_profile_t* profile = prof_get_profile(self);
if (profile->running == Qfalse)
{
- prof_start(self);
- }
- else
- {
- profile->running = Qtrue;
- prof_install_hook(self);
+ rb_raise(rb_eRuntimeError, "RubyProf is not running.");
}
- if (rb_block_given_p())
+ if (profile->paused == Qtrue)
{
- rb_ensure(rb_yield, self, prof_pause, self);
+ profile->paused = Qfalse;
+ profile->measurement_at_pause_resume = profile->measurer->measure();
+ st_foreach(profile->threads_tbl, unpause_thread, (st_data_t) profile);
}
- return self;
+ return rb_block_given_p() ? rb_ensure(rb_yield, self, prof_pause, self) : self;
}
/* call-seq:
@@ -628,7 +679,7 @@ prof_stop(VALUE self)
/* Unset the last_thread_data (very important!)
and the threads table */
- profile->running = Qfalse;
+ profile->running = profile->paused = Qfalse;
profile->last_thread_data = NULL;
/* Post process result */
@@ -686,10 +737,10 @@ void Init_ruby_prof()
rb_define_alloc_func (cProfile, prof_allocate);
rb_define_method(cProfile, "initialize", prof_initialize, -1);
rb_define_method(cProfile, "start", prof_start, 0);
- rb_define_method(cProfile, "start", prof_start, 0);
rb_define_method(cProfile, "stop", prof_stop, 0);
rb_define_method(cProfile, "resume", prof_resume, 0);
rb_define_method(cProfile, "pause", prof_pause, 0);
rb_define_method(cProfile, "running?", prof_running, 0);
+ rb_define_method(cProfile, "paused?", prof_paused, 0);
rb_define_method(cProfile, "threads", prof_threads, 0);
}
View
2 ext/ruby_prof/ruby_prof.h
@@ -42,11 +42,13 @@ void method_key(prof_method_key_t* key, VALUE klass, ID mid);
typedef struct
{
VALUE running;
+ VALUE paused;
prof_measurer_t* measurer;
VALUE threads;
st_table* threads_tbl;
st_table* exclude_threads_tbl;
thread_data_t* last_thread_data;
+ double measurement_at_pause_resume;
} prof_profile_t;
View
2 lib/ruby-prof/compatibility.rb
@@ -148,7 +148,7 @@ def self.enable_gc_stats_if_needed
end
def self.disable_gc_stats_if_needed(was_enabled=nil)
- was_enabled ||= @gc_stat_was_enabled
+ was_enabled ||= defined?(@gc_stat_was_enabled) && @gc_stat_was_enabled
GC.disable_stats if self.measure_mode == RubyProf::MEMORY && GC.respond_to?(:disable_stats) && !was_enabled
end
end
View
2 lib/ruby-prof/printers/flat_printer.rb
@@ -62,7 +62,7 @@ def print_methods(thread)
def print_footer(thread)
@output << "\n"
- @output << "* in front of method name means it is recursively called\n"
+ @output << "* indicates recursively called methods\n"
end
end
end
View
2 lib/ruby-prof/printers/graph_html_printer.rb
@@ -235,7 +235,7 @@ def template
</tbody>
<tfoot>
<tr>
- <td colspan="9">* in front of method name means it is recursively called</td>
+ <td colspan="9">* indicates recursively called methods</td>
</tr>
</tfoot>
</table>
View
2 lib/ruby-prof/printers/graph_printer.rb
@@ -109,7 +109,7 @@ def print_children(method)
def print_footer(thread)
@output << "\n"
- @output << "* in front of method name means it is recursively called\n"
+ @output << "* indicates recursively called methods\n"
end
end
end
View
56 test/basic_test.rb
@@ -39,4 +39,58 @@ def test_traceback
RubyProf.stop
end
-end
+
+ def test_pause_seq
+ p= RubyProf::Profile.new(RubyProf::WALL_TIME,[])
+ p.start ; refute p.paused?
+ p.pause ; assert p.paused?
+ p.resume; refute p.paused?
+ p.pause ; assert p.paused?
+ p.pause ; assert p.paused?
+ p.resume; refute p.paused?
+ p.resume; refute p.paused?
+ p.stop ; refute p.paused?
+ end
+
+ def test_pause_block
+ p= RubyProf::Profile.new(RubyProf::WALL_TIME,[])
+ p.start
+ p.pause
+ assert p.paused?
+
+ times_block_invoked = 0
+ retval= p.resume{
+ times_block_invoked += 1
+ 120 + times_block_invoked
+ }
+ assert_equal 1, times_block_invoked
+ assert p.paused?
+
+ assert_equal 121, retval, "resume() should return the result of the given block."
+
+ p.stop
+ end
+
+ def test_pause_block_with_error
+ p= RubyProf::Profile.new(RubyProf::WALL_TIME,[])
+ p.start
+ p.pause
+ assert p.paused?
+
+ begin
+ p.resume{ raise }
+ flunk 'Exception expected.'
+ rescue
+ assert p.paused?
+ end
+
+ p.stop
+ end
+
+ def test_resume_when_not_paused
+ p= RubyProf::Profile.new(RubyProf::WALL_TIME,[])
+ p.start ; refute p.paused?
+ p.resume; refute p.paused?
+ p.stop ; refute p.paused?
+ end
+end
View
10 test/line_number_test.rb
@@ -5,11 +5,9 @@
class LineNumbers
def method1
- 3
end
def method2
- 3
method1
end
@@ -32,11 +30,11 @@ def test_function_line_no
method = methods[0]
assert_equal('LineNumbersTest#test_function_line_no', method.full_name)
- assert_equal(27, method.line)
+ assert_equal(25, method.line)
method = methods[1]
assert_equal('LineNumbers#method2', method.full_name)
- assert_equal(11, method.line)
+ assert_equal(10, method.line)
method = methods[2]
assert_equal('LineNumbers#method1', method.full_name)
@@ -64,10 +62,10 @@ def test_c_function
method = methods[1]
assert_equal('LineNumbers#method3', method.full_name)
- assert_equal(16, method.line)
+ assert_equal(14, method.line)
method = methods[2]
assert_equal('LineNumbersTest#test_c_function', method.full_name)
- assert_equal(50, method.line)
+ assert_equal(48, method.line)
end
end
View
1 test/multi_printer_test.rb
@@ -57,7 +57,6 @@ def test_all_profiles_can_be_created
\s*</table>')
assert graph =~ re
display_time = $1.to_f
- difference = (expected_time-display_time).abs
assert_in_delta expected_time, display_time, 0.005
end
View
61 test/pause_resume_test.rb
@@ -0,0 +1,61 @@
+#!/usr/bin/env ruby
+# encoding: UTF-8
+
+require File.expand_path('../test_helper', __FILE__)
+
+class PauseResumeTest < Test::Unit::TestCase
+
+ # pause/resume in the same frame
+ def test_pause_resume_1
+ p= RubyProf::Profile.new(RubyProf::WALL_TIME,[])
+
+ p.start
+ method_1a
+
+ p.pause
+ method_1b
+
+ p.resume
+ method_1c
+
+ r= p.stop
+ assert_in_delta(0.6, r.threads[0].methods.select{|m| m.full_name =~ /test_pause_resume_1$/}[0].total_time, 0.05)
+ end
+ def method_1a; sleep 0.2 end
+ def method_1b; sleep 1 end
+ def method_1c; sleep 0.4 end
+
+ # pause in parent frame, resume in child
+ def test_pause_resume_2
+ p= RubyProf::Profile.new(RubyProf::WALL_TIME,[])
+
+ p.start
+ method_2a
+
+ p.pause
+ sleep 0.5
+ method_2b(p)
+
+ r= p.stop
+ assert_in_delta(0.6, r.threads[0].methods.select{|m| m.full_name =~ /test_pause_resume_2$/}[0].total_time, 0.05)
+ end
+ def method_2a; sleep 0.2 end
+ def method_2b(p); sleep 0.5; p.resume; sleep 0.4 end
+
+ # pause in child frame, resume in parent
+ def test_pause_resume_3
+ p= RubyProf::Profile.new(RubyProf::WALL_TIME,[])
+
+ p.start
+ method_3a(p)
+
+ sleep 0.5
+ p.resume
+ method_3b
+
+ r= p.stop
+ assert_in_delta(0.6, r.threads[0].methods.select{|m| m.full_name =~ /test_pause_resume_3$/}[0].total_time, 0.05)
+ end
+ def method_3a(p); sleep 0.2; p.pause; sleep 0.5 end
+ def method_3b; sleep 0.4 end
+end
View
2 test/prime.rb
@@ -51,5 +51,5 @@ def run_primes(length=10, maxnum=1000)
primes = find_primes(random_array)
# Find the largest primes
- # largest = find_largest(primes)
+ largest = find_largest(primes)
end
View
2 test/prime_test.rb
@@ -6,7 +6,7 @@
# -- Tests ----
class PrimeTest< Test::Unit::TestCase
def test_consistency
- result = RubyProf.profile do
+ RubyProf.profile do
run_primes
end
end
View
10 test/thread_test.rb
@@ -25,14 +25,14 @@ def test_thread_count
def test_thread_identity
RubyProf.start
- thread = Thread.new do
+ sleep_thread = Thread.new do
sleep(1)
end
- thread.join
+ sleep_thread.join
result = RubyProf.stop
thread_ids = result.threads.map {|thread| thread.id}.sort
- threads = [Thread.current, thread]
+ threads = [Thread.current, sleep_thread]
assert_equal(2, result.threads.length)
assert(thread_ids.include?(threads[0].object_id))
@@ -164,9 +164,9 @@ def test_thread_back_and_forth
end
def test_thread
- result = RubyProf.profile do
+ RubyProf.profile do
begin
- status = Timeout::timeout(2) do
+ Timeout::timeout(2) do
while true
next
end
View
1 test/unique_call_path_test.rb
@@ -17,7 +17,6 @@ def method_b
end
def method_c
- c = 3
end
def method_k(i)

No commit comments for this range

Something went wrong with that request. Please try again.