RubyException.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

在深入研究源代码后，我发现首先NameError#message尝试调用inspect您的对象，如果该字符串太长，它会调用to_s。预计这inspect将需要很长时间，因为它递归地检查每个实例变量。（请参阅检查文档。）

来自错误.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