Ruby exception.message 花费了太多时间

Question

我看到了 ruby​​ 的非常有趣和灾难性的行为，请参阅下面的代码

class ExceptionTest

  def test
    @result = [0]*500000

    begin
      no_such_method
    rescue Exception => ex
      puts "before #{ex.class}"
      st = Time.now
      ex.message
      puts "after #{Time.now-st} #{ex.message}"
    end

  end
end

ExceptionTest.new.test

理想情况下，ex.message 不应该花费任何时间来执行，因此所用时间应该以毫秒为单位，但这是输出

before NameError
after 0.462443 undefined local variable or method `no_such_method' for #<ExceptionTest:0x007fc74a84e4f0>

如果我将 [0]*500000 分配给局部变量而不是实例变量，例如result = [0]*500000 它按预期运行

before NameError
after 2.8e-05 undefined local variable or method `no_such_method' for #<ExceptionTest:0x007ff59204e518>

看起来ex.message 似乎在循环通过实例变量，为什么会这样，请赐教！

我已经在 ruby​​ ruby​​-1.9.2-p290、ruby-1.9.1-p376、ruby 2.0.0 以及 codepad.org 上的任何 ruby​​ 版本上尝试过。

编辑：提交错误http://bugs.ruby-lang.org/issues/8366

Answer 1

在深入了解the source 之后，我发现NameError#message 会首先尝试在您的对象上调用inspect，如果该字符串太长，它会改为调用to_s。预计inspect 会花费很长时间，因为它递归地检查每个实例变量。 （请参阅documentation 进行检查。）

来自error.c：

d = rb_protect(rb_inspect, obj, &state);
if (state)
  rb_set_errinfo(Qnil);
if (NIL_P(d) || RSTRING_LEN(d) > 65) {
  d = rb_any_to_s(obj);
}
desc = RSTRING_PTR(d);

你可以把这个测试归结为它与异常无关：

class InspectTest
  def initialize
    @result = [0]*500000
  end

  def test
    puts "before"
    st = Time.now
    self.inspect
    puts "after #{Time.now-st}"
  end
end

InspectTest.new.test
#before
#after 0.162566

InspectTest.new.foo
# NoMethodError: undefined method `foo' for #<InspectTest:0x007fd7e317bf20>

e=InspectTest.new.tap {|e| e.instance_variable_set(:@result, 0) }
e.foo
# NoMethodError: undefined method `foo' for #<InspectTest:0x007fd7e3184580 @result=0>
e.test
#before
#after 1.5e-05

如果您知道您的类将保存大量数据并可能引发大量异常，那么理论上您可以覆盖 #inspect。

class InspectTest
  def inspect
    to_s
  end
end

InspectTest.new.test
#before
#after 1.0e-05