Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Java::JavaLang::StackOverflowError running spec which works on 2.2.1 #3193

Closed
hakanai opened this issue Jul 28, 2015 · 11 comments
Closed

Java::JavaLang::StackOverflowError running spec which works on 2.2.1 #3193

hakanai opened this issue Jul 28, 2015 · 11 comments

Comments

@hakanai
Copy link

hakanai commented Jul 28, 2015

An rspec extension I'm trying to get working works fine on 2.2.1, but gives a stack overflow on JRuby 9.0.0.0. Demonstration:

    $ rbenv jruby-9.0.0.0
    $ rspec my_spec.rb
    F

    Failures:

      1) some thing does something
         Failure/Error: Unable to find matching line from backtrace
         Java::JavaLang::StackOverflowError:
         # org.jruby.ir.IRBuilder.buildOperand(IRBuilder.java:361)
         # org.jruby.ir.IRBuilder.build(IRBuilder.java:499)
         # org.jruby.ir.IRBuilder.defineMethodInner(IRBuilder.java:1714)
         # org.jruby.ir.IRMethod.lazilyAcquireInterpreterContext(IRMethod.java:45)
         # org.jruby.internal.runtime.methods.MixedModeIRMethod.ensureInstrsReady(MixedModeIRMethod.java:98)
         # org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:149)
         # org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:193)
         # org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:293)
         # org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:131)
         # org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:305)
         # org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:77)
         # org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:128)
         # org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:114)
         # org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:77)
         # org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:83)
         # org.jruby.ir.instructions.CallBase.interpret(CallBase.java:419)
         # org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:321)
         # org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:77)
         # org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:136)
         # org.jruby.runtime.InterpretedIRBlockBody.commonYieldPath(InterpretedIRBlockBody.java:118)
         # org.jruby.runtime.IRBlockBody.doYield(IRBlockBody.java:139)
         # org.jruby.runtime.BlockBody.yield(BlockBody.java:77)
         # org.jruby.runtime.Block.yield(Block.java:147)
         # org.jruby.RubyHash.fetch(RubyHash.java:1180)
         # org.jruby.RubyHash$INVOKER$i$fetch.call(RubyHash$INVOKER$i$fetch.gen)
         # org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:171)
         # org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:177)
         # org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:298)
         # org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:77)
         # org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:82)
         # org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:198)
         # org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:184)
         # org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:171)
         # org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:177)
         # org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:298)
         # org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:77)
         # org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:136)
         # org.jruby.runtime.InterpretedIRBlockBody.commonYieldPath(InterpretedIRBlockBody.java:118)
         # org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:58)
         # org.jruby.runtime.Block.call(Block.java:106)
         # org.jruby.RubyProc.call(RubyProc.java:324)
         # org.jruby.internal.runtime.methods.ProcMethod.call(ProcMethod.java:63)
         # org.jruby.ir.runtime.IRRuntimeHelpers.unresolvedSuper(IRRuntimeHelpers.java:929)
         # org.jruby.ir.instructions.UnresolvedSuperInstr.interpret(UnresolvedSuperInstr.java:83)
         # org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:321)
         # org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:77)
         # org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:136)
         # org.jruby.runtime.InterpretedIRBlockBody.commonYieldPath(InterpretedIRBlockBody.java:118)
         # org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:58)
         # org.jruby.runtime.Block.call(Block.java:106)
         # org.jruby.RubyProc.call(RubyProc.java:324)
         # org.jruby.internal.runtime.methods.ProcMethod.call(ProcMethod.java:63)
         # org.jruby.ir.runtime.IRRuntimeHelpers.unresolvedSuper(IRRuntimeHelpers.java:929)
         # org.jruby.ir.instructions.UnresolvedSuperInstr.interpret(UnresolvedSuperInstr.java:83)
         # org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:321)
         # org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:77)
         # org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:136)
         # org.jruby.runtime.InterpretedIRBlockBody.commonYieldPath(InterpretedIRBlockBody.java:118)
         # org.jruby.runtime.IRBlockBody.yieldSpecific(IRBlockBody.java:66)
         # org.jruby.runtime.Block.yieldSpecific(Block.java:116)
         # org.jruby.ir.runtime.IRRuntimeHelpers.yieldSpecific(IRRuntimeHelpers.java:457)
         # org.jruby.ir.instructions.YieldInstr.interpret(YieldInstr.java:72)
         # org.jruby.ir.interpreter.StartupInterpreterEngine.processOtherOp(StartupInterpreterEngine.java:183)
         # org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:107)
         # org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:136)
         # org.jruby.runtime.InterpretedIRBlockBody.commonYieldPath(InterpretedIRBlockBody.java:118)
         # org.jruby.runtime.IRBlockBody.doYield(IRBlockBody.java:139)
         # org.jruby.runtime.BlockBody.yield(BlockBody.java:77)
         # org.jruby.runtime.Block.yield(Block.java:147)
         # org.jruby.RubyHash.fetch(RubyHash.java:1180)
         # org.jruby.RubyHash$INVOKER$i$fetch.call(RubyHash$INVOKER$i$fetch.gen)
         # org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:171)
         # org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:177)
         # org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:298)
         # org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:77)
         # org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:136)
         # org.jruby.runtime.InterpretedIRBlockBody.commonYieldPath(InterpretedIRBlockBody.java:118)
         # org.jruby.runtime.IRBlockBody.yieldSpecific(IRBlockBody.java:66)
         # org.jruby.runtime.Block.yieldSpecific(Block.java:116)
         # org.jruby.ir.runtime.IRRuntimeHelpers.yieldSpecific(IRRuntimeHelpers.java:457)
         # org.jruby.ir.instructions.YieldInstr.interpret(YieldInstr.java:72)
...
org.jruby.ir.interpreter.StartupInterpreterEngine.processOtherOp(StartupInterpreterEngine.java:183)
         # org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:107)
         # org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:136)
         # org.jruby.runtime.InterpretedIRBlockBody.commonYieldPath(InterpretedIRBlockBody.java:118)
         # org.jruby.runtime.IRBlockBody.doYield(IRBlockBody.java:139)
         # org.jruby.runtime.BlockBody.yield(BlockBody.java:77)
         # org.jruby.runtime.Block.yield(Block.java:147)
         # org.jruby.RubyHash.fetch(RubyHash.java:1180)
         # org.jruby.RubyHash$INVOKER$i$fetch.call(RubyHash$INVOKER$i$fetch.gen)
         # org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:171)
         # org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:177)
         # org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:298)
         # org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:77)
         # org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:136)
         # org.jruby.runtime.InterpretedIRBlockBody.commonYieldPath(InterpretedIRBlockBody.java:118)
         # org.jruby.runtime.IRBlockBody.yieldSpecific(IRBlockBody.java:66)
         # org.jruby.runtime.Block.yieldSpecific(Block.java:116)
         # org.jruby.ir.runtime.IRRuntimeHelpers.yieldSpecific(IRRuntimeHelpers.java:457)
         # org.jruby.ir.instructions.YieldInstr.interpret(YieldInstr.java:72)
         # org.jruby.ir.interpreter.StartupInterpreterEngine.processOtherOp(StartupInterpreterEngine.java:183)
         # org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:107)
         # org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:128)
         # org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:114)
         # org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:77)
         # org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:83)
         # org.jruby.ir.instructions.CallBase.interpret(CallBase.java:419)

    Finished in 0.027 seconds (files took 0.58 seconds to load)
    1 example, 1 failure

    Failed examples:

    rspec ./my_spec.rb:6 # some thing does something

my_spec.rb cut down to just the extension we are trying to get working, plus one spec to call the code which triggers the issue:

    module LetAndAfterExtensions
      class LetAndAfter
        def initialize(let_name, example_group)
          @let_name = let_name
          @example_group = example_group
        end

        def and_after(&block)
          let_initialized = nil
          name = @let_name

          observation_module = Module.new do
            define_method(name) do |*args|
              super(*args).tap { let_initialized = true }
            end
          end

          @example_group.class_exec do
            prepend observation_module
            before { let_initialized = false }
            after { block.call if let_initialized }
          end
        end
      end

      def let(name, &block)
        super(name, &block)
        LetAndAfter.new(name, self)
      end
    end

    RSpec.configure do |c|
      c.extend LetAndAfterExtensions
    end

    RSpec.describe "some thing" do
      let(:foo) { 2 }.and_after { }

      it "does something" do
        expect(foo).to eq 2
      end
    end

Same spec on 2.2.1:

    $ rbenv shell 2.2.1
    $ rspec my_spec.rb 
    .

    Finished in 0.00064 seconds (files took 0.07848 seconds to load)
    1 example, 0 failures

In our actual specs, we don't get this stack overflow, but instead get an error about the prepend method not being found on Class. This stack overflow is what I found when trying to cut that problem down to a small enough size to report. So this issue is either related, or you will discover that other issue once this one is fixed.

The issue occurred on 9.0.0.0.rc2 as well, but I haven't tested any earlier versions.

@kares kares added this to the JRuby 9.0.1.0 milestone Jul 30, 2015
@enebo enebo modified the milestones: JRuby 9.0.1.0, JRuby 9.0.2.0 Sep 2, 2015
@headius
Copy link
Member

headius commented Oct 7, 2015

Confirmed on master. Investigating.

@headius
Copy link
Member

headius commented Oct 7, 2015

This is taking a long time to sort out...may not be able to get this in for 9.0.2.

@headius
Copy link
Member

headius commented Jan 20, 2016

Still failing on master.

@headius
Copy link
Member

headius commented Jan 20, 2016

FYI, the prepend issue is not related; 9.0.0.0.rc2 did not have prepend implemented yet.

@headius
Copy link
Member

headius commented Jan 20, 2016

If I log the block being invoked recursively here, I see two line numbers over and over once it starts to go down the rabbit hole:

/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/configuration.rb:720
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/configuration.rb:1802
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/configuration.rb:1802
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/configuration.rb:1802
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/configuration.rb:1802
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/configuration.rb:720
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/configuration.rb:1802
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/configuration.rb:1802
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/configuration.rb:1802
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/configuration.rb:1802

The one at line 720 looks pretty mundane, and probably isn't the culprit:

      # Returns the configuration option for color, but should not
      # be used to check if color is supported.
      #
      # @see color_enabled?
      # @return [Boolean]
      def color
        value_for(:color) { @color }
      end

The other one at line 1802, however, contains a yield within a block, for which we've had a few sneaky bugs creep in:

      def value_for(key)
        @preferred_options.fetch(key) { yield }
      end

The fetch method is simply Hash#fetch, which is pretty simple:

    @JRubyMethod
    public IRubyObject fetch(ThreadContext context, IRubyObject key, Block block) {
        Ruby runtime = context.runtime;

        IRubyObject value = internalGet(key);

        if (value == null) {
            if (block.isGiven()) return block.yield(context, key);

            throw runtime.newKeyError("key not found: :" + key);
        }

        return value;
    }

Turning off JIT does not appear to fix the issue. Curiouser and curiouser.

@headius
Copy link
Member

headius commented Jan 20, 2016

Ok, there's a possibility prepend is involved, since the example script prepends a define_method method into the example group, and the define_method does a super call. I may be able to reduce this.

@headius
Copy link
Member

headius commented Jan 20, 2016

Ok, yep, prepend is involved. If I modify the prepend section to instead do an include on the singleton of @example_group, it works fine:

          @example_group.instance_eval do
            self.class.send :include, observation_module
            before { let_initialized = false }
            after { block.call if let_initialized }
          end

@headius
Copy link
Member

headius commented Jan 20, 2016

With a somewhat reduced example, I get this Ruby backtrace for the recursing bit:

/Users/headius/projects/jruby/my_spec.rb:9:in `block in foo'
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/memoized_helpers.rb:295:in `block in foo'
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/memoized_helpers.rb:157:in `block in fetch_or_store'
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/memoized_helpers.rb:157:in `fetch'
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/memoized_helpers.rb:157:in `block in fetch_or_store'
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-support-3.4.1/lib/rspec/support/reentrant_mutex.rb:23:in `synchronize'
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/memoized_helpers.rb:156:in `block in fetch_or_store'
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/memoized_helpers.rb:155:in `fetch'
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/memoized_helpers.rb:155:in `fetch_or_store'
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/memoized_helpers.rb:295:in `block in foo'
/Users/headius/projects/jruby/my_spec.rb:9:in `block in foo'
/Users/headius/projects/jruby/my_spec.rb:27:in `block in (root)'
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/example.rb:236:in `instance_exec'
/Users/headius/projects/jruby/lib/ruby/gems/shared/gems/rspec-core-3.4.1/lib/rspec/core/example.rb:236:in `block in run'

Reduced version:

    module LetAndAfterExtensions
      def let(name, &block)
        super(name, &block)
        observation_module = Module.new do
          define_method(name) do |*args|
            super(*args)
          end
        end

        class_exec do
          prepend observation_module
        end
      end
    end

    RSpec.configure do |c|
      c.extend LetAndAfterExtensions
    end

    RSpec.describe "some thing" do
      let(:foo) { 2 } #.and_after { }

      it "does something" do
        foo
      end
    end

@headius
Copy link
Member

headius commented Jan 20, 2016

I believe I have a reduced reproduction:

class A
  define_method :foo do
    super
  end

  prepend Module.new do
    def foo
      super
    end
  end
end

A.new.foo

Interestingly, this only fails if run in the interpreter, either simple or full. If run in the JIT (as when running directly at command line) it works fine. It's likely that the original rspec example would have started working had it not reached a stack overflow before the method bodies in question had jitted.

So this seems like an issue with unresolved super in a define_method not starting from the proper place.

@headius
Copy link
Member

headius commented Jan 20, 2016

It turns out the contents of the prepended module are not important:

class A
  define_method :foo do
    super()
  end

  prepend Module.new
end

A.new.foo

@headius
Copy link
Member

headius commented Jan 20, 2016

A slightly longer example, using a concrete module rather than a block-initialized module, shows we bounce back and forth between the prepended foo and the class's foo:

class A
  define_method :foo do
    p :a
    super()
  end
end

module B
  def foo
    p :b
    super()
  end
end

A.prepend(B)
A.new.foo

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

4 participants