Bug #11088
closedOn Exception too expensive inspect is called on recursive object graph with 3000 elements in it, swallows memory and ultimately doesn't deliver exception
Description
I have tested with simple cases where the dumped structure is not recursive and it works fine. So I attached a non-working dump which will when called with inspect or a non-existing method run off in an infinite loop.
When you run "ruby bug_hunt.rb" it will get stuck and you have to abort(CTRL-C) and only then will it print an error message and finish.
Files
Updated by shishir127 (Shishir Joshi) over 9 years ago
- File 11088_test.rb 11088_test.rb added
Hi Jurgen,
I executed bug_hunt.rb and I was able to reproduce this issue. But when I tried a simple test (attached in 11088_test.rb) I did not see this bug. Can you tell us how you generated the ruby_object.dump? Do you have code for it?
Also, according to the documentation for Marshall (http://ruby-doc.org/core-2.2.2/Marshal.html#method-c-dump)
Marshal can't dump following objects:
anonymous Class/Module.
objects which are related to system (ex: Dir, File::Stat, IO, File, Socket and so on)
an instance of MatchData, Data, Method, UnboundMethod, Proc, Thread, ThreadGroup, Continuation
objects which define singleton methods
Updated by austin (Austin Ziegler) over 9 years ago
- File simple-inspect.txt simple-inspect.txt added
- File simple-inspect-stats.txt simple-inspect-stats.txt added
- File bug_hunt_benchmark.rb bug_hunt_benchmark.rb added
- File bug_hunt_simple.rb bug_hunt_simple.rb added
The data structure in question is large and has some slightly pathological recursiveness. There are 3,204 objects marshalled. Most of these (3,088) are referenced exactly once. Of the remaining:
- 52 appear between 2x and 9x.
- 17 appear between 20x and 29x.
- 13 appear between 30x and 39x.
- 6 appear between 40x and 49x.
- 16 appear between 50x and 59x.
- 9 appear between 60x and 69x.
- 1 appears 71x.
- 1 appears 88x.
- 1 appears 89x.
I’m attaching bug_hunt_simple.rb
(based on SimpleInspect
below), simple-inspect.txt
(the output of a simplified inspect), and simple-inspect-stats.txt
(the count of appearances).
What’s interesting to me is that there’s an observable slowdown in the output of the NoMethodError
result, so I benchmarked it (bug_hunt_benchmark.rb
). There’s a consistent 0.1–0.2 second slowdown over 100,000 iterations, and the output of the exception message differs between the two forms (at the bottom of the file). (The slowdown is ~0.6s/100k on ruby 2.0 and 2.1, so there is that.)
Note: these are the values where the inspect strings are constructed. If I remove the custom string construction and minimize the interaction with
$__inspected__
and its helper methods, there is still a consistent 0.05–0.1s/100k slowdown.
So there’s something about looking at an exception that triggers an expensive #inspect
—but then discards it for a cheap #inspect
in some circumstances. Without the SimpleInspect
module (which is mostly useless because it keeps program-wide state, but is useful for this investigation), somehow the recursion detection of #inspect
has been blown to bits in some recent version of Ruby (the problem shows up for ruby 2.0.0p481, ruby 2.1.6p336, ruby 2.2.2p95 and ruby 2.3.0dev (2015-04-11), which are the only Rubies I have on my Mac right now).
module SimpleInspect
def inspect
result = if inspected?
"#<%s (%d) ...>" % [ inspected_key, inspected_count ]
else
super
end
inspect!
"\n" + result
end
private
def inspected?
inspected[inspected_key].nonzero?
end
def inspect!
inspected[inspected_key] += 1
end
def inspected_count
inspected[inspected_key]
end
def inspected
$__inspected__ ||= Hash.new { |h, k| h[k] = 0 }
end
def inspected_key
"%s:0x%014x" % [ self.class, "0x%014x" % (object_id * 2) ]
end
end
class Object
include SimpleInspect
end
Updated by nobu (Nobuyoshi Nakada) over 9 years ago
- Status changed from Open to Rejected
Your objects are consist of very large networks with complex recursive references.
Even with omission of the recursions, it makes tons of hundreds MB strings.
You should define inspect
methods for your purpose.
Updated by austin (Austin Ziegler) over 9 years ago
I don't think this should be rejected completely, Nobu. As I mentioned in
my analysis, it appears that NoMethodError#message is calling #inspect on
the object that raised the error, only to discard most of the item in
favour of just the "#Klass:0xOBJECTREF" output. I can understand that
this is a pathological case, but I'm curious why the output is different
than would be expected here.
-a
On Sat, May 9, 2015 at 10:48 PM nobu@ruby-lang.org wrote:
Issue #11088 has been updated by Nobuyoshi Nakada.
Status changed from Open to Rejected
Your objects are consist of very large networks with complex recursive
references.
Even with omission of the recursions, it makes tons of hundreds MB strings.
You should defineinspect
methods for your purpose.
Bug #11088: Infinite loop on calling missing/overwritten methods of
restored marshaled objects
https://bugs.ruby-lang.org/issues/11088#change-52360
- Author: Jürgen Bickert
- Status: Rejected
- Priority: Normal
- Assignee:
- ruby -v: ruby 2.2.2p95 (2015-04-13 revision 50295) [x86_64-linux]
- Backport: 2.0.0: UNKNOWN, 2.1: UNKNOWN, 2.2: UNKNOWN
I have Marshal.dump some objects and then I Marshal.load them and later I
call non-existent methods on those objects and instead of raising an
exception (NoMethodError) it runs off in an infinite loop.I have tested with simple cases where the dumped structure is not
recursive and it works fine. So I attached a non-working dump which will
when called with inspect or a non-existing method run off in an infinite
loop.When you run "ruby bug_hunt.rb" it will get stuck and you have to
abort(CTRL-C) and only then will it print an error message and finish.---Files--------------------------------
bug_hunt.rb (336 Bytes)
ruby_object.dump (561 KB)
11088_test.rb (305 Bytes)
simple-inspect.txt (1.19 MB)
simple-inspect-stats.txt (90.7 KB)
bug_hunt_benchmark.rb (1.42 KB)
bug_hunt_simple.rb (1.09 KB)
Updated by kaiserprogrammer (Jürgen Bickert) over 9 years ago
- Subject changed from Infinite loop on calling missing/overwritten methods of restored marshaled objects to On Exception too expensive inspect is called on recursive object graph with 3000 elements in it, swallows memory and ultimately doesn't deliver exception
- Description updated (diff)
After your input and directing me to inspect, I did some more testing and found that marshal has absolutely nothing to do with this problem. Writing custom inspect methods fixes the problem. Another question still remains for why is inspect called on the errored object, development stagnated for me because my program has a moderately sized object graph with recursive dependencies. I couldn't get any error messages at all anymore! Imagine you mistyped a method but your process will hang in inspect instead of finally raising NoMethodError exception to the toplevel.