[ruby-dev:25917] fast profiler
From:
Shugo Maeda <shugo@...>
Date:
2005-03-15 08:15:27 UTC
List:
ruby-dev #25917
前田です。 Shugo Maeda wrote: >>>パッチを当ててもよいですが、せっかく手を入れるんなら複数のイ >>>ベントフックを登録したいような気がするんですが、どう思います >>>か？ >> >> >>そう思いつつ手を抜いていました。手が空いたら書き直します。 > > > 実装してみました。 > パッチを添付します。 1.8用のパッチも用意してみました。 ちなみに、 $ svn co http://svn.shugo.net/src/ruby-prof/trunk/ ruby-prof でプロファイラを取得できます。 パッチ(ruby-1.8.diffかruby-1.9.diff)をあててたRubyで、 $ ruby extconf.rb $ make # make install でインストールできます。 プロファイルを取るには、 $ ruby -v -r doprof ~/ruby/fib.rb ruby 1.8.2 (2005-03-14) [i686-linux] use clock(3) for profiling 6765 %% cumulative self self total time seconds seconds calls ms/call ms/call name 71.43 0.10 0.10 21891 0.00 0.09 Object#fib 14.29 0.12 0.02 21890 0.00 0.00 Fixnum#- 7.14 0.13 0.01 21891 0.00 0.00 Fixnum#< 7.14 0.14 0.01 10945 0.00 0.00 Fixnum#+ 0.00 0.14 0.00 2 0.00 0.00 IO#write 0.00 0.14 0.00 1 0.00 140.00 #toplevel 0.00 0.14 0.00 1 0.00 0.00 Kernel.print 0.00 0.14 0.00 1 0.00 0.00 Fixnum#to_s 0.00 0.14 0.00 1 0.00 0.00 Module#method_added のようにdoprof.rbをrequireするだけでOKです。 デフォルトではclock(3)を使いますが、環境変数RUBY_PROF_CLOCK_MODEの 値によって $ export RUBY_PROF_CLOCK_MODE=gettimeofday ならgettimeofday(2)を、 $ export RUBY_PROF_CLOCK_MODE=cpu ならCPUのクロックカウンタを使います(現状ではPentiumとPowerPCのみ対応)。 -- 前田 修吾
Attachments (1)
ruby-1.8.diff
(8.93 KB, text/x-diff)
Index: eval.c
===================================================================
RCS file: /var/cvs/src/ruby/eval.c,v
retrieving revision 1.616.2.85
diff -u -p -r1.616.2.85 eval.c
--- eval.c 8 Mar 2005 09:56:18 -0000 1.616.2.85
+++ eval.c 15 Mar 2005 08:08:06 -0000
@@ -1017,9 +1017,27 @@ static VALUE module_setup _((VALUE,NODE*
static VALUE massign _((VALUE,NODE*,VALUE,int));
static void assign _((VALUE,NODE*,VALUE,int));
+typedef struct event_hook {
+ rb_event_hook_func_t func;
+ rb_event_t events;
+ struct event_hook *next;
+} rb_event_hook_t;
+
+static rb_event_hook_t *event_hooks;
+
+#define EXEC_EVENT_HOOK(event, node, self, id, klass) \
+ do { \
+ rb_event_hook_t *hook; \
+ \
+ for (hook = event_hooks; hook; hook = hook->next) { \
+ if (hook->events & event) \
+ (*hook->func)(event, node, self, id, klass); \
+ } \
+ } while (0)
+
static VALUE trace_func = 0;
static int tracing = 0;
-static void call_trace_func _((char*,NODE*,VALUE,ID,VALUE));
+static void call_trace_func _((rb_event_t,NODE*,VALUE,ID,VALUE));
#if 0
#define SET_CURRENT_SOURCE() (ruby_sourcefile = ruby_current_node->nd_file, \
@@ -2384,6 +2402,42 @@ rb_obj_is_proc(proc)
return Qfalse;
}
+void
+rb_add_event_hook(rb_event_hook_func_t func, rb_event_t events)
+{
+ rb_event_hook_t *hook;
+
+ hook = ALLOC(rb_event_hook_t);
+ hook->func = func;
+ hook->events = events;
+ hook->next = event_hooks;
+ event_hooks = hook;
+}
+
+int
+rb_remove_event_hook(rb_event_hook_func_t func)
+{
+ rb_event_hook_t *prev, *hook;
+
+ prev = NULL;
+ hook = event_hooks;
+ while (hook) {
+ if (hook->func == func) {
+ if (prev) {
+ prev->next = hook->next;
+ }
+ else {
+ event_hooks = hook->next;
+ }
+ xfree(hook);
+ return 0;
+ }
+ prev = hook;
+ hook = hook->next;
+ }
+ return -1;
+}
+
/*
* call-seq:
* set_trace_func(proc) => proc
@@ -2432,19 +2486,53 @@ static VALUE
set_trace_func(obj, trace)
VALUE obj, trace;
{
+ rb_event_hook_t *hook;
+
if (NIL_P(trace)) {
trace_func = 0;
+ rb_remove_event_hook(call_trace_func);
return Qnil;
}
if (!rb_obj_is_proc(trace)) {
rb_raise(rb_eTypeError, "trace_func needs to be Proc");
}
- return trace_func = trace;
+ trace_func = trace;
+ for (hook = event_hooks; hook; hook = hook->next) {
+ if (hook->func == call_trace_func)
+ return trace;
+ }
+ rb_add_event_hook(call_trace_func, RUBY_EVENT_ALL);
+ return trace;
+}
+
+static char *
+get_event_name(rb_event_t event)
+{
+ switch (event) {
+ case RUBY_EVENT_LINE:
+ return "line";
+ case RUBY_EVENT_CLASS:
+ return "class";
+ case RUBY_EVENT_END:
+ return "end";
+ case RUBY_EVENT_CALL:
+ return "call";
+ case RUBY_EVENT_RETURN:
+ return "return";
+ case RUBY_EVENT_C_CALL:
+ return "c-call";
+ case RUBY_EVENT_C_RETURN:
+ return "c-return";
+ case RUBY_EVENT_RAISE:
+ return "raise";
+ default:
+ return "unknown";
+ }
}
static void
call_trace_func(event, node, self, id, klass)
- char *event;
+ rb_event_t event;
NODE *node;
VALUE self;
ID id;
@@ -2454,6 +2542,7 @@ call_trace_func(event, node, self, id, k
struct FRAME *prev;
NODE *node_save;
VALUE srcfile;
+ char *event_name;
if (!trace_func) return;
if (tracing) return;
@@ -2488,7 +2577,8 @@ call_trace_func(event, node, self, id, k
raised = thread_reset_raised();
if ((state = EXEC_TAG()) == 0) {
srcfile = rb_str_new2(ruby_sourcefile?ruby_sourcefile:"(ruby)");
- proc_invoke(trace_func, rb_ary_new3(6, rb_str_new2(event),
+ event_name = get_event_name(event);
+ proc_invoke(trace_func, rb_ary_new3(6, rb_str_new2(event_name),
srcfile,
INT2FIX(ruby_sourceline),
id?ID2SYM(id):Qnil,
@@ -2769,11 +2859,9 @@ rb_eval(self, n)
RETURN(Qfalse);
case NODE_IF:
- if (trace_func) {
- call_trace_func("line", node, self,
- ruby_frame->last_func,
- ruby_frame->last_class);
- }
+ EXEC_EVENT_HOOK(RUBY_EVENT_LINE, node, self,
+ ruby_frame->last_func,
+ ruby_frame->last_class);
if (RTEST(rb_eval(self, node->nd_cond))) {
node = node->nd_body;
}
@@ -2789,11 +2877,9 @@ rb_eval(self, n)
if (nd_type(node) != NODE_WHEN) goto again;
tag = node->nd_head;
while (tag) {
- if (trace_func) {
- call_trace_func("line", tag, self,
- ruby_frame->last_func,
- ruby_frame->last_class);
- }
+ EXEC_EVENT_HOOK(RUBY_EVENT_LINE, tag, self,
+ ruby_frame->last_func,
+ ruby_frame->last_class);
if (tag->nd_head && nd_type(tag->nd_head) == NODE_WHEN) {
VALUE v = rb_eval(self, tag->nd_head->nd_head);
long i;
@@ -2832,11 +2918,9 @@ rb_eval(self, n)
}
tag = node->nd_head;
while (tag) {
- if (trace_func) {
- call_trace_func("line", tag, self,
- ruby_frame->last_func,
- ruby_frame->last_class);
- }
+ EXEC_EVENT_HOOK(RUBY_EVENT_LINE, tag, self,
+ ruby_frame->last_func,
+ ruby_frame->last_class);
if (tag->nd_head && nd_type(tag->nd_head) == NODE_WHEN) {
VALUE v = rb_eval(self, tag->nd_head->nd_head);
long i;
@@ -3875,11 +3959,9 @@ rb_eval(self, n)
break;
case NODE_NEWLINE:
- if (trace_func) {
- call_trace_func("line", node, self,
- ruby_frame->last_func,
- ruby_frame->last_class);
- }
+ EXEC_EVENT_HOOK(RUBY_EVENT_LINE, node, self,
+ ruby_frame->last_func,
+ ruby_frame->last_class);
node = node->nd_next;
goto again;
@@ -3930,9 +4012,8 @@ module_setup(module, n)
PUSH_CREF(module);
PUSH_TAG(PROT_NONE);
if ((state = EXEC_TAG()) == 0) {
- if (trace_func) {
- call_trace_func("class", n, ruby_cbase, ruby_frame->last_func, ruby_frame->last_class);
- }
+ EXEC_EVENT_HOOK(RUBY_EVENT_CLASS, n, ruby_cbase,
+ ruby_frame->last_func, ruby_frame->last_class);
result = rb_eval(ruby_cbase, node->nd_next);
}
POP_TAG();
@@ -3942,9 +4023,8 @@ module_setup(module, n)
POP_CLASS();
ruby_frame = frame.tmp;
- if (trace_func) {
- call_trace_func("end", n, 0, ruby_frame->last_func, ruby_frame->last_class);
- }
+ EXEC_EVENT_HOOK(RUBY_EVENT_END, n, 0,
+ ruby_frame->last_func, ruby_frame->last_class);
if (state) JUMP_TAG(state);
return result;
@@ -4339,8 +4419,8 @@ rb_longjmp(tag, mesg)
}
rb_trap_restore_mask();
- if (trace_func && tag != TAG_FATAL) {
- call_trace_func("raise", ruby_current_node,
+ if (tag != TAG_FATAL) {
+ EXEC_EVENT_HOOK(RUBY_EVENT_RAISE, ruby_current_node,
ruby_frame->self,
ruby_frame->last_func,
ruby_frame->last_class);
@@ -5506,17 +5586,19 @@ rb_call0(klass, recv, id, oid, argc, arg
rb_bug("bad argc (%d) specified for `%s(%s)'",
len, rb_class2name(klass), rb_id2name(id));
}
- if (trace_func) {
+ if (event_hooks) {
int state;
- call_trace_func("c-call", ruby_current_node, recv, id, klass);
+ EXEC_EVENT_HOOK(RUBY_EVENT_C_CALL, ruby_current_node,
+ recv, id, klass);
PUSH_TAG(PROT_FUNC);
if ((state = EXEC_TAG()) == 0) {
result = call_cfunc(body->nd_cfnc, recv, len, argc, argv);
}
POP_TAG();
ruby_current_node = ruby_frame->node;
- call_trace_func("c-return", ruby_current_node, recv, id, klass);
+ EXEC_EVENT_HOOK(RUBY_EVENT_C_RETURN, ruby_current_node,
+ recv, id, klass);
if (state) JUMP_TAG(state);
}
else {
@@ -5645,9 +5727,7 @@ rb_call0(klass, recv, id, oid, argc, arg
}
}
- if (trace_func) {
- call_trace_func("call", b2, recv, id, klass);
- }
+ EXEC_EVENT_HOOK(RUBY_EVENT_CALL, b2, recv, id, klass);
result = rb_eval(recv, body);
}
else if (state == TAG_RETURN && TAG_DST()) {
@@ -5659,9 +5739,8 @@ rb_call0(klass, recv, id, oid, argc, arg
POP_CLASS();
POP_SCOPE();
ruby_cref = saved_cref;
- if (trace_func) {
- call_trace_func("return", ruby_frame->prev->node, recv, id, klass);
- }
+ EXEC_EVENT_HOOK(RUBY_EVENT_RETURN, ruby_frame->prev->node,
+ recv, id, klass);
switch (state) {
case 0:
break;
Index: node.h
===================================================================
RCS file: /var/cvs/src/ruby/node.h,v
retrieving revision 1.50.2.2
diff -u -p -r1.50.2.2 node.h
--- node.h 2 Oct 2004 11:34:29 -0000 1.50.2.2
+++ node.h 15 Mar 2005 08:08:07 -0000
@@ -359,6 +359,23 @@ VALUE rb_gvar_get _((struct global_entry
VALUE rb_gvar_set _((struct global_entry *, VALUE));
VALUE rb_gvar_defined _((struct global_entry *));
+typedef unsigned int rb_event_t;
+
+#define RUBY_EVENT_NONE 0x00
+#define RUBY_EVENT_LINE 0x01
+#define RUBY_EVENT_CLASS 0x02
+#define RUBY_EVENT_END 0x04
+#define RUBY_EVENT_CALL 0x08
+#define RUBY_EVENT_RETURN 0x10
+#define RUBY_EVENT_C_CALL 0x20
+#define RUBY_EVENT_C_RETURN 0x40
+#define RUBY_EVENT_RAISE 0x80
+#define RUBY_EVENT_ALL 0xff
+
+typedef void (*rb_event_hook_func_t)_((rb_event_t,NODE*,VALUE,ID,VALUE));
+void rb_add_event_hook(rb_event_hook_func_t,rb_event_t);
+int rb_remove_event_hook(rb_event_hook_func_t);
+
#if defined(__cplusplus)
} /* extern "C" { */
#endif