1
0
Fork 0
mirror of https://github.com/ruby/ruby.git synced 2022-11-09 12:17:21 -05:00
ruby--ruby/test/ruby/test_backtrace.rb

403 lines
9.5 KiB
Ruby
Raw Normal View History

# frozen_string_literal: false
require 'test/unit'
require 'tempfile'
class TestBacktrace < Test::Unit::TestCase
def test_exception
bt = Fiber.new{
begin
raise
rescue => e
e.backtrace
end
}.resume
assert_equal(1, bt.size)
assert_match(/.+:\d+:.+/, bt[0])
end
def helper_test_exception_backtrace_locations
raise
end
def test_exception_backtrace_locations
backtrace, backtrace_locations = Fiber.new{
begin
raise
rescue => e
[e.backtrace, e.backtrace_locations]
end
}.resume
assert_equal(backtrace, backtrace_locations.map{|e| e.to_s})
backtrace, backtrace_locations = Fiber.new{
begin
begin
helper_test_exception_backtrace_locations
rescue
raise
end
rescue => e
[e.backtrace, e.backtrace_locations]
end
}.resume
assert_equal(backtrace, backtrace_locations.map{|e| e.to_s})
end
def call_helper_test_exception_backtrace_locations
helper_test_exception_backtrace_locations(:bad_argument)
end
def test_argument_error_backtrace_locations
backtrace, backtrace_locations = Fiber.new{
begin
helper_test_exception_backtrace_locations(1)
rescue ArgumentError => e
[e.backtrace, e.backtrace_locations]
end
}.resume
assert_equal(backtrace, backtrace_locations.map{|e| e.to_s})
backtrace, backtrace_locations = Fiber.new{
begin
call_helper_test_exception_backtrace_locations
rescue ArgumentError => e
[e.backtrace, e.backtrace_locations]
end
}.resume
assert_equal(backtrace, backtrace_locations.map{|e| e.to_s})
end
def test_caller_lev
cs = []
Fiber.new{
Proc.new{
cs << caller(0)
cs << caller(1)
cs << caller(2)
cs << caller(3)
cs << caller(4)
cs << caller(5)
}.call
}.resume
assert_equal(2, cs[0].size)
assert_equal(1, cs[1].size)
assert_equal(0, cs[2].size)
assert_equal(nil, cs[3])
assert_equal(nil, cs[4])
#
max = 7
rec = lambda{|n|
if n > 0
1.times{
rec[n-1]
}
else
(max*3).times{|i|
total_size = caller(0).size
c = caller(i)
if c
assert_equal(total_size - i, caller(i).size, "[ruby-dev:45673]")
end
}
end
}
Fiber.new{
rec[max]
}.resume
end
def test_caller_lev_and_n
m = 10
rec = lambda{|n|
if n < 0
(m*6).times{|lev|
(m*6).times{|i|
t = caller(0).size
r = caller(lev, i)
r = r.size if r.respond_to? :size
# STDERR.puts [t, lev, i, r].inspect
if i == 0
assert_equal(0, r, [t, lev, i, r].inspect)
elsif t < lev
assert_equal(nil, r, [t, lev, i, r].inspect)
else
if t - lev > i
assert_equal(i, r, [t, lev, i, r].inspect)
else
assert_equal(t - lev, r, [t, lev, i, r].inspect)
end
end
}
}
else
rec[n-1]
end
}
rec[m]
end
def test_caller_with_limit
x = nil
c = Class.new do
define_method(:bar) do
x = caller(1, 1)
end
end
[c.new].group_by(&:bar)
assert_equal 1, x.length
assert_equal caller(0), caller(0, nil)
end
def test_caller_with_nil_length
assert_equal caller(0), caller(0, nil)
end
def test_caller_locations_first_label
def self.label
caller_locations.first.label
end
def self.label_caller
label
end
assert_equal 'label_caller', label_caller
[1].group_by do
assert_equal 'label_caller', label_caller
end
end
Make backtrace generation work outward from current frame This fixes multiple bugs found in the partial backtrace optimization added in 3b24b7914c16930bfadc89d6aff6326a51c54295. These bugs occurs when passing a start argument to caller where the start argument lands on a iseq frame without a pc. Before this commit, the following code results in the same line being printed twice, both for the #each method. ```ruby def a; [1].group_by { b } end def b; puts(caller(2, 1).first, caller(3, 1).first) end a ``` After this commit and in Ruby 2.7, the lines are different, with the first line being for each and the second for group_by. Before this commit, the following code can either segfault or result in an infinite loop: ```ruby def foo caller_locations(2, 1).inspect # segfault caller_locations(2, 1)[0].path # infinite loop end 1.times.map { 1.times.map { foo } } ``` After this commit, this code works correctly. This commit completely refactors the backtrace handling. Instead of processing the backtrace from the outermost frame working in, process it from the innermost frame working out. This is much faster for partial backtraces, since you only access the control frames you need to in order to construct the backtrace. To handle cfunc frames in the new design, they start out with no location information. We increment a counter for each cfunc frame added. When an iseq frame with pc is accessed, after adding the iseq backtrace location, we use the location for the iseq backtrace location for all of the directly preceding cfunc backtrace locations. If the last backtrace line is a cfunc frame, we continue scanning for iseq frames until the end control frame, and use the location information from the first one for the trailing cfunc frames in the backtrace. As only rb_ec_partial_backtrace_object uses the new backtrace implementation, remove all of the function pointers and inline the functions. This makes the process easier to understand. Restore the Ruby 2.7 implementation of backtrace_each and use it for all the other functions that called backtrace_each other than rb_ec_partial_backtrace_object. All other cases requested the entire backtrace, so there is no advantage of using the new algorithm for those. Additionally, there are implicit assumptions in the other code that the backtrace processing works inward instead of outward. Remove the cfunc/iseq union in rb_backtrace_location_t, and remove the prev_loc member for cfunc. Both cfunc and iseq types can now have iseq and pc entries, so the location information can be accessed the same way for each. This avoids the need for a extra backtrace location entry to store an iseq backtrace location if the final entry in the backtrace is a cfunc. This is also what fixes the segfault and infinite loop issues in the above bugs. Here's Ruby pseudocode for the new algorithm, where start and length are the arguments to caller or caller_locations: ```ruby end_cf = VM.end_control_frame.next cf = VM.start_control_frame size = VM.num_control_frames - 2 bt = [] cfunc_counter = 0 if length.nil? || length > size length = size end while cf != end_cf && bt.size != length if cf.iseq? if cf.instruction_pointer? if start > 0 start -= 1 else bt << cf.iseq_backtrace_entry cf_counter.times do |i| bt[-1 - i].loc = cf.loc end cfunc_counter = 0 end end elsif cf.cfunc? if start > 0 start -= 1 else bt << cf.cfunc_backtrace_entry cfunc_counter += 1 end end cf = cf.prev end if cfunc_counter > 0 while cf != end_cf if (cf.iseq? && cf.instruction_pointer?) cf_counter.times do |i| bt[-i].loc = cf.loc end end cf = cf.prev end end ``` With the following benchmark, which uses a call depth of around 100 (common in many Ruby applications): ```ruby class T def test(depth, &block) if depth == 0 yield self else test(depth - 1, &block) end end def array Array.new end def first caller_locations(1, 1) end def full caller_locations end end t = T.new t.test((ARGV.first || 100).to_i) do Benchmark.ips do |x| x.report ('caller_loc(1, 1)') {t.first} x.report ('caller_loc') {t.full} x.report ('Array.new') {t.array} x.compare! end end ``` Results before commit: ``` Calculating ------------------------------------- caller_loc(1, 1) 281.159k (_ 0.7%) i/s - 1.426M in 5.073055s caller_loc 15.836k (_ 2.1%) i/s - 79.450k in 5.019426s Array.new 1.852M (_ 2.5%) i/s - 9.296M in 5.022511s Comparison: Array.new: 1852297.5 i/s caller_loc(1, 1): 281159.1 i/s - 6.59x (_ 0.00) slower caller_loc: 15835.9 i/s - 116.97x (_ 0.00) slower ``` Results after commit: ``` Calculating ------------------------------------- caller_loc(1, 1) 562.286k (_ 0.8%) i/s - 2.858M in 5.083249s caller_loc 16.402k (_ 1.0%) i/s - 83.200k in 5.072963s Array.new 1.853M (_ 0.1%) i/s - 9.278M in 5.007523s Comparison: Array.new: 1852776.5 i/s caller_loc(1, 1): 562285.6 i/s - 3.30x (_ 0.00) slower caller_loc: 16402.3 i/s - 112.96x (_ 0.00) slower ``` This shows that the speed of caller_locations(1, 1) has roughly doubled, and the speed of caller_locations with no arguments has improved slightly. So this new algorithm is significant faster, much simpler, and fixes bugs in the previous algorithm. Fixes [Bug #18053]
2021-07-21 19:44:56 -04:00
def test_caller_limit_cfunc_iseq_no_pc
def self.a; [1].group_by { b } end
def self.b
[
caller_locations(2, 1).first.base_label,
caller_locations(3, 1).first.base_label
]
end
assert_equal({["each", "group_by"]=>[1]}, a)
end
def test_caller_location_inspect_cfunc_iseq_no_pc
def self.foo
@res = caller_locations(2, 1).inspect
end
@line = __LINE__ + 1
1.times.map { 1.times.map { foo } }
assert_equal("[\"#{__FILE__}:#{@line}:in `times'\"]", @res)
end
def test_caller_location_path_cfunc_iseq_no_pc
def self.foo
@res = caller_locations(2, 1)[0].path
end
1.times.map { 1.times.map { foo } }
assert_equal(__FILE__, @res)
end
def test_caller_locations
cs = caller(0); locs = caller_locations(0).map{|loc|
loc.to_s
}
assert_equal(cs, locs)
end
def test_caller_locations_with_range
cs = caller(0,2); locs = caller_locations(0..1).map { |loc|
loc.to_s
}
assert_equal(cs, locs)
end
def test_caller_locations_to_s_inspect
cs = caller(0); locs = caller_locations(0)
cs.zip(locs){|str, loc|
assert_equal(str, loc.to_s)
assert_equal(str.inspect, loc.inspect)
}
end
def test_caller_locations_path
loc, = caller_locations(0, 1)
assert_equal(__FILE__, loc.path)
Tempfile.create(%w"caller_locations .rb") do |f|
f.puts "caller_locations(0, 1)[0].tap {|loc| puts loc.path}"
f.close
dir, base = File.split(f.path)
assert_in_out_err(["-C", dir, base], "", [base])
end
end
def test_caller_locations_absolute_path
loc, = caller_locations(0, 1)
assert_equal(__FILE__, loc.absolute_path)
Tempfile.create(%w"caller_locations .rb") do |f|
f.puts "caller_locations(0, 1)[0].tap {|loc| puts loc.absolute_path}"
f.close
assert_in_out_err(["-C", *File.split(f.path)], "", [File.realpath(f.path)])
end
end
def test_caller_locations_lineno
loc, = caller_locations(0, 1)
assert_equal(__LINE__-1, loc.lineno)
Tempfile.create(%w"caller_locations .rb") do |f|
f.puts "caller_locations(0, 1)[0].tap {|loc| puts loc.lineno}"
f.close
assert_in_out_err(["-C", *File.split(f.path)], "", ["1"])
end
end
def test_caller_locations_base_label
assert_equal("#{__method__}", caller_locations(0, 1)[0].base_label)
loc, = tap {break caller_locations(0, 1)}
assert_equal("#{__method__}", loc.base_label)
begin
raise
rescue
assert_equal("#{__method__}", caller_locations(0, 1)[0].base_label)
end
end
def test_caller_locations_label
assert_equal("#{__method__}", caller_locations(0, 1)[0].label)
loc, = tap {break caller_locations(0, 1)}
assert_equal("block in #{__method__}", loc.label)
begin
raise
rescue
assert_equal("rescue in #{__method__}", caller_locations(0, 1)[0].label)
end
end
def th_rec q, n=10
if n > 1
th_rec q, n-1
else
q.pop
end
end
def test_thread_backtrace
begin
q = Thread::Queue.new
th = Thread.new{
th_rec q
}
sleep 0.5
th_backtrace = th.backtrace
th_locations = th.backtrace_locations
assert_equal(10, th_backtrace.count{|e| e =~ /th_rec/})
assert_equal(th_backtrace, th_locations.map{|e| e.to_s})
assert_equal(th_backtrace, th.backtrace(0))
assert_equal(th_locations.map{|e| e.to_s},
th.backtrace_locations(0).map{|e| e.to_s})
th_backtrace.size.times{|n|
assert_equal(n, th.backtrace(0, n).size)
assert_equal(n, th.backtrace_locations(0, n).size)
}
n = th_backtrace.size
assert_equal(n, th.backtrace(0, n + 1).size)
assert_equal(n, th.backtrace_locations(0, n + 1).size)
ensure
q << true
th.join
end
end
def test_thread_backtrace_locations_with_range
begin
q = Thread::Queue.new
th = Thread.new{
th_rec q
}
sleep 0.5
bt = th.backtrace(0,2)
locs = th.backtrace_locations(0..1).map { |loc|
loc.to_s
}
assert_equal(bt, locs)
ensure
q << true
th.join
end
end
def test_core_backtrace_alias
obj = BasicObject.new
e = assert_raise(NameError) do
class << obj
alias foo bar
end
end
assert_not_match(/\Acore#/, e.backtrace_locations[0].base_label)
end
def test_core_backtrace_undef
obj = BasicObject.new
e = assert_raise(NameError) do
class << obj
undef foo
end
end
assert_not_match(/\Acore#/, e.backtrace_locations[0].base_label)
end
def test_core_backtrace_hash_merge
e = assert_raise(TypeError) do
{**nil}
end
assert_not_match(/\Acore#/, e.backtrace_locations[0].base_label)
end
def test_notty_backtrace
err = ["-:1:in `<main>': unhandled exception"]
assert_in_out_err([], "raise", [], err)
err = ["-:2:in `foo': foo! (RuntimeError)",
"\tfrom -:4:in `<main>'"]
assert_in_out_err([], <<-"end;", [], err)
def foo
raise "foo!"
end
foo
end;
err = ["-:7:in `rescue in bar': bar! (RuntimeError)",
"\tfrom -:4:in `bar'",
"\tfrom -:9:in `<main>'",
"-:2:in `foo': foo! (RuntimeError)",
"\tfrom -:5:in `bar'",
"\tfrom -:9:in `<main>'"]
assert_in_out_err([], <<-"end;", [], err)
def foo
raise "foo!"
end
def bar
foo
rescue
raise "bar!"
end
bar
end;
end
def test_caller_to_enum
err = ["-:3:in `foo': unhandled exception", "\tfrom -:in `each'"]
assert_in_out_err([], <<-"end;", [], err, "[ruby-core:91911]")
def foo
return to_enum(__method__) unless block_given?
raise
yield 1
end
enum = foo
enum.next
end;
end
end