Mutex sleeps indefinitely with timeout <= 0.0001 seconds #4862
Description
Environment
Provide at least:
- JRuby version (
jruby -v) and command line (flags, JRUBY_OPTS, etc)
JRuby 9.1.14.0
- Operating system and platform (e.g.
uname -a)
Windows
Expected Behavior
- Describe your expectation of how JRuby should behave, perhaps by showing how CRuby/MRI behaves.
When sleep() is called with a timeout which is 0.0001 or less (including 0) seconds on a locked mutex, the sleep() appears to be indefinite. For MRI 2.4.2, however, the sleep times out quickly with these smaller values.
- Provide an executable Ruby script or a link to an example repository.
I ran the following script to reproduce this issue:
m = Mutex.new
m.synchronize do
[0.001, 0.0001, 0].each do |timeout|
puts "About to sleep for #{timeout} seconds..."
m.sleep(timeout)
puts "Done sleeping for #{timeout} seconds"
end
endWith MRI 2.4.2, the following output appears and the script ends normally:
About to sleep for 0.001 seconds...
Done sleeping for 0.001 seconds
About to sleep for 0.0001 seconds...
Done sleeping for 0.0001 seconds
About to sleep for 0 seconds...
Done sleeping for 0 seconds
Actual Behavior
- Describe or show the actual behavior.
With JRuby 9.1.14.0, only part of the output appears:
About to sleep for 0.001 seconds...
Done sleeping for 0.001 seconds
About to sleep for 0.0001 seconds...
Even after leaving the script running for several minutes, the next expected message never appears: "Done sleeping for 0.0001 seconds". The same apparent hang appears if a sleep for 0 seconds - without the preceding sleep for 0.0001 seconds - occurs.
Here is a backtrace for the main thread while in the hang state:
"main" #1 prio=5 os_prio=0 tid=0x000000000355e000 nid=0x7ff0 waiting on condition [0x000000000375d000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000e0efc748> (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:1445)
at org.jruby.RubyThread$SleepTask2.run(RubyThread.java:1434)
at org.jruby.RubyThread.executeTask(RubyThread.java:1486)
at org.jruby.RubyThread.sleep(RubyThread.java:1354)
at org.jruby.ext.thread.Mutex.sleep(Mutex.java:135)
at org.jruby.ext.thread.Mutex$INVOKER$i$sleep.call(Mutex$INVOKER$i$sleep.gen)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:153)
at C_3a_.mutex_sleep.invokeOther4:sleep(mutex_sleep.rb:5)
at C_3a_.mutex_sleep.RUBY$block$\=mutex_sleep\,rb$1(mutex_sleep.rb:5)
at java.lang.invoke.LambdaForm$DMH/468121027.invokeStatic_L8_L(LambdaForm$DMH)
at java.lang.invoke.LambdaForm$MH/422392391.invokeExact_MT(LambdaForm$MH)
at org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:156)
at org.jruby.runtime.BlockBody.yield(BlockBody.java:114)
at org.jruby.runtime.Block.yield(Block.java:165)
at org.jruby.RubyArray.each(RubyArray.java:1734)
at org.jruby.RubyArray$INVOKER$i$0$0$each.call(RubyArray$INVOKER$i$0$0$each.gen)
at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:308)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:137)
at org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:142)
at C_3a_.mutex_sleep.invokeOther12:each(mutex_sleep.rb:3)
at C_3a_.mutex_sleep.RUBY$block$\=mutex_sleep\,rb$0(mutex_sleep.rb:3)
at java.lang.invoke.LambdaForm$DMH/468121027.invokeStatic_L8_L(LambdaForm$DMH)
at java.lang.invoke.LambdaForm$MH/422392391.invokeExact_MT(LambdaForm$MH)
at org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:156)
at org.jruby.runtime.IRBlockBody.yieldSpecific(IRBlockBody.java:80)
at org.jruby.runtime.Block.yieldSpecific(Block.java:134)
at org.jruby.ext.thread.Mutex.synchronize(Mutex.java:148)
at org.jruby.ext.thread.Mutex$INVOKER$i$0$0$synchronize.call(Mutex$INVOKER$i$0$0$synchronize.gen)
at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:308)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:137)
at org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:142)
at C_3a_.mutex_sleep.invokeOther15:synchronize(mutex_sleep.rb:2)
at C_3a_.mutex_sleep.RUBY$script(mutex_sleep.rb:2)
at java.lang.invoke.LambdaForm$DMH/1450495309.invokeStatic_L7_L(LambdaForm$DMH)
at java.lang.invoke.LambdaForm$BMH/84739718.reinvoke(LambdaForm$BMH)
at java.lang.invoke.LambdaForm$MH/632249781.invoker(LambdaForm$MH)
at java.lang.invoke.LambdaForm$MH/434176574.invokeExact_MT(LambdaForm$MH)
at java.lang.invoke.MethodHandle.invokeWithArguments(MethodHandle.java:627)
at org.jruby.ir.Compiler$1.load(Compiler.java:95)
at org.jruby.Ruby.runScript(Ruby.java:828)
at org.jruby.Ruby.runNormally(Ruby.java:747)
at org.jruby.Ruby.runNormally(Ruby.java:765)
at org.jruby.Ruby.runFromMain(Ruby.java:578)
at org.jruby.Main.doRunFromMain(Main.java:417)
at org.jruby.Main.internalRun(Main.java:305)
at org.jruby.Main.run(Main.java:232)
at org.jruby.Main.main(Main.java:204
I had some code which would sleep for 0 seconds periodically to allow a waiter to take the mutex and change some state to interrupt a long running process. Bumping the timeout up to a slightly higher value - like 0.001 seconds - is a reasonable workaround. Just thought it might be good to point out the discrepancy as compared to MRI Ruby behavior.