Segfault in 2.2.2 and above

[xaviershay]

The following segfaults on master (not released 1.0.0 gem) 2.2.2 and above. Can be seen in travis CI.

input = {
  "i" => Hamster::Hash["k" => Hamster::Set[1]]
}

Hamster.from(input)

/Users/xavier/Code/ex/hamster/lib/hamster/trie.rb:32: [BUG] Stack consistency error (sp: 47, bp: 48)
ruby 2.2.2p95 (2015-04-13 revision 50295) [x86_64-darwin14]

-- Crash Report log information --------------------------------------------
   See Crash Report log file under the one of following:
     * ~/Library/Logs/CrashReporter
     * /Library/Logs/CrashReporter
     * ~/Library/Logs/DiagnosticReports
     * /Library/Logs/DiagnosticReports
   for more details.

-- Control frame information -----------------------------------------------
c:0014 p:0018 s:0047 e:000047 BLOCK  /Users/xavier/Code/ex/hamster/lib/hamster/trie.rb:32 [FINISH]
c:0013 p:---- s:0045 e:000044 CFUNC  :each
c:0012 p:0009 s:0042 e:000041 METHOD /Users/xavier/Code/ex/hamster/lib/hamster/trie.rb:32
c:0011 p:0028 s:0038 e:000037 METHOD /Users/xavier/Code/ex/hamster/lib/hamster/hash.rb:348 [FINISH]
c:0010 p:---- s:0034 E:000578 CFUNC  :map
c:0009 p:0041 s:0031 e:000029 METHOD /Users/xavier/Code/ex/hamster/lib/hamster/hash.rb:424
c:0008 p:0162 s:0027 E:000a00 METHOD /Users/xavier/Code/ex/hamster/lib/hamster/nested.rb:27
c:0007 p:0014 s:0022 e:000020 BLOCK  /Users/xavier/Code/ex/hamster/lib/hamster/nested.rb:24 [FINISH]
c:0006 p:---- s:0017 e:000016 IFUNC
c:0005 p:---- s:0015 e:000014 CFUNC  :each
c:0004 p:---- s:0013 e:000012 CFUNC  :map
c:0003 p:0136 s:0010 e:000009 METHOD /Users/xavier/Code/ex/hamster/lib/hamster/nested.rb:24
c:0002 p:0056 s:0005 E:000208 EVAL   /tmp/test.rb:19 [FINISH]
c:0001 p:0000 s:0002 E:001c40 TOP    [FINISH]

-- Ruby level backtrace information ----------------------------------------
/tmp/test.rb:19:in `<main>'
/Users/xavier/Code/ex/hamster/lib/hamster/nested.rb:24:in `from'
/Users/xavier/Code/ex/hamster/lib/hamster/nested.rb:24:in `map'
/Users/xavier/Code/ex/hamster/lib/hamster/nested.rb:24:in `each'
/Users/xavier/Code/ex/hamster/lib/hamster/nested.rb:24:in `block in from'
/Users/xavier/Code/ex/hamster/lib/hamster/nested.rb:27:in `from'
/Users/xavier/Code/ex/hamster/lib/hamster/hash.rb:424:in `map'
/Users/xavier/Code/ex/hamster/lib/hamster/hash.rb:424:in `map'
/Users/xavier/Code/ex/hamster/lib/hamster/hash.rb:348:in `each'
/Users/xavier/Code/ex/hamster/lib/hamster/trie.rb:32:in `each'
/Users/xavier/Code/ex/hamster/lib/hamster/trie.rb:32:in `each'
/Users/xavier/Code/ex/hamster/lib/hamster/trie.rb:32:in `block in each'

-- C level backtrace information -------------------------------------------
0   ruby                                0x000000010a3bd735 rb_vm_bugreport + 149
1   ruby                                0x000000010a260754 rb_bug + 468
2   ruby                                0x000000010a39f693 vm_exec_core + 17347
3   ruby                                0x000000010a3ae931 vm_exec + 129
4   ruby                                0x000000010a3b3b08 invoke_block_from_c + 2408
5   ruby                                0x000000010a3aad80 rb_yield + 192
6   ruby                                0x000000010a221e79 rb_ary_each + 89
7   ruby                                0x000000010a3bb6c4 vm_call_cfunc + 1764
8   ruby                                0x000000010a3ba7b2 vm_call_method + 882
9   ruby                                0x000000010a39e720 vm_exec_core + 13392
10  ruby                                0x000000010a3ae931 vm_exec + 129
11  ruby                                0x000000010a3ab4ec iterate_method + 220
12  ruby                                0x000000010a3ab329 rb_iterate + 441
13  ruby                                0x000000010a3ab3fd rb_block_call + 45
14  ruby                                0x000000010a257076 enum_collect + 54
15  ruby                                0x000000010a3bb6c4 vm_call_cfunc + 1764
16  ruby                                0x000000010a3ba7b2 vm_call_method + 882
17  ruby                                0x000000010a39ed15 vm_exec_core + 14917
18  ruby                                0x000000010a3ae931 vm_exec + 129
19  ruby                                0x000000010a3b3b08 invoke_block_from_c + 2408
20  ruby                                0x000000010a3aafe7 rb_yield_values2 + 103
21  ruby                                0x000000010a25b863 collect_i + 19
22  ruby                                0x000000010a3b3830 invoke_block_from_c + 1680
23  ruby                                0x000000010a3aad80 rb_yield + 192
24  ruby                                0x000000010a295a41 each_pair_i + 17
25  ruby                                0x000000010a296305 hash_foreach_iter + 37
26  ruby                                0x000000010a342321 st_foreach_check + 113
27  ruby                                0x000000010a28f2a2 hash_foreach_call + 34
28  ruby                                0x000000010a26a70e rb_ensure + 174
29  ruby                                0x000000010a292caa rb_hash_each_pair + 154
30  ruby                                0x000000010a3b7bc8 vm_call0_body + 2328
31  ruby                                0x000000010a3ab4ec iterate_method + 220
32  ruby                                0x000000010a3ab329 rb_iterate + 441
33  ruby                                0x000000010a3ab3fd rb_block_call + 45
34  ruby                                0x000000010a257076 enum_collect + 54
35  ruby                                0x000000010a3bb6c4 vm_call_cfunc + 1764
36  ruby                                0x000000010a3ba7b2 vm_call_method + 882
37  ruby                                0x000000010a39e720 vm_exec_core + 13392
38  ruby                                0x000000010a3ae931 vm_exec + 129
39  ruby                                0x000000010a3afa38 rb_iseq_eval_main + 504
40  ruby                                0x000000010a269764 ruby_exec_internal + 148
41  ruby                                0x000000010a26968e ruby_run_node + 78
42  ruby                                0x000000010a21f33f main + 79

-- Other runtime information -----------------------------------------------

* Loaded script: /tmp/test.rb

* Loaded features:

    0 enumerator.so
    1 rational.so
    2 complex.so
    3 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/x86_64-darwin14/enc/encdb.bundle
    4 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/x86_64-darwin14/enc/trans/transdb.bundle
    5 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/unicode_normalize.rb
    6 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/x86_64-darwin14/rbconfig.rb
    7 thread.rb
    8 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/x86_64-darwin14/thread.bundle
    9 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/rubygems/compatibility.rb
   10 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/rubygems/defaults.rb
   11 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/rubygems/deprecate.rb
   12 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/rubygems/errors.rb
   13 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/rubygems/version.rb
   14 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/rubygems/requirement.rb
   15 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/rubygems/platform.rb
   16 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/rubygems/basic_specification.rb
   17 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/rubygems/stub_specification.rb
   18 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/rubygems/util/stringio.rb
   19 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/rubygems/specification.rb
   20 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/rubygems/exceptions.rb
   21 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/rubygems/core_ext/kernel_gem.rb
   22 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/monitor.rb
   23 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/rubygems/core_ext/kernel_require.rb
   24 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/rubygems.rb
   25 /Users/xavier/.rubies/cruby-2.2.2/lib/ruby/2.2.0/set.rb
   26 /Users/xavier/Code/ex/hamster/lib/hamster/immutable.rb
   27 /Users/xavier/Code/ex/hamster/lib/hamster/undefined.rb
   28 /Users/xavier/Code/ex/hamster/lib/hamster/enumerable.rb
   29 /Users/xavier/Code/ex/hamster/lib/hamster/trie.rb
   30 /Users/xavier/Code/ex/hamster/lib/hamster/sorted_set.rb
   31 /Users/xavier/Code/ex/hamster/lib/hamster/set.rb
   32 /Users/xavier/Code/ex/hamster/lib/hamster/vector.rb
   33 /Users/xavier/Code/ex/hamster/lib/hamster/hash.rb
   34 /Users/xavier/Code/ex/hamster/lib/hamster/nested.rb

[NOTE]
You may have encountered a bug in the Ruby interpreter or extension libraries.
Bug reports are welcome.
Don't forget to include the above Crash Report log file.
For details: http://www.ruby-lang.org/bugreport.html

I am investigating.

[xaviershay]

https://github.com/hamstergem/hamster/commits/933781fa222e680995132b492803f6cbb740c6ae appears to be the first bad commit.

[xaviershay]

Maybe related to https://bugs.ruby-lang.org/issues/11071 ?

[alexdowad]

Just duplicated this with 2.3.0-dev. "Stack consistency error (sp: 47, bp: 48)". Intriguing!

[alexdowad]

I have a Ruby interpreter which I have built with full debug info, which makes the stack trace much better:

-- C level backtrace information -------------------------------------------
/home/alex/Software/ruby/ruby(rb_vm_bugreport+0x51f) [0x55e28ea69acf] vm_dump.c:695
/home/alex/Software/ruby/ruby(rb_bug+0xca) [0x55e28ead4f8a] error.c:414
/home/alex/Software/ruby/ruby(vm_exec_core+0x59a6) [0x55e28ea5b856] insns.def:1031
/home/alex/Software/ruby/ruby(vm_exec+0x72) [0x55e28ea5b902] vm.c:1472
/home/alex/Software/ruby/ruby(invoke_block_from_c+0x5d4) [0x55e28ea5c634] vm.c:850
/home/alex/Software/ruby/ruby(rb_yield+0x68) [0x55e28ea5c9e8] vm.c:888
/home/alex/Software/ruby/ruby(rb_ary_each+0x3d) [0x55e28ea8609d] array.c:1820

[alexdowad]

I've found what is causing this error. It would be nice if it was just a simple coding error, but unfortunately it seems to be more of a conceptual error in the design of the block-calling and argument-passing mechanism. If only I could wrap my mind around the right way to fix it up...

[alexdowad]

OK, sigh of relief. It seems that the fix wasn't as tricky as I had thought. Have a look: https://bugs.ruby-lang.org/issues/11451

@xaviershay, I seriously doubted that this had anything to do with https://bugs.ruby-lang.org/issues/11071, but it turns out you were right! My patch also fixes that one.

[alexdowad]

@xaviershay, I said it in the Ruby core bug tracker, but I'll say it here too: thanks for reporting this problem!

If and when you run across a similar problem in the future, try to eliminate all gems and get a repro script which uses only core Ruby. You can do this by repeatedly inlining gem method calls (by hand), and checking each time to see if the problem still occurs (and backing up if it doesn't).

After each inlining, you will usually be able to delete some unneeded code and simplify what remains. After each change, check again to see if the script still crashes or not. If inlining makes the crash "disappear" -- in other words, if the method call itself is part of the problem -- just copy-and-paste the gem code into the repro script. Then remove as much as you can, while checking that the crash still occurs.

Your repro script was already quite small, which was a big help. But I reduced it further down to this:

class Yielder
  def each
    yield [1,2]
  end
end

class Getter1
  include Enumerable

  def each(&block)
    Yielder.new.each(&block)
  end
end

class Getter2
  include Enumerable

  def each
    Yielder.new.each { |a,b| yield(a) }
  end
end

Getter1.new.map { Getter2.new.map {} }

Yielder was originally Hamster::Trie, Getter1 was Hamster::Hash, and Getter2 was Hamster::Set. The core Ruby devs will appreciate it if they don't have to wade through 1000s of lines of gem code to track down a crash. (More realistically, they may actually look into it rather than ignoring it.)

[alexdowad]

So, having said all that, now we can look at fixing up Hamster. I would suggest that we apply @xaviershay's fix, with a comment stating that the modified code is for MRI 2.2.2 compatibility and that the change will be reverted when 2.2.2 is sufficiently old. (Because the changed code will almost certainly be slower.) Whenever that time comes, we can add a warning message if someone uses the gem on MRI 2.2.2.

Comments from other contributors? @dubek @krainboltgreene

[xaviershay]

Nice find!

[krainboltgreene]

Sold.

On Mon, Aug 17, 2015 at 9:41 AM, Xavier Shay notifications@github.com wrote:

Nice find!

— Reply to this email directly or view it on GitHub https://github.com/hamstergem/hamster/issues/189#issuecomment-131844954.

Kurtis Rainbolt-Greene, Hacker Software Developer 1631 8th St. New Orleans, LA 70115

[xaviershay]

Micro-benchmark suggesting expected size of performance hit. Would be the difference between the final two cases, though obviously actual benchmark of this code is needed:

require 'benchmark/ips'

def a
  yield
  yield
end

def b(&block)
  yield
  yield
end

def c(&block)
  yield
  block.call
end

def d(&block)
  block.call
  block.call
end

Benchmark.ips do |x|
  y = 0
  x.report("yield only") { a { y + 1 } }
  x.report("yield with &block") { b { y + 1 } }
  x.report("mixed with &block") { c { y + 1 } }
  x.report("&block only") { d { y + 1 } }
end

Calculating -------------------------------------
          yield only    61.039k i/100ms
   yield with &block    34.155k i/100ms
   mixed with &block    32.514k i/100ms
         &block only    32.829k i/100ms
-------------------------------------------------
          yield only      2.188M (± 6.9%) i/s -     10.926M
   yield with &block    710.589k (± 4.8%) i/s -      3.552M
   mixed with &block    653.130k (± 3.7%) i/s -      3.284M
         &block only    611.241k (± 3.6%) i/s -      3.053M

[alexdowad]

Already merged @xaviershay's fix.

[no-reply]

@alexdowad I'm not sure if you want to revisit this yet, but I was playing with this while working on some benchmarks in a downstream project and pushed up a branch.

I wasn't able to confirm that this has a real impact on performance (my benchmark/ips results vary too much), but raw calls to block.call do still seem as much as 4x slower than yield on Ruby 2.3.1.

[dubek]

@no-reply Interesting. I remember reading (can't find the source) that actually adding a &blk parameter to a method slows things down, because Ruby converts the block into a Proc object (which is later #call-ed).

So, supposedly, the fastest would be to eliminate &blk parameter and use yield (and maybe block_given? to check if we have a block at all. Of course this need benchmarking and might change in different Rubies. Here's a simple benchmark (which probably means wrong benchmark :-) ) on my machine:

require 'benchmark/ips'

def f1(&blk)
  blk.call
end

def f2(&blk)
  yield
end

def f3
  yield
end

def f4
  yield if block_given?
end

Benchmark.ips do |b|
  b.report("blk.call") { f1 { 100 * 100 } }
  b.report("blk and yield") { f2 { 100 * 100 } }
  b.report("yield") { f3 { 100 * 100 } }
  b.report("block_given? and yield (with block)") { f4 { 100 * 100 } }
  b.report("block_given? and yield (without block)") { f4 }
end

Results:

            blk.call      1.779M (± 2.5%) i/s -      8.955M
       blk and yield      2.215M (± 3.0%) i/s -     11.081M
               yield      6.639M (± 3.2%) i/s -     33.206M
block_given? and yield (with block)
                          4.570M (± 2.4%) i/s -     22.854M
block_given? and yield (without block)
                          6.677M (± 2.4%) i/s -     33.451M

So removing the &blk parameters improved from 2.2M i/s to 6.6M i/s. Get rid of those &blk ! :-)

[dubek]

Oops just saw I'm repeating the benchmark already above on this thread.... Too late I guess. Sorry.

[no-reply]

@dubek :+1: My branch linked above now has a much more complete (if somewhat slapdash) rework of &block usage throughout.

I'll open a new PR so the discussion can happen somewhere other than the bottom of a closed ticket.