diff options
Diffstat (limited to 'test/ruby/test_settracefunc.rb')
| -rw-r--r-- | test/ruby/test_settracefunc.rb | 524 |
1 files changed, 481 insertions, 43 deletions
diff --git a/test/ruby/test_settracefunc.rb b/test/ruby/test_settracefunc.rb index a30c4309ad..d3b2441e21 100644 --- a/test/ruby/test_settracefunc.rb +++ b/test/ruby/test_settracefunc.rb @@ -1,5 +1,6 @@ # frozen_string_literal: false require 'test/unit' +EnvUtil.suppress_warning {require 'continuation'} class TestSetTraceFunc < Test::Unit::TestCase def setup @@ -93,6 +94,22 @@ class TestSetTraceFunc < Test::Unit::TestCase assert_equal([[:req]], parameters) end + def test_c_call_aliased_method + # [Bug #20915] + klass = Class.new do + alias_method :new_method, :method + end + + instance = klass.new + parameters = nil + + TracePoint.new(:c_call) do |tp| + parameters = tp.parameters + end.enable { instance.new_method(:to_s) } + + assert_equal([[:req]], parameters) + end + def test_call events = [] name = "#{self.class}\##{__method__}" @@ -231,7 +248,9 @@ class TestSetTraceFunc < Test::Unit::TestCase events.shift) assert_equal(["line", 5, :meth_return, self.class], events.shift) - assert_equal(["return", 7, :meth_return, self.class], + assert_equal(["line", 6, :meth_return, self.class], + events.shift) + assert_equal(["return", 6, :meth_return, self.class], events.shift) assert_equal(["line", 10, :test_return, self.class], events.shift) @@ -270,7 +289,7 @@ class TestSetTraceFunc < Test::Unit::TestCase 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) @@ -358,18 +377,18 @@ class TestSetTraceFunc < Test::Unit::TestCase def test_thread_trace events = {:set => [], :add => []} + name = "#{self.class}\##{__method__}" prc = Proc.new { |event, file, lineno, mid, binding, klass| - events[:set] << [event, lineno, mid, klass, :set] + events[:set] << [event, lineno, mid, klass, :set] if file == name } prc = prc # suppress warning prc2 = Proc.new { |event, file, lineno, mid, binding, klass| - events[:add] << [event, lineno, mid, klass, :add] + events[:add] << [event, lineno, mid, klass, :add] if file == name } prc2 = prc2 # suppress warning th = Thread.new do th = Thread.current - name = "#{self.class}\##{__method__}" eval <<-EOF.gsub(/^.*?: /, ""), nil, name 1: th.set_trace_func(prc) 2: th.add_trace_func(prc2) @@ -453,6 +472,9 @@ class TestSetTraceFunc < Test::Unit::TestCase bug3921 = '[ruby-dev:42350]' ok = false func = lambda{|e, f, l, i, b, k| + # In parallel testing, unexpected events like IO operations may be traced, + # so we filter out events here. + next unless f == __FILE__ set_trace_func(nil) ok = eval("self", b) } @@ -504,7 +526,7 @@ class TestSetTraceFunc < Test::Unit::TestCase 1: trace = TracePoint.trace(*trace_events){|tp| next if !target_thread? 2: events << [tp.event, tp.lineno, tp.path, _defined_class.(tp), tp.method_id, tp.self, tp.binding&.eval("_local_var"), _get_data.(tp)] if tp.path == 'xyzzy' 3: } - 4: 1.times{|;_local_var| _local_var = :inner + 4: [1].reverse_each{|;_local_var| _local_var = :inner 5: tap{} 6: } 7: class XYZZY @@ -531,10 +553,10 @@ class TestSetTraceFunc < Test::Unit::TestCase answer_events = [ # [:line, 4, 'xyzzy', self.class, method, self, :outer, :nothing], - [:c_call, 4, 'xyzzy', Integer, :times, 1, nil, :nothing], + [:c_call, 4, 'xyzzy', Array, :reverse_each, [1], nil, :nothing], [:line, 4, 'xyzzy', self.class, method, self, nil, :nothing], [:line, 5, 'xyzzy', self.class, method, self, :inner, :nothing], - [:c_return, 4, "xyzzy", Integer, :times, 1, nil, 1], + [:c_return, 4, "xyzzy", Array, :reverse_each, [1], nil, [1]], [:line, 7, 'xyzzy', self.class, method, self, :outer, :nothing], [:c_call, 7, "xyzzy", Module, :const_added, TestSetTraceFunc, nil, :nothing], [:c_return, 7, "xyzzy", Module, :const_added, TestSetTraceFunc, nil, nil], @@ -625,6 +647,19 @@ PREP CODE end + def test_tracepoint_bmethod_memory_leak + assert_no_memory_leak([], '', "#{<<~"begin;"}\n#{<<~'end;'}", "[Bug #20194]", rss: true) + obj = Object.new + obj.define_singleton_method(:foo) {} + bmethod = obj.method(:foo) + tp = TracePoint.new(:return) {} + begin; + 1_000_000.times do + tp.enable(target: bmethod) {} + end + end; + end + def trace_by_set_trace_func events = [] trace = nil @@ -639,7 +674,7 @@ CODE 1: set_trace_func(lambda{|event, file, line, id, binding, klass| 2: events << [event, line, file, klass, id, binding&.eval('self'), binding&.eval("_local_var")] if file == 'xyzzy' 3: }) - 4: 1.times{|;_local_var| _local_var = :inner + 4: [1].map!{|;_local_var| _local_var = :inner 5: tap{} 6: } 7: class XYZZY @@ -810,6 +845,9 @@ CODE args = nil trace = TracePoint.trace(:call){|tp| next if !target_thread? + # In parallel testing, unexpected events like IO operations may be traced, + # so we filter out events here. + next unless [TracePoint, TestSetTraceFunc].include?(tp.defined_class) ary << tp.method_id } foo @@ -955,6 +993,55 @@ CODE assert_equal(expected*2, events) end + def test_tracepoint_struct + c = Struct.new(:x) do + alias y x + alias y= x= + end + obj = c.new + + ar_meth = obj.method(:x) + aw_meth = obj.method(:x=) + aar_meth = obj.method(:y) + aaw_meth = obj.method(:y=) + events = [] + trace = TracePoint.new(:c_call, :c_return){|tp| + next if !target_thread? + next if tp.path != __FILE__ + next if tp.method_id == :call + case tp.event + when :c_call + assert_raise(RuntimeError) {tp.return_value} + events << [tp.event, tp.method_id, tp.callee_id] + when :c_return + events << [tp.event, tp.method_id, tp.callee_id, tp.return_value] + end + } + test_proc = proc do + obj.x = 1 + obj.x + obj.y = 2 + obj.y + aw_meth.call(1) + ar_meth.call + aaw_meth.call(2) + aar_meth.call + end + test_proc.call # populate call caches + trace.enable(&test_proc) + expected = [ + [:c_call, :x=, :x=], + [:c_return, :x=, :x=, 1], + [:c_call, :x, :x], + [:c_return, :x, :x, 1], + [:c_call, :x=, :y=], + [:c_return, :x=, :y=, 2], + [:c_call, :x, :y], + [:c_return, :x, :y, 2], + ] + assert_equal(expected*2, events) + end + class XYZZYException < Exception; end def method_test_tracepoint_raised_exception err raise err @@ -994,7 +1081,7 @@ CODE /return/ =~ tp.event ? tp.return_value : nil ] }.enable{ - 1.times{ + [1].map!{ 3 } method_for_test_tracepoint_block{ @@ -1004,10 +1091,10 @@ CODE # pp events # expected_events = [[:b_call, :test_tracepoint_block, TestSetTraceFunc, TestSetTraceFunc, nil], - [:c_call, :times, Integer, Integer, nil], + [:c_call, :map!, Array, Array, nil], [:b_call, :test_tracepoint_block, TestSetTraceFunc, TestSetTraceFunc, nil], [:b_return, :test_tracepoint_block, TestSetTraceFunc, TestSetTraceFunc, 3], - [:c_return, :times, Integer, Integer, 1], + [:c_return, :map!, Array, Array, [3]], [:call, :method_for_test_tracepoint_block, TestSetTraceFunc, TestSetTraceFunc, nil], [:b_call, :test_tracepoint_block, TestSetTraceFunc, TestSetTraceFunc, nil], [:b_return, :test_tracepoint_block, TestSetTraceFunc, TestSetTraceFunc, 4], @@ -1061,9 +1148,9 @@ CODE when :line assert_match(/ in /, str) when :call, :c_call - assert_match(/call \`/, str) # #<TracePoint:c_call `inherited' ../trunk/test.rb:11> + assert_match(/call \'/, str) # #<TracePoint:c_call 'inherited' ../trunk/test.rb:11> when :return, :c_return - assert_match(/return \`/, str) # #<TracePoint:return `m' ../trunk/test.rb:3> + assert_match(/return \'/, str) # #<TracePoint:return 'm' ../trunk/test.rb:3> when /thread/ assert_match(/\#<Thread:/, str) # #<TracePoint:thread_end of #<Thread:0x87076c0>> else @@ -1196,15 +1283,17 @@ CODE end } assert_normal_exit src % %q{obj.zip({}) {}}, bug7774 - assert_normal_exit src % %q{ - require 'continuation' - begin - c = nil - obj.sort_by {|x| callcc {|c2| c ||= c2 }; x } - c.call - rescue RuntimeError - end - }, bug7774 + if respond_to?(:callcc) + assert_normal_exit src % %q{ + require 'continuation' + begin + c = nil + obj.sort_by {|x| callcc {|c2| c ||= c2 }; x } + c.call + rescue RuntimeError + end + }, bug7774 + end # TracePoint tp_b = nil @@ -1306,11 +1395,13 @@ CODE def test_a_call events = [] + log = [] TracePoint.new(:a_call){|tp| next if !target_thread? events << tp.event + log << "| event:#{ tp.event } method_id:#{ tp.method_id } #{ tp.path }:#{ tp.lineno }" }.enable{ - 1.times{ + [1].map!{ 3 } method_for_test_tracepoint_block{ @@ -1323,16 +1414,18 @@ CODE :b_call, :call, :b_call, - ], events) + ], events, "TracePoint log:\n#{ log.join("\n") }\n") end def test_a_return events = [] + log = [] TracePoint.new(:a_return){|tp| next if !target_thread? events << tp.event + log << "| event:#{ tp.event } method_id:#{ tp.method_id } #{ tp.path }:#{ tp.lineno }" }.enable{ - 1.times{ + [1].map!{ 3 } method_for_test_tracepoint_block{ @@ -1345,7 +1438,7 @@ CODE :b_return, :return, :b_return - ], events) + ], events, "TracePoint log:\n#{ log.join("\n") }\n") end def test_const_missing @@ -1906,7 +1999,7 @@ CODE TracePoint.new(:c_call, &capture_events).enable{ c.new } - assert_equal [:c_call, :itself, :initialize], events[1] + assert_equal [:c_call, :itself, :initialize], events[0] events.clear o = Class.new{ @@ -1923,7 +2016,11 @@ CODE def tp_return_value mid ary = [] - TracePoint.new(:return, :b_return){|tp| next if !target_thread?; ary << [tp.event, tp.method_id, tp.return_value]}.enable{ + TracePoint.new(:return, :b_return){|tp| + next if !target_thread? + next if tp.path != __FILE__ + ary << [tp.event, tp.method_id, tp.return_value] + }.enable{ send mid } ary.pop # last b_return event is not required. @@ -2129,10 +2226,10 @@ CODE def test_thread_add_trace_func events = [] base_line = __LINE__ - q = Thread::Queue.new + q = [] t = Thread.new{ Thread.current.add_trace_func proc{|ev, file, line, *args| - events << [ev, line] + events << [ev, line] if file == __FILE__ } # do not stop trace. They will be stopped at Thread termination. q.push 1 _x = 1 @@ -2168,9 +2265,6 @@ CODE } # it is dirty hack. usually we shouldn't use such technique Thread.pass until t.status == 'sleep' - # When RJIT thread exists, t.status becomes 'sleep' even if it does not reach m2t_q.pop. - # This sleep forces it to reach m2t_q.pop for --jit-wait. - sleep 1 if defined?(RubyVM::RJIT) && RubyVM::RJIT.enabled? t.add_trace_func proc{|ev, file, line, *args| if file == __FILE__ @@ -2229,7 +2323,7 @@ CODE _c = a + b end - def check_with_events *trace_events + def check_with_events(trace_point_events, expected_events = trace_point_events) all_events = [[:call, :method_for_enable_target1], [:line, :method_for_enable_target1], [:line, :method_for_enable_target1], @@ -2251,7 +2345,7 @@ CODE [:return, :method_for_enable_target1], ] events = [] - TracePoint.new(*trace_events) do |tp| + TracePoint.new(*trace_point_events) do |tp| next unless target_thread? events << [tp.event, tp.method_id] end.enable(target: method(:method_for_enable_target1)) do @@ -2259,15 +2353,22 @@ CODE method_for_enable_target2 method_for_enable_target1 end - assert_equal all_events.find_all{|(ev)| trace_events.include? ev}, events + + assert_equal all_events.keep_if { |(ev)| expected_events.include? ev }, events end def test_tracepoint_enable_target - check_with_events :line - check_with_events :call, :return - check_with_events :line, :call, :return - check_with_events :call, :return, :b_call, :b_return - check_with_events :line, :call, :return, :b_call, :b_return + check_with_events([:line]) + check_with_events([:call, :return]) + check_with_events([:line, :call, :return]) + check_with_events([:call, :return, :b_call, :b_return]) + check_with_events([:line, :call, :return, :b_call, :b_return]) + + # No arguments passed into TracePoint.new enables all ISEQ_TRACE_EVENTS + check_with_events([], [:line, :class, :end, :call, :return, :c_call, :c_return, :b_call, :b_return, :rescue]) + + # Raise event should be ignored + check_with_events([:line, :raise]) end def test_tracepoint_nested_enabled_with_target @@ -2406,6 +2507,18 @@ CODE assert_equal [:tp1, 1, 2, :tp2, 3], events end + def test_multiple_enable + ary = [] + trace = TracePoint.new(:call) do |tp| + ary << tp.method_id + end + trace.enable + trace.enable + foo + trace.disable + assert_equal(1, ary.count(:foo), '[Bug #19114]') + end + def test_multiple_tracepoints_same_bmethod events = [] tp1 = TracePoint.new(:return) do |tp| @@ -2611,7 +2724,7 @@ CODE end def test_disable_local_tracepoint_in_trace - assert_normal_exit <<-EOS + assert_normal_exit(<<-EOS, timeout: 60) def foo trace = TracePoint.new(:b_return){|tp| tp.disable @@ -2725,4 +2838,329 @@ CODE Foo.foo RUBY end + + def helper_cant_rescue + begin + raise SyntaxError + rescue + cant_rescue + end + end + + def test_tp_rescue + lines = [] + TracePoint.new(:line){|tp| + next unless target_thread? + lines << tp.lineno + }.enable{ + begin + helper_cant_rescue + rescue SyntaxError + end + } + _call_line = lines.shift + _raise_line = lines.shift + assert_equal [], lines + end + + def helper_can_rescue + begin + raise __LINE__.to_s + rescue SyntaxError + :ng + rescue + :ok + end + end + + def helper_can_rescue_empty_body + begin + raise __LINE__.to_s + rescue SyntaxError + :ng + rescue + end + end + + def test_tp_rescue_event + lines = [] + TracePoint.new(:rescue){|tp| + next unless target_thread? + lines << [tp.lineno, tp.raised_exception] + }.enable{ + helper_can_rescue + } + + line, err, = lines.pop + assert_equal [], lines + assert err.kind_of?(RuntimeError) + assert_equal err.message.to_i + 4, line + + lines = [] + TracePoint.new(:rescue){|tp| + next unless target_thread? + lines << [tp.lineno, tp.raised_exception] + }.enable{ + helper_can_rescue_empty_body + } + + line, err, = lines.pop + assert_equal [], lines + assert err.kind_of?(RuntimeError) + assert_equal err.message.to_i + 3, line + end + + def test_tracepoint_thread_begin + target_thread = nil + + trace = TracePoint.new(:thread_begin) do |tp| + target_thread = tp.self + end + + trace.enable(target_thread: nil) do + Thread.new{}.join + end + + assert_kind_of(Thread, target_thread) + end + + def test_tracepoint_thread_end + target_thread = nil + + trace = TracePoint.new(:thread_end) do |tp| + target_thread = tp.self + end + + trace.enable(target_thread: nil) do + Thread.new{}.join + end + + assert_kind_of(Thread, target_thread) + end + + def test_tracepoint_thread_end_with_exception + target_thread = nil + + trace = TracePoint.new(:thread_end) do |tp| + target_thread = tp.self + end + + trace.enable(target_thread: nil) do + thread = Thread.new do + Thread.current.report_on_exception = false + raise + end + + # Ignore the exception raised by the thread: + thread.join rescue nil + end + + assert_kind_of(Thread, target_thread) + end + + def test_tracepoint_garbage_collected_when_disable + before_count_stat = 0 + before_count_objspace = 0 + TracePoint.stat.each do + before_count_stat += 1 + end + ObjectSpace.each_object(TracePoint) do + before_count_objspace += 1 + end + tp = TracePoint.new(:c_call, :c_return) do + end + tp.enable + Class.inspect # c_call, c_return invoked + tp.disable + tp_id = tp.object_id + tp = nil + + gc_times = 0 + gc_max_retries = 10 + EnvUtil.suppress_warning do + until (ObjectSpace._id2ref(tp_id) rescue nil).nil? + GC.start + gc_times += 1 + if gc_times == gc_max_retries + break + end + end + end + return if gc_times == gc_max_retries + + after_count_stat = 0 + TracePoint.stat.each do |v| + after_count_stat += 1 + end + assert after_count_stat <= before_count_stat + after_count_objspace = 0 + ObjectSpace.each_object(TracePoint) do + after_count_objspace += 1 + end + assert after_count_objspace <= before_count_objspace + end + + def test_tp_ractor_local_untargeted + assert_ractor("#{<<~"begin;"}\n#{<<~'end;'}") + begin; + r = Ractor.new do + results = [] + tp = TracePoint.new(:line) { |tp| results << tp.path } + tp.enable + Ractor.main << :continue + Ractor.receive + tp.disable + results + end + outer_results = [] + outer_tp = TracePoint.new(:line) { |tp| outer_results << tp.path } + outer_tp.enable + Ractor.receive + GC.start # so I can check <internal:gc> path + r << :continue + inner_results = r.value + outer_tp.disable + assert_equal 1, outer_results.select { |path| path.match?(/internal:gc/) }.size + assert_equal 0, inner_results.select { |path| path.match?(/internal:gc/) }.size + end; + end + + def test_tp_targeted_ractor_local_bmethod + assert_ractor("#{<<~"begin;"}\n#{<<~'end;'}") + begin; + mname = :foo + prok = Ractor.shareable_proc do + end + klass = EnvUtil.labeled_class(:Klass) do + define_method(mname, &prok) + end + outer_results = 0 + _outer_tp = TracePoint.new(:call) do + outer_results += 1 + end # not enabled + rs = 10.times.map do + Ractor.new(mname, klass) do |mname, klass0| + inner_results = 0 + tp = TracePoint.new(:call) { |tp| inner_results += 1 } + target = klass0.instance_method(mname) + tp.enable(target: target) + obj = klass0.new + 10.times { obj.send(mname) } + tp.disable + inner_results + end + end + inner_results = rs.map(&:value).sum + obj = klass.new + 10.times { obj.send(mname) } + assert_equal 100, inner_results + assert_equal 0, outer_results + end; + end + + def test_tp_targeted_ractor_local_method + assert_ractor("#{<<~"begin;"}\n#{<<~'end;'}") + begin; + def foo + end + outer_results = 0 + _outer_tp = TracePoint.new(:call) do + outer_results += 1 + end # not enabled + + rs = 10.times.map do + Ractor.new do + inner_results = 0 + tp = TracePoint.new(:call) do + inner_results += 1 + end + tp.enable(target: method(:foo)) + 10.times { foo } + tp.disable + inner_results + end + end + + inner_results = rs.map(&:value).sum + 10.times { foo } + assert_equal 100, inner_results + assert_equal 0, outer_results + end; + end + + def test_tracepoints_not_disabled_by_ractor_gc + assert_ractor("#{<<~"begin;"}\n#{<<~'end;'}") + begin; + $-w = nil # uses ObjectSpace._id2ref + def hi = "hi" + greetings = 0 + tp_target = TracePoint.new(:call) do |tp| + greetings += 1 + end + tp_target.enable(target: method(:hi)) + + raises = 0 + tp_global = TracePoint.new(:raise) do |tp| + raises += 1 + end + tp_global.enable + + r = Ractor.new { 10 } + r.join + ractor_id = r.object_id + r = nil # allow gc for ractor + gc_max_retries = 15 + gc_times = 0 + # force GC of ractor (or try, because we have a conservative GC) + until (ObjectSpace._id2ref(ractor_id) rescue nil).nil? + GC.start + gc_times += 1 + if gc_times == gc_max_retries + break + end + end + + # tracepoints should still be enabled after GC of `r` + 5.times { + hi + } + 6.times { + raise "uh oh" rescue nil + } + tp_target.disable + tp_global.disable + assert_equal 5, greetings + if gc_times == gc_max_retries # _id2ref never raised + assert_equal 6, raises + else + assert_equal 7, raises + end + end; + end + + def test_lots_of_enabled_tracepoints_ractor_gc + assert_ractor("#{<<~"begin;"}\n#{<<~'end;'}") + begin; + def foo; end + sum = 8.times.map do + Ractor.new do + called = 0 + TracePoint.new(:call) do |tp| + next if tp.callee_id != :foo + called += 1 + end.enable + 200.times do + TracePoint.new(:line) { + # all these allocations shouldn't GC these tracepoints while the ractor is alive. + Object.new + }.enable + end + 100.times { foo } + called + end + end.map(&:value).sum + assert_equal 800, sum + 4.times { GC.start } # Now the tracepoints can be GC'd because the ractors can be GC'd + end; + end end |