Feature #9725: Do not inspect NameError target object unless verbose

• Status: Open
• Assignee: -
• Target version: -

[headius (Charles Nutter)]

At least once every few months, we get an error report of JRuby raising a memory error where MRI does not due to NameError's Message object holding a reference to an object that's too large to inspect. I propose that this inspection of the target object should only be done in verbose mode.

Background:

NameError is raised when a variable-like method call fails to find a defined method. The resulting exception is created with a hidden NameError::Message that holds the object in which the method could not be found.

When name error needs to render its message, such as when it bubbles out or when #message is called, it does to_str on the NameError::Message, which ends up inspecting the target object. If this object's inspect output is large (or infinite) it can end up consuming a large amount of memory.

Problems:

• If the amount of memory required to render a NameError exceeds available memory, a very confusing and misleading memory error can be raised instead.
• If the target object is considered sensitive data, it will end up bubbling out through potentially untrustworthy code. It is an encapsulation flaw, basically.
• A NameError that gets held in memory will also prevent GC of the object it references.

Solutions:

• NameError should not capture the target object.
• NameError should build a message based on the target object at creation time, and only include information useful to indicate the type of object.
• (Optional) If verbose mode is set, NameError can just do what it does now.

[josh.cheek (Josh Cheek)]

Solutions:

• NameError should not capture the target object.
• NameError should build a message based on the target object at creation time, and only include information useful to indicate the type of object.
• (Optional) If verbose mode is set, NameError can just do what it does now.

+1 for creation time.

I would also like to see it not hidden in the NameError::message method, but to just be a normal class that is easier to find and reason about

e.g. it causes this issue https://bugs.ruby-lang.org/issues/8303 I've seen a few others that resulted from it. Here's a fun article about it http://web.archive.org/web/20120125075139/http://www.carboni.ca/blog/p/Ruby-Did-You-Know-That-5-NameErrormessage

Because its so confusing, it causes what appear to be bugs in basically anything that hits this case. E.g. I thought RSpec was broken for quite a while, because half my students were hitting this, and it means that it blows not on the test that had the issue, but when the message is accessed at the very end of the test suite. This is very misleading and difficult to debug https://github.com/rspec/rspec-core/issues/1631

# Here is an example showing how confusing it is that you can raise and rescue the NameError,
# and continue on your merry way, not bitten until you access the message.

def self.inspect
  sleep 5 # mimics an expensive inspect like the one below
  "#<expensive inspect result>"
end

puts "BEFORE EXCEPTION"
ex = whoops! rescue $!
puts "AFTER EXCEPTION"
 
puts "...some time later, we decide to look at the message"
puts ex.message
puts "WTF?"

# Here is an example of how graphs inspect methods will grow incredibly quickly,
# making them use up all the resources available when asking for the inspect method,
# which will happen at the time that NameError.message is called.

class Graph
  def self.size(n)
    nodes = n.times.map { new }
    nodes.each { |n| n.associations = nodes - [n] }
    nodes
  end
  attr_accessor :associations
end

Graph.size(2).first.inspect      # => "#<Graph:0x007fca52890840 @associations=[#<Graph:0x007fca528907f0 @associations=[#<Graph:0x007fca52890840 ...>]>]>"
Graph.size(1).first.inspect.size # => 42
Graph.size(2).first.inspect.size # => 113
Graph.size(3).first.inspect.size # => 394
Graph.size(4).first.inspect.size # => 1693
Graph.size(5).first.inspect.size # => 8804
Graph.size(6).first.inspect.size # => 54145
Graph.size(7).first.inspect.size # => 385558
Graph.size(8).first.inspect.size # => 3123629

# quite a pause when generating that last one

[headius (Charles Nutter)]

Josh: great examples, thank you. I've run into similar cases trying to debug applications on JRuby or help users find performance problems. This is a hidden gotcha that's very hard to find, especially if you have some library sticking a giant graph of objects in there.

I'd like to get approval that this is a good idea before I attempt to patch it. There must be others out there who hate the fact that NameError carries along the whole object with it!

[headius (Charles Nutter)]

One of the JRuby issues that keeps getting +1'ed: https://github.com/jruby/jruby/issues/216

I really think we need to address this.

[headius (Charles Nutter)]

I think we're going to have to make this change unilaterally in JRuby.

This behavior leads to unpredictable systems, since NameErrors can happen even in tested code, and you'll never know how big the attached object might be. One untested code path leading to NameError and you might blow the memory cap of the entire system.

I really hope MRI decides to fix this.

[matz (Yukihiro Matsumoto)]

We had another memory issue in the past, and this behavior was the fix for that issue.
So both adding and removing could cause the problem.

I am interested why referencing the target object could cause problem. The target object must be existed before the exception, and exception should disappear soon after handling.

Matz.

[nobu (Nobuyoshi Nakada)]

• Description updated (diff)

Building the message at creation time does not reduce memory usage and CPU time at all, just makes it earlier.
And #inspect method of such complex class should consider it, I don't think that huge output is not human-readable.

Anyway, unexpectedly huge result of inspection often causes problems, so the uncaught exception handler shows the class and the object ID only in that case, but it needs to build the inspection string once and discards then.
It's a long-time known issue that we need smarter way for inspection.

[headius (Charles Nutter)]

Yukihiro Matsumoto wrote:

I am interested why referencing the target object could cause problem. The target object must be existed before the exception, and exception should disappear soon after handling.

I'm not sure it's the referencing that's really the problem here, it's that NameError#inspect will inspect the object, possibly causing side effects. The case I've seen in ActiveRecord is when you have a lazy set or tree of results that won't load until walked...but then inspect fires and has to walk the whole thing. You end up having a NameError bubble out somewhere, get inspected, and trigger all this loading that will at least be overhead and at worst cause a different error, wiping out the first.

Why does NameError need to inspect the target object at all? If it just carried it along, users could opt-in to get more info on the target by calling NameError#target.Nobuyoshi Nakada wrote:

Building the message at creation time does not reduce memory usage and CPU time at all, just makes it earlier.

Agreed.

And #inspect method of such complex class should consider it, I don't think that huge output is not human-readable.

Perhaps. Should #inspect never trigger lazy loads? Should inspect not recurse down large hierarchies? The problem here is that you could get a NameError against almost anything, like a giant array with a bunch of giant arrays in it.

Anyway, unexpectedly huge result of inspection often causes problems, so the uncaught exception handler shows the class and the object ID only in that case, but it needs to build the inspection string once and discards then.
It's a long-time known issue that we need smarter way for inspection.

That's all well and good, but this is a real problem now, and I don't think having NameError inspect the failed target adds as much as it risks.

I also suggested that the inspect behavior could remain, but perhaps only if we're in verbose mode. In that case, getting the fully-inspected NameError is just a flag away.

[headius (Charles Nutter)]

Yukihiro Matsumoto wrote:

I am interested why referencing the target object could cause problem. The target object must be existed before the exception, and exception should disappear soon after handling.

Oh I see, you were asking about this line in my original description:

• A NameError that gets held in memory will also prevent GC of the object it references.

This is a problem because a NameError is never just a NameError object...it could hold a reference to a giant object graph. In a system that collects exceptions, e.g. for logging or auditing, NameError is the only exception that could potentially root a bunch of memory just because you happen to keep it around.

Having the object available via #target obviously still has the same problem. I'm not opposed to doing it that way, but I still don't like that a NameError can be just the tip of a giant object graph iceberg.

[headius (Charles Nutter)]

• Has duplicate Feature #18285: NoMethodError#message uses a lot of CPU/is really expensive to call added