autoload & require deadlock #3341
Description
I run into an interesting problem when using require and autoload for the same classes.
I only tested it against JRuby 1.7.21 and quickly looking at the code I'd attributed the problem to combination of a global lock for autoload consts and the require lock.
Since autoload at some point will call require and try to acquire a lock for a file, that same file can contain autoloaded classes that in turn will need to acquire the autoload lock.
I wrote a little, perhaps convoluted, sample code to reproduce the problem. It is gisted here https://gist.github.com/bignacio/7a947960113775477c72 and I copy it below
Save all the files into the same directory and run
$ jruby main.rb
as any good deadlock, it won't happen all the time so you can do something like this
$ while [ true ] ; do jruby main.rb ; done
and wait untill it hangs.
You can confirm the dealock with jstack
Once the process is hung, get its pid and run
jstack -l < pid >
# another_class_base.rb
module DeadlockTest
class AnotherClassBase
end
end
# file: class_a.rb
module DeadlockTest
autoload :AnotherClassBase, 'another_class_base'
class ClassA
class AnotherClass < AnotherClassBase
end
end
end
# file: deadlock_test.rb
module DeadlockTest
autoload :ClassA, 'class_a'
end
# file: main.rb
require 'thread'
require 'deadlock_test'
puts("Starting, JRuby version: #{JRUBY_VERSION}")
ta = Thread.new{
puts("Thread A #{JRuby.reference(Thread.current).native_thread}\n")
# This is not a usual thing for people to do but it can happen if an external component is loading
# your ruby code
# I first run into this problem in a storm topology (via RedStorm), which does
# a similar thing. I'm sure there are other ways to reproduce the same problem
# without a require but this
require 'class_a'
}
tb = Thread.new{
puts("Thread B #{JRuby.reference(Thread.current).native_thread}\n")
o = DeadlockTest::ClassA.new
puts('if you see this, try again :) ')
}
ta.join
tb.joinjstack output
Found one Java-level deadlock:
=============================
"Ruby-0-Thread-3: main.rb:1":
waiting for ownable synchronizer 0x00000007b65c1c40, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
which is held by "Ruby-0-Thread-2: main.rb:1"
"Ruby-0-Thread-2: main.rb:1":
waiting to lock monitor 0x00007f84e9014b38 (object 0x00000007b6408c78, a java.lang.Object),
which is held by "Ruby-0-Thread-3: main.rb:1"
Java stack information for the threads listed above:
===================================================
"Ruby-0-Thread-3: main.rb:1":
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000007b65c1c40> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:870)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1199)
at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLock.java:209)
at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)
at org.jruby.runtime.load.LoadService$RequireLocks.lock(LoadService.java:509)
at org.jruby.runtime.load.LoadService$RequireLocks.access$200(LoadService.java:478)
at org.jruby.runtime.load.LoadService.requireCommon(LoadService.java:444)
at org.jruby.runtime.load.LoadService.autoloadRequire(LoadService.java:418)
at org.jruby.RubyKernel$1.load(RubyKernel.java:202)
at org.jruby.RubyModule$Autoload.getConstant(RubyModule.java:3832)
- locked <0x00000007b6408c78> (a java.lang.Object)
at org.jruby.RubyModule.getAutoloadConstant(RubyModule.java:3621)
at org.jruby.RubyModule.resolveUndefConstant(RubyModule.java:3108)
at org.jruby.RubyModule.getConstantFromNoConstMissing(RubyModule.java:3076)
at org.jruby.ast.executable.RuntimeCache.reCacheFrom(RuntimeCache.java:442)
at org.jruby.ast.executable.RuntimeCache.getValueFrom(RuntimeCache.java:436)
at org.jruby.ast.executable.RuntimeCache.getConstantFrom(RuntimeCache.java:429)
at org.jruby.ast.executable.AbstractScript.getConstantFrom8(AbstractScript.java:336)
at main.block_1$RUBY$__file__(main.rb:19)
at main$block_1$RUBY$__file__.call(main$block_1$RUBY$__file__)
at org.jruby.runtime.CompiledBlock19.yield(CompiledBlock19.java:159)
at org.jruby.runtime.CompiledBlock19.call(CompiledBlock19.java:87)
at org.jruby.runtime.Block.call(Block.java:101)
at org.jruby.RubyProc.call(RubyProc.java:290)
at org.jruby.RubyProc.call(RubyProc.java:228)
at org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:99)
at java.lang.Thread.run(Thread.java:745)
"Ruby-0-Thread-2: main.rb:1":
at org.jruby.RubyModule$Autoload.getConstant(RubyModule.java:3825)
- waiting to lock <0x00000007b6408c78> (a java.lang.Object)
at org.jruby.RubyModule.getAutoloadConstant(RubyModule.java:3621)
at org.jruby.RubyModule.resolveUndefConstant(RubyModule.java:3108)
at org.jruby.RubyModule.getConstantAtSpecial(RubyModule.java:2968)
at org.jruby.RubyModule.defineOrGetClassUnder(RubyModule.java:1281)
at org.jruby.ast.ClassNode.interpret(ClassNode.java:134)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:105)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at org.jruby.evaluator.ASTInterpreter.INTERPRET_CLASS(ASTInterpreter.java:103)
at org.jruby.evaluator.ASTInterpreter.evalClassDefinitionBody(ASTInterpreter.java:280)
at org.jruby.ast.ModuleNode.interpret(ModuleNode.java:120)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:105)
at org.jruby.ast.RootNode.interpret(RootNode.java:129)
at org.jruby.evaluator.ASTInterpreter.INTERPRET_ROOT(ASTInterpreter.java:121)
at org.jruby.Ruby.runInterpreter(Ruby.java:894)
at org.jruby.Ruby.loadFile(Ruby.java:2860)
at org.jruby.runtime.load.ExternalScript.load(ExternalScript.java:66)
at org.jruby.runtime.load.LoadService.tryLoadingLibraryOrScript(LoadService.java:892)
at org.jruby.runtime.load.LoadService.requireCommon(LoadService.java:465)
at org.jruby.runtime.load.LoadService.require(LoadService.java:414)
at org.jruby.RubyKernel.requireCommon(RubyKernel.java:1047)
at org.jruby.RubyKernel.require19(RubyKernel.java:1040)
at org.jruby.RubyKernel$INVOKER$s$1$0$require19.call(RubyKernel$INVOKER$s$1$0$require19.gen)
at org.jruby.internal.runtime.methods.JavaMethod$JavaMethodOneOrNBlock.call(JavaMethod.java:352)
at org.jruby.internal.runtime.methods.AliasMethod.call(AliasMethod.java:61)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:168)
at org.jruby.ast.FCallOneArgNode.interpret(FCallOneArgNode.java:36)
at org.jruby.ast.ReturnNode.interpret(ReturnNode.java:92)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:105)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at org.jruby.ast.IfNode.interpret(IfNode.java:116)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:105)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at org.jruby.ast.RescueNode.executeBody(RescueNode.java:221)
at org.jruby.ast.RescueNode.interpret(RescueNode.java:116)
at org.jruby.evaluator.ASTInterpreter.INTERPRET_METHOD(ASTInterpreter.java:74)
at org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:182)
at org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:203)
at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:326)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:170)
at main.block_0$RUBY$__file__(main.rb:13)
at main$block_0$RUBY$__file__.call(main$block_0$RUBY$__file__)
at org.jruby.runtime.CompiledBlock19.yield(CompiledBlock19.java:159)
at org.jruby.runtime.CompiledBlock19.call(CompiledBlock19.java:87)
at org.jruby.runtime.Block.call(Block.java:101)
at org.jruby.RubyProc.call(RubyProc.java:290)
at org.jruby.RubyProc.call(RubyProc.java:228)
at org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:99)
at java.lang.Thread.run(Thread.java:745)
Found 1 deadlock.