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

org.jruby.runtime.scopes.DynamicScope6 only supports scopes with 6 variables on JRuby 9.2.12.0/OpenJDK8 #6319

Closed
JohnPhillips31416 opened this issue Jul 13, 2020 · 19 comments · Fixed by #6323

Comments

@JohnPhillips31416
Copy link

JohnPhillips31416 commented Jul 13, 2020

We've been running JRuby 9.2.9.0, but we're unable to run with JRuby 9.2.12.0 without getting the following stack trace. This looks similar to #4739. This issue implies that the cause is the cross of the JRuby JIT compilation and the Java7 parallel classloader, however, the issue occurs even with -XX:+AlwaysLockClassLoader.

(Running Java VM OpenJDK 64-Bit Server VM Java Version 1.8.0_252 JRuby Version 9.2.12.0 JRuby Revision db01a49)

Java::JavaLang::RuntimeException : org.jruby.runtime.scopes.DynamicScope6 only supports scopes with 6 variables
  org.jruby.runtime.scopes.DynamicScope6.sizeError(Unknown Source)
  org.jruby.runtime.scopes.DynamicScope6.setValueVoid(Unknown Source)
  org.jruby.ir.interpreter.InterpreterEngine.setResult(InterpreterEngine.java:572)
  org.jruby.ir.interpreter.InterpreterEngine.setResult(InterpreterEngine.java:578)
  org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:362)
  org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:72)
  org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:86)
  org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:73)
  org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:84)
  org.jruby.ir.instructions.CallBase.interpret(CallBase.java:552)
  org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:361)
  org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:72)
  org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:116)
  org.jruby.runtime.MixedModeIRBlockBody.commonYieldPath(MixedModeIRBlockBody.java:136)
  org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:60)
  org.jruby.runtime.Block.call(Block.java:143)
  org.jruby.RubyProc.call(RubyProc.java:339)
  org.jruby.internal.runtime.methods.ProcMethod.call(ProcMethod.java:64)
  org.jruby.RubyMethod.call(RubyMethod.java:131)
  org.jruby.RubyMethod$INVOKER$i$call.call(RubyMethod$INVOKER$i$call.gen)
  org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:174)
  org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:74)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.invokeOther2:call(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:1610)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.RUBY$block$compile!$2(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:1610)
  org.jruby.runtime.CompiledIRBlockBody.callDirect(CompiledIRBlockBody.java:138)
  org.jruby.runtime.IRBlockBody.call(IRBlockBody.java:58)
  org.jruby.runtime.Block.call(Block.java:143)
  org.jruby.RubyProc.call(RubyProc.java:275)
  org.jruby.RubyProc$INVOKER$i$call.call(RubyProc$INVOKER$i$call.gen)
  org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:174)
  org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:74)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.invokeOther0:\=\{\}(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:975)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.RUBY$block$route!$3(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:975)
  org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:148)
  org.jruby.runtime.IRBlockBody.yieldSpecific(IRBlockBody.java:66)
  org.jruby.runtime.Block.yieldSpecific(Block.java:153)
  org.jruby.ir.runtime.IRRuntimeHelpers.yieldSpecific(IRRuntimeHelpers.java:503)
  org.jruby.ir.instructions.YieldInstr.interpret(YieldInstr.java:76)
  org.jruby.ir.interpreter.StartupInterpreterEngine.processOtherOp(StartupInterpreterEngine.java:178)
  org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:104)
  org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:80)
  org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:121)
  org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:108)
  org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:365)
  org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:153)
  org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:160)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.invokeOther4:route_eval(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:975)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.RUBY$block$route!$2(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:975)
  org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:148)
  org.jruby.runtime.BlockBody.yield(BlockBody.java:114)
  org.jruby.runtime.Block.yieldValues(Block.java:200)
  org.jruby.ir.targets.YieldSite.yieldValues(YieldSite.java:166)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.RUBY$block$process_route$3(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:1015)
  org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:148)
  org.jruby.runtime.BlockBody.yield(BlockBody.java:106)
  org.jruby.runtime.Block.yield(Block.java:184)
  org.jruby.exceptions.CatchThrow.enter(CatchThrow.java:32)
  org.jruby.RubyKernel.rbCatch(RubyKernel.java:1189)
  org.jruby.RubyKernel$INVOKER$s$rbCatch.call(RubyKernel$INVOKER$s$rbCatch.gen)
  org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:182)
  org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:191)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.invokeOther33:catch(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:1013)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.RUBY$method$process_route$0(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:1013)
  org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:82)
  org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:131)
  org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:210)
  org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:244)
  org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:253)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.invokeOther5:process_route(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:973)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.RUBY$block$route!$1(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:973)
  org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:148)
  org.jruby.runtime.BlockBody.yield(BlockBody.java:106)
  org.jruby.runtime.Block.yield(Block.java:184)
  org.jruby.RubyArray.each(RubyArray.java:1809)
  org.jruby.RubyArray$INVOKER$i$0$0$each.call(RubyArray$INVOKER$i$0$0$each.gen)
  org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:151)
  org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:160)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.invokeOther11:each(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:972)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.RUBY$method$route!$0(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:972)
  org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:82)
  org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:118)
  org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:175)
  org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:208)
  org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:396)
  org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:205)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.invokeOther15:route!(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:985)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.RUBY$method$route!$0(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:985)
  org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:82)
  org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:92)
  org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:105)
  org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:192)
  org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:354)
  org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:143)
  org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:345)
  org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:72)
  org.jruby.ir.interpreter.Interpreter.INTERPRET_BLOCK(Interpreter.java:116)
  org.jruby.runtime.MixedModeIRBlockBody.commonYieldPath(MixedModeIRBlockBody.java:136)
  org.jruby.runtime.IRBlockBody.yieldSpecific(IRBlockBody.java:70)
  org.jruby.runtime.Block.yieldSpecific(Block.java:153)
  org.jruby.ir.targets.YieldSite.yieldSpecific(YieldSite.java:156)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.RUBY$block$invoke$1(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067)
  org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:148)
  org.jruby.runtime.BlockBody.yield(BlockBody.java:106)
  org.jruby.runtime.Block.yield(Block.java:184)
  org.jruby.exceptions.CatchThrow.enter(CatchThrow.java:32)
  org.jruby.RubyKernel.rbCatch(RubyKernel.java:1189)
  org.jruby.RubyKernel$INVOKER$s$rbCatch.call(RubyKernel$INVOKER$s$rbCatch.gen)
  org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:182)
  org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:191)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.invokeOther0:catch(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.RUBY$method$invoke$0(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb:1067)
  uri_3a_classloader_3a_.gems.sinatra_minus_1_dot_4_dot_8.lib.sinatra.base.RUBY$method$invoke$0$__VARARGS__(uri:classloader:/gems/sinatra-1.4.8/lib/sinatra/base.rb)

@headius
Copy link
Member

headius commented Jul 14, 2020

Sorry for delay in looking at this.

I suspect this is another concurrency error in the lazy optimization that we do in our jit subsystem. Usually this is caused by an unoptimized method or block getting called from an optimized call path. The optimized call path will have eliminated the allocation of the appropriate DynamicScope type, expecting the code to use JVM local variables instead, and then it runs the unoptimized code that needs a DynamicScope and it finds some other method's scope on the stack which doesn't match right.

@JohnPhillips31416
Copy link
Author

JohnPhillips31416 commented Jul 14, 2020

I tried several workarounds for this and was about to move forward with jruby.jit.background=false but even with that fix I'm still seeing the issue, this time on Oracle JDK8.

@headius
Copy link
Member

headius commented Jul 14, 2020

@JohnPhillips31416 That doesn't surprise me. Even with background=false you may still have one thread synchronously optimizing a method while another thread tries to execute it, and then we're back in the same boat. We need to deal with the shared data getting overwritten across threads.

This will be in 9.2.13.

@headius headius added this to the 9.2.13.0 milestone Jul 14, 2020
headius added a commit that referenced this issue Jul 14, 2020
Part of eliminating races against the mutable IR flags for #6319.
headius added a commit that referenced this issue Jul 15, 2020
This eliminates two dynscope-related flags that get tweaked during
optimization, moving all consumers to using InterpreterContext
and eliminating the flags altogether. This will help #6319
specifically by ensuring a non-full IC will not see full IC's
dynscope flag changes.

This also introduces a new overridable initialize method to IC so
FullIC can override it to do nothing, eliminating some needless
overrides. These two classes should be modified to be disjoint in
the future.
@headius
Copy link
Member

headius commented Jul 15, 2020

I think the sensitive flags have been isolated properly in #6323 and this could be retested with that branch (ir_concurrency).

enebo pushed a commit to enebo/jruby that referenced this issue Jul 16, 2020
Part of eliminating races against the mutable IR flags for jruby#6319.
enebo pushed a commit to enebo/jruby that referenced this issue Jul 16, 2020
This eliminates two dynscope-related flags that get tweaked during
optimization, moving all consumers to using InterpreterContext
and eliminating the flags altogether. This will help jruby#6319
specifically by ensuring a non-full IC will not see full IC's
dynscope flag changes.

This also introduces a new overridable initialize method to IC so
FullIC can override it to do nothing, eliminating some needless
overrides. These two classes should be modified to be disjoint in
the future.
@JohnPhillips31416
Copy link
Author

JohnPhillips31416 commented Jul 17, 2020

We've been able to run our integration test suite using a local jruby build from the ir_concurrency branch & see no occurrence of this issue. Tested both with OpenJDK 64-Bit Server VM Java Version 1.8.0_252 and HotSpot(TM) 64-Bit Server VM Java Version 1.8.0_202.

@enebo
Copy link
Member

enebo commented Jul 20, 2020

@JohnPhillips31416 Can you try latest version of this branch again commit 10a0db5. I am not sure which version you did before but since 3 days ago I have removed another race where we would sometimes reset a flags field back to default state (only to recalculate it to the same values again).

@enebo
Copy link
Member

enebo commented Jul 20, 2020

At this point we are probably good for 9.2.13.0 with some ok that people are not seeing the errors reported here. The remaining problems which we will address in 9.3:

  1. we use IRFlags as a cache of information about the state of the scope we are analyzing/executing. Right now two threads can both decide to compile the same method at the same time. They both share the same flags cache (although all other shared resources have been eliminated on this branch). The cache itself is additive only (sans one flag which will not be affected by compilation) so regardless of which thread is winning the flags it needs to test will have already been set.

The future of flags will be to have one set managed in IRBuilder and one in FullIC. In order to achieve this each scope type (Closure/Method/ModuleBody/...) will need to delineate which its initial flags should be. Then we will calculate scope flags from a proper starting point (and not call initScopeFlags ever). The flags will live in IC once builder is finished. When FIC is made we will clone those flags and store them in FIC. Passes will interact with that set. In both IC and FIC the runtime will ask them for things like whether the flag specifying the scope uses keyword arguments (although the other option in this case is to make this a boolean and not a flag since kwargs user will always be a kwargs user). In any case, execution will ask ICs for what it needs directly.

  1. Although I cannot reproduce this I feel like there is an old activation calling something compiled for the next activation problem. Figuring out a working case is proving difficult enough where I do not know if I am right anymore. Here was one doodle (needs to be called with -r so we do not force compile the scipe):
def pr
  yield
end


def foo
  i = 0
  pr {
    while i < 1000
      pr {
        puts i
      }
      i += 1
    end

    i = 0
    while i < 2000
      pr {
        puts i
      }
      i += 1
    end
  }
end

foo

It does work but the thought was the first nested pr inside the while would compile while second would not have been called yet. The second sibling would use a new version of itself which would assume the parent pr had eliminated its dynscope and then picked the wrong scope. Does not happen.... So something bugs me but I have not been able to make anything break.

@enebo
Copy link
Member

enebo commented Jul 21, 2020

Ok I think we want to do something with flags too :(

I just traced through all our passes and it all stumbles on a small race within IRScope.initScopeFlags(). I was hoping to avoid this but I see enough potential for problems I now want to tackle this. Here are some notes I made:

Passes

LocalOptimizationPass - Runs local optimiations on each instr potentially marking some instrs dead.

  1. Calls instr.simplifyAndGetResult(scope, valueMap) -

    1. ToAryInstr
    2. CopyInstr - value

    These will call getSimplifiedOperand as well but they seemingly are about
    properties of the operand without caring about state of the scope.
    Calls intrs.canBeDeletedFromScope(fic) - Only ToAryInstr does this unconditionally

    No flags seem to be used by this optimization.

DeadCodeElimination - Eliminates unreachable code

Relies on LiveVariableAnalysis (LVA). LVA will check if dynamic scope
is eliminated (fic.isDynamicScopeEliminated). By default, this will never
be true because it only gets marked from OptimizeDynScopes and that happens
after this pass. LiveVariableNode also depends on bindingHasEscaped().

bindingHasEscape being wrong at this point will just end up marking more
variables as live which will not break code but will make all variables alive.

OptimizeDynScopesPass (ODS) - Do not use dynamic scope if we know a binding has not
escaped.

Depends on REQUIRES_DYNSCOPE. Sets reuseParentDynScope on fic.

If this is set then no problems can occur. If it gets unset at the time this
is running then it might eliminate a dynscope which needs to exist.

OptimizeDelegationPass - Optimization for unused &foo to not construct
procs if that method does not actually use it (or merely passes it on).

Depends on BINDING_HAS_ESCAPED and RECIEVES_CLOSURE_ARG.

If a binding escapes then that variable must be capturable by a binding.
If set then optimization does not happen but it is safe. Otherwise,
if a binding really happens then the variable will not have the proper value.

RECEIVES_CLOSURE_ARG not being set means no opt happens. no correctness
problem. It is only set in the case of actually detecting a closure arg
so we cannot have a case where it is set but it is not true. Even if that
did happen then the opt would try but would not find anything to opt.

AddCallProtocolInstructions - Potentially set up less initialization of frames
and bindings

Depends on needsFrame(), needsBinding(), and needsOnlyBackref().

needsFrame() depends on BINDING_HAS_ESCAPED (problem).
Also USES_EVAL (problem). looks at all REQUIRES_* frame flags (problem) as
two are set in constructor but all are unset in initScopeFlags().
CAN_CAPTURE_CALLERS_BINDING (problem initScopeFlags).
USES_EVAL (problem) /USES_ZSUPER (problem initScopeFlags).

needsBinding() depends on reuseParentDynScope on fic and set by OptimizeDynScopesPass. no issues. It also depends on dynamicScopeEliminated which also happens during ODS. no issues.

needsOnlyBackRef() all the same fields as needsFrame().

This pass is pretty complicated from a flags perspective.

AddMissingInitsPass - Adds potentially missing assigns with nil.

reuseParentDynScope() - not a problem set via OptimizeDelegationPass into fic.

Flags

BINDING_HAS_ESCAPE

computeScopeFlags/Early both will call BINDING_HAS_ESCAPED and remove it if
it is not an IREvalScript or IRScriptBody. This needs to be set once and
not changed.

REQUIRES_DYNSCOPE

Removes in initScope but is set in DEFAULT_SCOPE_FLAGS. This flag is derived
off of other flags (which naturally are also derived) in
computeNeedsDynamicScopeFlag(). This happens after walking all children
closures in computeScopeFlags* because those closures in form the parent scope
whether something like receiving a break is possible (as an example). We cannot
remove this flag because instrs may also call something which will mark the
dynscope as required.

REQUIRES_* (frame flags)

Removes in initScope but only REQUIRES_BACKREF and REQUIRES_LASTLINE set by default.

USES_EVAL

Removes in initScope but is set in DEFAULT_SCOPE_FLAGS.

@enebo
Copy link
Member

enebo commented Jul 22, 2020

Ok so a new discovery: HAS_ LOOPS, MAYBE_USES_REFINEMENTS, and ACCESS_PARENTS_LOCAL_VARIABLES are only set during IRBuild. So if we reset and recalculate flags these values will get lost. This essentially means flags should never remove but only modify the flag set.

For 9.3 we should really consider a state machine for these cached values. It would not only explain how they get set/unset but it will be much more clear than we need to consider the lifecycle of these values.

@enebo
Copy link
Member

enebo commented Jul 27, 2020

@JohnPhillips31416 ok. I believe ir_concurrency branch is what we would like to use. If you could try this out we would appreciate it.

@JohnPhillips31416
Copy link
Author

JohnPhillips31416 commented Jul 27, 2020

@enebo Using the ir_concurrency branch I've built our warbler jar and I'm seeing a deadlock/hang at startup. Is there something here which doesn't work properly when Warbler invokes org.jruby.embed.ScriptingContainer.runScriptlet? I'm seeing my process stuck as follows

		at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000003d2ee5a10> (a java.util.concurrent.Semaphore$NonfairSync)
	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedNanos(AbstractQueuedSynchronizer.java:1037)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.tryAcquireSharedNanos(AbstractQueuedSynchronizer.java:1328)
	at java.util.concurrent.Semaphore.tryAcquire(Semaphore.java:409)
	at org.jruby.RubyThread$SleepTask2.run(RubyThread.java:1541)
	at org.jruby.RubyThread$SleepTask2.run(RubyThread.java:1528)
	at org.jruby.RubyThread.executeTask(RubyThread.java:1585)
	at org.jruby.RubyThread.executeTask(RubyThread.java:1571)
	at org.jruby.RubyThread.sleep(RubyThread.java:1452)
	at org.jruby.RubyKernel.sleep(RubyKernel.java:691)
	at org.jruby.RubyKernel$INVOKER$s$0$1$sleep.call(RubyKernel$INVOKER$s$0$1$sleep.gen)
	at org.jruby.internal.runtime.methods.JavaMethod$JavaMethodN.call(JavaMethod.java:815)
	at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:200)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:172)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:60)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:301)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:72)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:86)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:73)
	at org.jruby.RubyClass.finvokeWithRefinements(RubyClass.java:514)
	at org.jruby.RubyBasicObject.send(RubyBasicObject.java:1755)
	at org.jruby.RubyKernel.send(RubyKernel.java:2200)
	at org.jruby.RubyKernel$INVOKER$s$send.call(RubyKernel$INVOKER$s$send.gen)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:332)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:86)
	at org.jruby.ir.instructions.CallBase.interpret(CallBase.java:549)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:361)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:72)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:86)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:73)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:332)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:86)
	at org.jruby.ir.instructions.CallBase.interpret(CallBase.java:549)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:361)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:72)
	at org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:92)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:191)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:178)
	at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:208)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:396)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:205)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:325)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:72)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:86)
        at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:73)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:332)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:86)
	at org.jruby.ir.instructions.CallBase.interpret(CallBase.java:549)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:361)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:72)
	at org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:80)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:121)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:108)
	at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:192)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:354)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:143)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:345)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:72)
	at org.jruby.ir.interpreter.Interpreter.INTERPRET_ROOT(Interpreter.java:96)
	at org.jruby.ir.interpreter.Interpreter.execute(Interpreter.java:81)
	at org.jruby.ir.interpreter.Interpreter.execute(Interpreter.java:30)
	at org.jruby.ir.IRTranslator.execute(IRTranslator.java:42)
	at org.jruby.Ruby.runInterpreter(Ruby.java:1218)
	at org.jruby.Ruby.loadFile(Ruby.java:2785)
	at org.jruby.runtime.load.LibrarySearcher$ResourceLibrary.load(LibrarySearcher.java:234)
	at org.jruby.runtime.load.LibrarySearcher$FoundLibrary.load(LibrarySearcher.java:34)
	at org.jruby.runtime.load.LoadService.load(LoadService.java:343)
	at org.jruby.RubyKernel.loadCommon(RubyKernel.java:1039)
	at org.jruby.RubyKernel.load(RubyKernel.java:1009)
	at org.jruby.RubyKernel$INVOKER$s$load.call(RubyKernel$INVOKER$s$load.gen)
	at org.jruby.internal.runtime.methods.JavaMethod$JavaMethodOneOrNBlock.call(JavaMethod.java:417)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:375)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:174)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:316)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:72)
	at org.jruby.ir.interpreter.Interpreter.INTERPRET_ROOT(Interpreter.java:96)
	at org.jruby.ir.interpreter.Interpreter.execute(Interpreter.java:81)
	at org.jruby.ir.interpreter.Interpreter.execute(Interpreter.java:30)
	at org.jruby.ir.IRTranslator.execute(IRTranslator.java:42)
	at org.jruby.Ruby.runInterpreter(Ruby.java:1218)
	at org.jruby.Ruby.loadFile(Ruby.java:2785)
	at org.jruby.runtime.load.LibrarySearcher$ResourceLibrary.load(LibrarySearcher.java:234)
	at org.jruby.runtime.load.LibrarySearcher$FoundLibrary.load(LibrarySearcher.java:34)
	at org.jruby.runtime.load.LoadService.tryLoadingLibraryOrScript(LoadService.java:887)
	at org.jruby.runtime.load.LoadService.smartLoadInternal(LoadService.java:535)
	at org.jruby.runtime.load.LoadService.require(LoadService.java:402)
	at org.jruby.RubyKernel.requireCommon(RubyKernel.java:981)
	at org.jruby.RubyKernel.require(RubyKernel.java:974)
	at org.jruby.RubyKernel$INVOKER$s$1$0$require.call(RubyKernel$INVOKER$s$1$0$require.gen)
	at org.jruby.internal.runtime.methods.JavaMethod$JavaMethodOneOrNBlock.call(JavaMethod.java:417)
	at org.jruby.internal.runtime.methods.AliasMethod.call(AliasMethod.java:97)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:172)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:316)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:72)
	at org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:86)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:156)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:143)
	at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:200)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:375)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:174)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:316)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:72)
	at org.jruby.ir.interpreter.Interpreter.INTERPRET_ROOT(Interpreter.java:96)
	at org.jruby.ir.interpreter.Interpreter.execute(Interpreter.java:81)
	at org.jruby.ir.interpreter.Interpreter.execute(Interpreter.java:30)
	at org.jruby.ir.IRTranslator.execute(IRTranslator.java:42)
	at org.jruby.Ruby.runInterpreter(Ruby.java:1240)
	at org.jruby.Ruby.runInterpreter(Ruby.java:1244)
	at org.jruby.embed.internal.EmbedEvalUnitImpl.run(EmbedEvalUnitImpl.java:118)
	at org.jruby.embed.ScriptingContainer.runUnit(ScriptingContainer.java:1295)
	at org.jruby.embed.ScriptingContainer.runScriptlet(ScriptingContainer.java:1288)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at JarMain.invokeMethod(JarMain.java:263)
	at JarMain.invokeMethod(JarMain.java:256)
	at JarMain.launchJRuby(JarMain.java:141)
	at LookerJarMain.launchJRuby(LookerJarMain.java:27)

The branch works fine when I invoke using the jruby command.

@enebo
Copy link
Member

enebo commented Jul 28, 2020

@JohnPhillips31416 And on 9.2.12.0 you do not see this deadlock when starting from warbler/embedded? All the work I put on this branch does not add any behavior which would increase the chance of a dead lock. It largely just allows multiple compiles to compete without sharing the same data. This is perplexing...

@JohnPhillips31416
Copy link
Author

JohnPhillips31416 commented Jul 28, 2020

@enebo The JRuby I've built from the branch works fine when I run our stack using the jruby command, but when I use Warbler to build our jar it hangs when I run the jar with Java. Only thing I can think of is that maybe the Warbler JRuby entrypoint is after some of the initialization of flags that you have refactored.

@JohnPhillips31416
Copy link
Author

JohnPhillips31416 commented Jul 28, 2020

@enebo
Copy link
Member

enebo commented Jul 28, 2020

@JohnPhillips31416 just because I did not see it explicitly said. 9.2.12.0 does not exhibit this behavior when started from warbler?

@JohnPhillips31416
Copy link
Author

JohnPhillips31416 commented Jul 28, 2020

@enebo Sorry for the omission. I've previously tested on 9.2.12.0 and it works fine. Testing with
OpenJDK Runtime Environment (build 1.8.0_232-8u232-b09-1~deb9u1-b09)
OpenJDK 64-Bit Server VM (build 25.232-b09, mixed mode)

@JohnPhillips31416
Copy link
Author

JohnPhillips31416 commented Jul 29, 2020

The hang at startup using our warbler jar was an issue on our end. I'm now able to test with the top of the ir_concurrency branch but unfortunately the issue is back:

java.lang.RuntimeException: org.jruby.runtime.scopes.DynamicScope1 only supports scopes with 1 variables
                 require at org/jruby/RubyKernel.java:974
  require_with_backports at uri:classloader:/gems/backports-3.7.0/lib/backports/std_lib.rb:9
                   start at uri:classloader:/helltool/lib/helltool/runner.class:7
                    each at org/jruby/RubyArray.java:1809
                   start at uri:classloader:/helltool/lib/helltool/runner.class:7
                   start at uri:classloader:/helltool/lib/helltool/cli.class:75
                     run at uri:classloader:/gems/thor-0.15.4/lib/thor/task.rb:27
             invoke_task at uri:classloader:/gems/thor-0.15.4/lib/thor/invocation.rb:120
                dispatch at uri:classloader:/gems/thor-0.15.4/lib/thor.rb:275
                   start at uri:classloader:/gems/thor-0.15.4/lib/thor/base.rb:425
                  <main> at uri:classloader:/helltool/bin/helltool:31
                    load at org/jruby/RubyKernel.java:1009
                  <main> at uri:classloader:/META-INF/main.rb:1
                 require at org/jruby/RubyKernel.java:974
                 require at uri:classloader:/META-INF/jruby.home/lib/ruby/stdlib/rubygems/core_ext/kernel_require.rb:54
                  <main> at <script>:3
ERROR: org.jruby.embed.EvalFailedException: (LoadError) load error: uri:classloader:...

@headius
Copy link
Member

headius commented Aug 1, 2020

Fixed by #6323.

@headius headius closed this as completed Aug 1, 2020
@JohnPhillips31416
Copy link
Author

JohnPhillips31416 commented Aug 19, 2020

We have now successfully moved to 9.2.13.0. Thanks again for the help.

enebo pushed a commit that referenced this issue Aug 31, 2020
Part of eliminating races against the mutable IR flags for #6319.
enebo pushed a commit that referenced this issue Aug 31, 2020
This eliminates two dynscope-related flags that get tweaked during
optimization, moving all consumers to using InterpreterContext
and eliminating the flags altogether. This will help #6319
specifically by ensuring a non-full IC will not see full IC's
dynscope flag changes.

This also introduces a new overridable initialize method to IC so
FullIC can override it to do nothing, eliminating some needless
overrides. These two classes should be modified to be disjoint in
the future.
enebo pushed a commit that referenced this issue Aug 31, 2020
Part of eliminating races against the mutable IR flags for #6319.
enebo pushed a commit that referenced this issue Aug 31, 2020
This eliminates two dynscope-related flags that get tweaked during
optimization, moving all consumers to using InterpreterContext
and eliminating the flags altogether. This will help #6319
specifically by ensuring a non-full IC will not see full IC's
dynscope flag changes.

This also introduces a new overridable initialize method to IC so
FullIC can override it to do nothing, eliminating some needless
overrides. These two classes should be modified to be disjoint in
the future.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants