ruby-changes:49012
From: ko1 <ko1@a...>
Date: Tue, 12 Dec 2017 09:51:33 +0900 (JST)
Subject: [ruby-changes:49012] ko1:r60763 (trunk): remove `trace` instruction. [Feature #14104]
ko1 2017-11-14 21:58:36 +0900 (Tue, 14 Nov 2017) New Revision: 60763 https://svn.ruby-lang.org/cgi-bin/viewvc.cgi?view=revision&revision=60763 Log: remove `trace` instruction. [Feature #14104] * tool/instruction.rb: create `trace_` prefix instructions. * compile.c (ADD_TRACE): do not add `trace` instructions but add TRACE link elements. TRACE elements will be unified with a next instruction as instruction information. * vm_trace.c (update_global_event_hook): modify all ISeqs when hooks are enabled. * iseq.c (rb_iseq_trace_set): added to toggle `trace_` instructions. * vm_insnhelper.c (vm_trace): added. This function is a body of `trace_` prefix instructions. * vm_insnhelper.h (JUMP): save PC to a control frame. * insns.def (trace): removed. * vm_exec.h (INSN_ENTRY_SIG): add debug output (disabled). Modified files: trunk/NEWS trunk/common.mk trunk/compile.c trunk/insns.def trunk/iseq.c trunk/iseq.h trunk/test/ruby/test_settracefunc.rb trunk/tool/instruction.rb trunk/vm_backtrace.c trunk/vm_exec.h trunk/vm_insnhelper.c trunk/vm_insnhelper.h trunk/vm_trace.c Index: common.mk =================================================================== --- common.mk (revision 60762) +++ common.mk (revision 60763) @@ -2904,6 +2904,7 @@ vm_trace.$(OBJEXT): {$(VPATH)}id.h https://github.com/ruby/ruby/blob/trunk/common.mk#L2904 vm_trace.$(OBJEXT): {$(VPATH)}intern.h vm_trace.$(OBJEXT): {$(VPATH)}internal.h vm_trace.$(OBJEXT): {$(VPATH)}io.h +vm_trace.$(OBJEXT): {$(VPATH)}iseq.h vm_trace.$(OBJEXT): {$(VPATH)}method.h vm_trace.$(OBJEXT): {$(VPATH)}missing.h vm_trace.$(OBJEXT): {$(VPATH)}node.h Index: tool/instruction.rb =================================================================== --- tool/instruction.rb (revision 60762) +++ tool/instruction.rb (revision 60763) @@ -33,6 +33,7 @@ class RubyVM https://github.com/ruby/ruby/blob/trunk/tool/instruction.rb#L33 @optimized = [] @is_sc = false @sp_inc = sp_inc + @trace = trace end def add_sc sci @@ -49,6 +50,7 @@ class RubyVM https://github.com/ruby/ruby/blob/trunk/tool/instruction.rb#L50 attr_reader :is_sc attr_reader :tvars attr_reader :sp_inc + attr_accessor :trace def set_sc @is_sc = true @@ -116,6 +118,7 @@ class RubyVM https://github.com/ruby/ruby/blob/trunk/tool/instruction.rb#L118 load_opt_operand_def opts[:"opope.def"] || 'defs/opt_operand.def' load_insn_unification_def opts[:"unif.def"] || 'defs/opt_insn_unif.def' make_stackcaching_insns if vm_opt?('STACK_CACHING') + make_trace_insns end attr_reader :vpath @@ -533,6 +536,21 @@ class RubyVM https://github.com/ruby/ruby/blob/trunk/tool/instruction.rb#L536 } end + def make_trace_insns + @insns.dup.each{|insn| + body = <<-EOS + vm_trace(ec, GET_CFP(), GET_PC()); + goto start_of_#{insn.name}; + EOS + + trace_insn = Instruction.new(name = "trace_#{insn.name}", + insn.opes, insn.pops, insn.rets, insn.comm, + body, insn.tvars, insn.sp_inc) + trace_insn.trace = true + add_insn trace_insn + } + end + def make_insn_sc orig_insn, name, opes, pops, rets, pushs, nextsc comm = orig_insn.comm.dup comm[:c] = 'optimize(sc)' @@ -866,27 +884,32 @@ class RubyVM https://github.com/ruby/ruby/blob/trunk/tool/instruction.rb#L884 end def make_header insn - commit "INSN_ENTRY(#{insn.name}){" + label = insn.trace ? '' : "start_of_#{insn.name}:;" + commit "INSN_ENTRY(#{insn.name}){#{label}" make_header_prepare_stack insn commit "{" - make_header_stack_val insn - make_header_default_operands insn - make_header_operands insn - make_header_stack_pops insn - make_header_temporary_vars insn - # - make_header_debug insn - make_header_pc insn - make_header_popn insn - make_header_defines insn - make_header_analysis insn + unless insn.trace + make_header_stack_val insn + make_header_default_operands insn + make_header_operands insn + make_header_stack_pops insn + make_header_temporary_vars insn + # + make_header_debug insn + make_header_pc insn + make_header_popn insn + make_header_defines insn + make_header_analysis insn + end commit "{" end def make_footer insn - make_footer_stack_val insn - make_footer_default_operands insn - make_footer_undefs insn + unless insn.trace + make_footer_stack_val insn + make_footer_default_operands insn + make_footer_undefs insn + end commit " END_INSN(#{insn.name});}}}" end Index: test/ruby/test_settracefunc.rb =================================================================== --- test/ruby/test_settracefunc.rb (revision 60762) +++ test/ruby/test_settracefunc.rb (revision 60763) @@ -77,7 +77,7 @@ class TestSetTraceFunc < Test::Unit::Tes https://github.com/ruby/ruby/blob/trunk/test/ruby/test_settracefunc.rb#L77 events.shift) assert_equal(["c-return", 5, :+, Integer], events.shift) - assert_equal(["return", 6, :add, self.class], + assert_equal(["return", 5, :add, self.class], events.shift) assert_equal(["line", 8, __method__, self.class], events.shift) @@ -116,7 +116,7 @@ class TestSetTraceFunc < Test::Unit::Tes https://github.com/ruby/ruby/blob/trunk/test/ruby/test_settracefunc.rb#L116 events.shift) assert_equal(["c-return", 5, :method_added, Module], events.shift) - assert_equal(["end", 7, nil, nil], + assert_equal(["end", 5, nil, nil], events.shift) assert_equal(["line", 8, __method__, self.class], events.shift) @@ -130,7 +130,7 @@ class TestSetTraceFunc < Test::Unit::Tes https://github.com/ruby/ruby/blob/trunk/test/ruby/test_settracefunc.rb#L130 events.shift) assert_equal(["call", 5, :bar, Foo], events.shift) - assert_equal(["return", 6, :bar, Foo], + assert_equal(["return", 5, :bar, Foo], events.shift) assert_equal(["line", 9, __method__, self.class], events.shift) @@ -176,7 +176,7 @@ class TestSetTraceFunc < Test::Unit::Tes https://github.com/ruby/ruby/blob/trunk/test/ruby/test_settracefunc.rb#L176 events.shift) assert_equal(["line", 5, :meth_return, self.class], events.shift) - assert_equal(["return", 7, :meth_return, self.class], + assert_equal(["return", 5, :meth_return, self.class], events.shift) assert_equal(["line", 10, :test_return, self.class], events.shift) @@ -215,7 +215,7 @@ class TestSetTraceFunc < Test::Unit::Tes https://github.com/ruby/ruby/blob/trunk/test/ruby/test_settracefunc.rb#L215 events.shift) assert_equal(["line", 6, :meth_return2, self.class], events.shift) - assert_equal(["return", 7, :meth_return2, self.class], + assert_equal(["return", 6, :meth_return2, self.class], events.shift) assert_equal(["line", 9, :test_return2, self.class], events.shift) @@ -239,8 +239,6 @@ class TestSetTraceFunc < Test::Unit::Tes https://github.com/ruby/ruby/blob/trunk/test/ruby/test_settracefunc.rb#L239 EOF assert_equal(["c-return", 1, :set_trace_func, Kernel], events.shift) - assert_equal(["line", 4, __method__, self.class], - events.shift) assert_equal(["line", 5, __method__, self.class], events.shift) assert_equal(["c-call", 5, :raise, Kernel], @@ -289,8 +287,8 @@ class TestSetTraceFunc < Test::Unit::Tes https://github.com/ruby/ruby/blob/trunk/test/ruby/test_settracefunc.rb#L287 ["line", 4, __method__, self.class], ["c-return", 4, :any?, Array], ["line", 5, __method__, self.class], - ["c-call", 5, :set_trace_func, Kernel]].each{|e| - assert_equal(e, events.shift) + ["c-call", 5, :set_trace_func, Kernel]].each.with_index{|e, i| + assert_equal(e, events.shift, "mismatch on #{i}th trace") } end @@ -345,7 +343,7 @@ class TestSetTraceFunc < Test::Unit::Tes https://github.com/ruby/ruby/blob/trunk/test/ruby/test_settracefunc.rb#L343 ["line", 4, nil, nil], ["c-call", 4, :method_added, Module], ["c-return", 4, :method_added, Module], - ["end", 7, nil, nil], + ["end", 4, nil, nil], ["line", 8, __method__, self.class], ["c-call", 8, :new, Class], ["c-call", 8, :initialize, BasicObject], @@ -355,7 +353,7 @@ class TestSetTraceFunc < Test::Unit::Tes https://github.com/ruby/ruby/blob/trunk/test/ruby/test_settracefunc.rb#L353 ["line", 5, :foo, ThreadTraceInnerClass], ["c-call", 5, :+, Integer], ["c-return", 5, :+, Integer], - ["return", 6, :foo, ThreadTraceInnerClass], + ["return", 5, :foo, ThreadTraceInnerClass], ["line", 9, __method__, self.class], ["c-call", 9, :set_trace_func, Thread]].each do |e| [:set, :add].each do |type| @@ -489,7 +487,7 @@ class TestSetTraceFunc < Test::Unit::Tes https://github.com/ruby/ruby/blob/trunk/test/ruby/test_settracefunc.rb#L487 [:line, 13, "xyzzy", nil, nil, xyzzy.class, :XYZZY_outer, :nothing], [:c_call, 13, "xyzzy", Module, :method_added, xyzzy.class, :XYZZY_outer, :nothing], [:c_return,13, "xyzzy", Module, :method_added, xyzzy.class, :XYZZY_outer, nil], - [:end, 17, "xyzzy", nil, nil, xyzzy.class, :XYZZY_outer, :nothing], + [:end, 13, "xyzzy", nil, nil, xyzzy.class, :XYZZY_outer, :nothing], [:line, 18, "xyzzy", TestSetTraceFunc, method, self, :outer, :nothing], [:c_call, 18, "xyzzy", Class, :new, xyzzy.class, :outer, :nothing], [:c_call, 18, "xyzzy", BasicObject, :initialize, xyzzy, :outer, :nothing], @@ -504,8 +502,8 @@ class TestSetTraceFunc < Test::Unit::Tes https://github.com/ruby/ruby/blob/trunk/test/ruby/test_settracefunc.rb#L502 [:line, 15, "xyzzy", xyzzy.class, :bar, xyzzy, :XYZZY_bar, :nothing], [:c_call, 15, "xyzzy", Kernel, :tap, xyzzy, :XYZZY_bar, :nothing], [:c_return,15, "xyzzy", Kernel, :tap, xyzzy, :XYZZY_bar, xyzzy], - [:return, 16, "xyzzy", xyzzy.class, :bar, xyzzy, :XYZZY_bar, xyzzy], - [:return, 12, "xyzzy", xyzzy.class, :foo, xyzzy, :XYZZY_foo, xyzzy], + [:return, 15, "xyzzy", xyzzy.class, :bar, xyzzy, :XYZZY_bar, xyzzy], + [:return, 11, "xyzzy", xyzzy.class, :foo, xyzzy, :XYZZY_foo, xyzzy], [:line, 20, "xyzzy", TestSetTraceFunc, method, self, :outer, :nothing], [:c_call, 20, "xyzzy", Kernel, :raise, self, :outer, :nothing], [:c_call, 20, "xyzzy", Exception, :exception, RuntimeError, :outer, :nothing], Index: vm_trace.c =================================================================== --- vm_trace.c (revision 60762) +++ vm_trace.c (revision 60763) @@ -25,6 +25,7 @@ https://github.com/ruby/ruby/blob/trunk/vm_trace.c#L25 #include "ruby/debug.h" #include "vm_core.h" +#include "iseq.h" #include "eval_intern.h" /* (1) trace mechanisms */ @@ -59,35 +60,44 @@ rb_vm_trace_mark_event_hooks(rb_hook_lis https://github.com/ruby/ruby/blob/trunk/vm_trace.c#L60 /* ruby_vm_event_flags management */ static void +update_global_event_hook(rb_event_flag_t vm_events) +{ + ruby_vm_event_flags = vm_events; + rb_iseq_trace_set_all(vm_events); + rb_objspace_set_event_hook(vm_events); +} + +static void recalc_add_ruby_vm_event_flags(rb_event_flag_t events) { int i; - ruby_vm_event_flags = 0; + rb_event_flag_t vm_events = 0; for (i=0; i<MAX_EVENT_NUM; i++) { if (events & ((rb_event_flag_t)1 << i)) { ruby_event_flag_count[i]++; } - ruby_vm_event_flags |= ruby_event_flag_count[i] ? (1<<i) : 0; + vm_events |= ruby_event_flag_count[i] ? (1<<i) : 0; } - rb_objspace_set_event_hook(ruby_vm_event_flags); + update_global_event_hook(vm_events); } static void recalc_remove_ruby_vm_event_flags(rb_event_flag_t events) { int i; - ruby_vm_event_flags = 0; + rb_event_flag_t vm_events = 0; for (i=0; i<MAX_EVENT_NUM; i++) { if (events & ((rb_event_flag_t)1 << i)) { + VM_ASSERT(ruby_event_flag_count[i] > 0); ruby_event_flag_count[i]--; } - ruby_vm_event_flags |= ruby_event_flag_count[i] ? (1<<i) : 0; + vm_events |= ruby_event_flag_count[i] ? (1<<i) : 0; } - rb_objspace_set_event_hook(ruby_vm_event_flags); + update_global_event_hook(vm_events); } /* add/remove hooks */ @@ -467,7 +477,6 @@ static void call_trace_func(rb_event_fla https://github.com/ruby/ruby/blob/trunk/vm_trace.c#L477 static VALUE set_trace_func(VALUE obj, VALUE trace) { - rb_remove_event_hook(call_trace_func); if (NIL_P(trace)) { @@ -581,15 +590,40 @@ get_event_id(rb_event_flag_t event) https://github.com/ruby/ruby/blob/trunk/vm_trace.c#L590 } static void +get_path_and_lineno(const rb_execution_context_t *ec, const rb_control_frame_t *cfp, rb_event_flag_t event, VALUE *pathp, int *linep) +{ + cfp = rb_vm_get_ruby_level_next_cfp(ec, cfp); + + if (cfp) { + const rb_iseq_t *iseq = cfp->iseq; + *pathp = rb_iseq_path(iseq); + + if (event & (RUBY_EVENT_CLASS | + RUBY_EVENT_CALL | + RUBY_EVENT_B_CALL)) { + *linep = FIX2INT(rb_iseq_first_lineno(iseq)); + } + else { + *linep = rb_vm_get_sourceline(cfp); + } + } + else { + *pathp = Qnil; + *linep = 0; + } +} + +static void call_trace_func(rb_event_flag_t event, VALUE proc, VALUE self, ID id, VALUE klass) { int line; - const char *srcfile = rb_source_loc(&line); + VALUE filename; VALUE eventname = rb_str_new2(get_event_name(event)); - VALUE filename = srcfile ? rb_str_new2(srcfile) : Qnil; VALUE argv[6]; const rb_execution_context_t *ec = GET_EC(); + get_path_and_lineno(ec, ec->cfp, event, &filename, &line); + if (!klass) { rb_ec_frame_method_id_and_class(ec, &id, 0, &klass); } @@ -607,7 +641,7 @@ call_trace_func(rb_event_flag_t event, V https://github.com/ruby/ruby/blob/trunk/vm_trace.c#L641 argv[1] = filename; argv[2] = INT2FIX(line); argv[3] = id ? ID2SYM(id) : Qnil; - argv[4] = (self && srcfile) ? rb_binding_new() : Qnil; + argv[4] = (self && (filename != Qnil)) ? rb_binding_new() : Qnil; argv[5] = klass ? klass : Qnil; rb_proc_call_with_block(proc, 6, argv, Qnil); @@ -725,16 +759,7 @@ static void https://github.com/ruby/ruby/blob/trunk/vm_trace.c#L759 fill_path_and_lineno(rb_trace_arg_t *trace_arg) { if (trace_arg->path == Qundef) { - rb_control_frame_t *cfp = rb_vm_get_ruby_level_next_cfp(trace_arg->ec, trace_arg->cfp); - - if (cfp) { - trace_arg->path = rb_iseq_path(cfp->iseq); - trace_arg->lineno = rb_vm_get_sourceline(cfp); - } - else { - trace_arg->path = Qnil; - trace_arg->lineno = 0; - } + get_path_and_lineno(trace_arg->ec, trace_arg->cfp, trace_arg->event, &trace_arg->path, &trace_arg->lineno); } } Index: vm_exec.h =================================================================== --- vm_exec.h (revision 60762) +++ vm_exec.h (revision 60763) @@ -74,8 +74,12 @@ error ! https://github.com/ruby/ruby/blob/trunk/vm_exec.h#L74 #define ELABEL(x) INSN_ELABEL_##x #define LABEL_PTR(x) &&LABEL(x) -#define INSN_ENTRY_SIG(insn) - +#define INSN_ENTRY_SIG(insn) \ + if (0) fprintf(stderr, "exec: %s@(%d, %d)@%s:%d\n", #insn, \ + (int)(reg_pc - reg_cfp->iseq->body->iseq_encoded), \ + (int)(reg_cfp->pc - reg_cfp->iseq->body->iseq_encoded), \ + RSTRING_PTR(rb_iseq_path(reg_cfp->iseq)), \ + (int)(rb_iseq_line_no(reg_cfp->iseq, reg_pc - reg_cfp->iseq->body->iseq_encoded))); #define INSN_DISPATCH_SIG(insn) Index: iseq.c =================================================================== --- iseq.c (revision 60762) +++ iseq.c (revision 60763) @@ -336,8 +336,10 @@ prepare_iseq_build(rb_iseq_t *iseq, https://github.com/ruby/ruby/blob/trunk/iseq.c#L336 return Qtrue; } +static void rb_iseq_trace_set(const rb_iseq_t *iseq, rb_event_flag_t turnon_events); + static VALUE -cleanup_iseq_build(rb_iseq_t *iseq) +finish_iseq_build(rb_iseq_t *iseq) { struct iseq_compile_data *data = ISEQ_COMPILE_DATA(iseq); VALUE err = data->err_info; @@ -350,6 +352,10 @@ cleanup_iseq_build(rb_iseq_t *iseq) https://github.com/ruby/ruby/blob/trunk/iseq.c#L352 rb_funcallv(err, rb_intern("set_backtrace"), 1, &path); rb_exc_raise(err); } + + if (ruby_vm_event_flags) { + rb_iseq_trace_set(iseq, ruby_vm_event_flags); + } return Qtrue; } @@ -503,7 +509,7 @@ rb_iseq_new_with_opt(const NODE *node, V https://github.com/ruby/ruby/blob/trunk/iseq.c#L509 prepare_iseq_build(iseq, name, path, realpath, first_lineno, parent, type, option); rb_iseq_compile_node(iseq, node); - cleanup_iseq_build(iseq); + finish_iseq_build(iseq); return iseq_translate(iseq); } @@ -606,7 +612,7 @@ iseq_load(VALUE data, const rb_iseq_t *p https://github.com/ruby/ruby/blob/trunk/iseq.c#L612 rb_iseq_build_from_ary(iseq, misc, locals, params, exception, body); - cleanup_iseq_build(iseq); + finish_iseq_build(iseq); return iseqw_new(iseq); } @@ -1265,6 +1271,18 @@ rb_iseq_line_no(const rb_iseq_t *iseq, s https://github.com/ruby/ruby/blob/trunk/iseq.c#L1271 } } +rb_event_flag_t +rb_iseq_event_flags(const rb_iseq_t *iseq, size_t pos) +{ + const struct iseq_insn_info_entry *entry = get_insn_info(iseq, pos); + if (entry) { + return entry->events; + } + else { + return 0; + } +} + static VALUE id_to_name(ID id, VALUE default_value) { @@ -1477,6 +1495,22 @@ rb_iseq_disasm_insn(VALUE ret, const VAL https://github.com/ruby/ruby/blob/trunk/iseq.c#L1495 } } + { + rb_event_flag_t events = rb_iseq_event_flags(iseq, pos); + if (events) { + str = rb_str_catf(str, "[%s%s%s%s%s%s%s%s%s]", + events & RUBY_EVENT_LINE ? "Li" : "", + events & RUBY_EVENT_CLASS ? "Cl" : "", + events & RUBY_EVENT_END ? "En" : "", + events & RUBY_EVENT_CALL ? "Ca" : "", + events & RUBY_EVENT_RETURN ? "Re" : "", + events & RUBY_EVENT_C_CALL ? "Cc" : "", + events & RUBY_EVENT_C_RETURN ? "Cr" : "", + events & RUBY_EVENT_B_CALL ? "Bc" : "", + events & RUBY_EVENT_B_RETURN ? "Br" : ""); + } + } + if (ret) { rb_str_cat2(str, "\n"); rb_str_concat(ret, str); @@ -1834,7 +1868,7 @@ iseq_data_to_ary(const rb_iseq_t *iseq) https://github.com/ruby/ruby/blob/trunk/iseq.c#L1868 long l; size_t ti; unsigned int pos; - unsigned int line = 0; + int last_line = 0; VALUE *seq, *iseq_original; VALUE val = rb_ary_new(); @@ -2095,10 +2129,27 @@ iseq_data_to_ary(const rb_iseq_t *iseq) https://github.com/ruby/ruby/blob/trunk/iseq.c#L2129 rb_ary_push(body, (VALUE)label); } - if (ti < iseq->body->insns_info_size && iseq->body->insns_info[ti].position == pos) { - line = iseq->body->insns_info[ti].line_no; - rb_ary_push(body, INT2FIX(line)); - ti++; + if (ti < iseq->body->insns_info_size) { + const struct iseq_insn_info_entry *info = &iseq->body->insns_info[ti]; + if (info->position == pos) { + int line = info->line_no; + rb_event_flag_t events = info->events; + + if (line > 0 && last_line != line) { + rb_ary_push(body, INT2FIX(line)); + last_line = line; + } +#define CHECK_EVENT(ev) if (events & ev) rb_ary_push(body, ID2SYM(rb_intern(#ev))); + CHECK_EVENT(RUBY_EVENT_LINE); + CHECK_EVENT(RUBY_EVENT_CLASS); + CHECK_EVENT(RUBY_EVENT_END); + CHECK_EVENT(RUBY_EVENT_CALL); + CHECK_EVENT(RUBY_EVENT_RETURN); + CHECK_EVENT(RUBY_EVENT_B_CALL); + CHECK_EVENT(RUBY_EVENT_B_RETURN); +#undef CHECK_EVENT + ti++; + } } rb_ary_push(body, ary); @@ -2112,7 +2163,6 @@ iseq_data_to_ary(const rb_iseq_t *iseq) https://github.com/ruby/ruby/blob/trunk/iseq.c#L2163 rb_hash_aset(misc, ID2SYM(rb_intern("local_size")), INT2FIX(iseq->body->local_table_size)); rb_hash_aset(misc, ID2SYM(rb_intern("stack_max")), INT2FIX(iseq->body->stack_max)); - /* TODO: compatibility issue */ /* * [:magic, :major_version, :minor_version, :format_type, :misc, * :name, :path, :absolute_path, :start_lineno, :type, :locals, :args, @@ -2261,131 +2311,72 @@ rb_iseq_defined_string(enum defined_type https://github.com/ruby/ruby/blob/trunk/iseq.c#L2311 return str; } -/* Experimental tracing support: trace(line) -> trace(specified_line) - * MRI Specific. - */ +#define TRACE_INSN_P(insn) ((insn) >= VM_INSTRUCTION_S (... truncated) -- ML: ruby-changes@q... Info: http://www.atdot.net/~ko1/quickml/