mperham/dalli — Issue #167: contention in thread mutex
Author: chrisochs
Created: 2012-02-03 00:38:50+00:00
State: open

This is with jruby-1.6.5. When load testing we are seeing a lot of contention with the thread locking. It eventually results in 80% of our threads looking like the following thread dump.

This is a major blocker for us so I'll be taking a stab at fixing it myself. If anyone has suggestions on the right way to fix this please let me know. Usually, we create an instance per thread for network clients, as mutexes tend to be problematic for high volume apps. So my first approach would be to have something like Dalli.current that returns a per thread instance of dalli, and remove the mutex altogether. But I need to understand better what the mutex is protecting before I do that.

Chris

java.lang.Thread.State: WAITING
at java.lang.Object.wait(Native Method)
- waiting on <6a8ca56a> (a org.jruby.libraries.ThreadLibrary$ConditionVariable)
at java.lang.Object.wait(Object.java:443)
at org.jruby.RubyThread$SleepTask.run(RubyThread.java:816)
at org.jruby.RubyThread.executeBlockingTask(RubyThread.java:832)
at org.jruby.RubyThread.wait_timeout(RubyThread.java:1102)
at org.jruby.libraries.ThreadLibrary$ConditionVariable.wait_ruby(ThreadLibrary.java:286)
at org.jruby.libraries.ThreadLibrary$ConditionVariable$i$0$1$wait_ruby.call(ThreadLibrary$ConditionVariable$i$0$1$wait_ruby.gen:65535)
at org.jruby.internal.runtime.methods.JavaMethod$JavaMethodN.call(JavaMethod.java:630)
at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:207)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:167)
at rubyjit.mon_acquire_E0AE09F8DFE5A26563727EB04CB29AE4A5E85C7F.__file__(file:/home/tomcat/e2-apache-tomcat-7.0.23/webapps/ROOT/WEB-INF/lib/jruby-complete.jar!/META-INF/jruby.home/lib/ruby/1.8/monitor.rb:240)
at rubyjit.mon_acquire_E0AE09F8DFE5A26563727EB04CB29AE4A5E85C7F.__file__(file:/home/tomcat/e2-apache-tomcat-7.0.23/webapps/ROOT/WEB-INF/lib/jruby-complete.jar!/META-INF/jruby.home/lib/ruby/1.8/monitor.rb)
at org.jruby.internal.runtime.methods.JittedMethod.call(JittedMethod.java:167)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:167)
at rubyjit.mon_enter_616E5B6E4B9195DFD728901C474061A50A32182A.block_0$RUBY$__file__(file:/home/tomcat/e2-apache-tomcat-7.0.23/webapps/ROOT/WEB-INF/lib/jruby-complete.jar!/META-INF/jruby.home/lib/ruby/1.8/monitor.rb:166)
at rubyjit$mon_enter_616E5B6E4B9195DFD728901C474061A50A32182A$block_0$RUBY$__file__.call(rubyjit$mon_enter_616E5B6E4B9195DFD728901C474061A50A32182A$block_0$RUBY$__file__:65535)
at org.jruby.runtime.CompiledBlock.yield(CompiledBlock.java:112)
at org.jruby.runtime.CompiledBlock.yield(CompiledBlock.java:95)
at org.jruby.runtime.Block.yield(Block.java:130)
at org.jruby.libraries.ThreadLibrary$Mutex.synchronize(ThreadLibrary.java:224)
at org.jruby.libraries.ThreadLibrary$Mutex$i$0$0$synchronize.call(ThreadLibrary$Mutex$i$0$0$synchronize.gen:65535)
at org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:142)
at org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:153)
at rubyjit.mon_enter_616E5B6E4B9195DFD728901C474061A50A32182A.__file__(file:/home/tomcat/e2-apache-tomcat-7.0.23/webapps/ROOT/WEB-INF/lib/jruby-complete.jar!/META-INF/jruby.home/lib/ruby/1.8/monitor.rb:165)
at rubyjit.mon_enter_616E5B6E4B9195DFD728901C474061A50A32182A.__file__(file:/home/tomcat/e2-apache-tomcat-7.0.23/webapps/ROOT/WEB-INF/lib/jruby-complete.jar!/META-INF/jruby.home/lib/ruby/1.8/monitor.rb)
at org.jruby.internal.runtime.methods.JittedMethod.call(JittedMethod.java:127)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:133)
at rubyjit.mon_synchronize_2B8A390F8E255A12A7AE14EEAC36AF0930A6A72B.__file__(file:/home/tomcat/e2-apache-tomcat-7.0.23/webapps/ROOT/WEB-INF/lib/jruby-complete.jar!/META-INF/jruby.home/lib/ruby/1.8/monitor.rb:189)
at rubyjit.mon_synchronize_2B8A390F8E255A12A7AE14EEAC36AF0930A6A72B.__file__(file:/home/tomcat/e2-apache-tomcat-7.0.23/webapps/ROOT/WEB-INF/lib/jruby-complete.jar!/META-INF/jruby.home/lib/ruby/1.8/monitor.rb)
at org.jruby.internal.runtime.methods.JittedMethod.call(JittedMethod.java:147)
at org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:174)
at org.jruby.internal.runtime.methods.AliasMethod.call(AliasMethod.java:81)
at org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:142)
at org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:153)
at rubyjit.alive?_A5A5D5D81A7B6DDB86085962614D1D3A24DB4120.__file__(/home/tomcat/tomcat20/webapps/ROOT/WEB-INF/gems/gems/dalli-1.0.5/lib/dalli/options.rb:23)
at rubyjit.alive?_A5A5D5D81A7B6DDB86085962614D1D3A24DB4120.__file__(/home/tomcat/tomcat20/webapps/ROOT/WEB-INF/gems/gems/dalli-1.0.5/lib/dalli/options.rb)
at org.jruby.internal.runtime.methods.JittedMethod.call(JittedMethod.java:127)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:133)
at rubyjit.server_for_key_878DBE368B0D07A4B1CFEBEA368D466FBC9FB0E0.__file__(/home/tomcat/tomcat20/webapps/ROOT/WEB-INF/gems/gems/dalli-1.0.5/lib/dalli/ring.rb:42)
at rubyjit.server_for_key_878DBE368B0D07A4B1CFEBEA368D466FBC9FB0E0.__file__(/home/tomcat/tomcat20/webapps/ROOT/WEB-INF/gems/gems/dalli-1.0.5/lib/dalli/ring.rb)
at org.jruby.internal.runtime.methods.JittedMethod.call(JittedMethod.java:167)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:167)
at rubyjit.perform_3A4B696045757A40EFCEA2684239B4497CD3D860.chained_0_rescue_1$RUBY$SYNTHETIC__file__(/home/tomcat/tomcat20/webapps/ROOT/WEB-INF/gems/gems/dalli-1.0.5/lib/dalli/client.rb:239)
at rubyjit.perform_3A4B696045757A40EFCEA2684239B4497CD3D860.__file__(/home/tomcat/tomcat20/webapps/ROOT/WEB-INF/gems/gems/dalli-1.0.5/lib/dalli/client.rb:238)
at rubyjit.perform_3A4B696045757A40EFCEA2684239B4497CD3D860.__file__(/home/tomcat/tomcat20/webapps/ROOT/WEB-INF/gems/gems/dalli-1.0.5/lib/dalli/client.rb)
at org.jruby.ast.executable.AbstractScript.__file__(AbstractScript.java:46)
at org.jruby.internal.runtime.methods.JittedMethod.call(JittedMethod.java:207)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:201)
at rubyjit.delete_25563009FE82B53FAE21F6C481F6EA9AEA3FA61B.__file__(/home/tomcat/tomcat20/webapps/ROOT/WEB-INF/gems/gems/dalli-1.0.5/lib/dalli/client.rb:146)
at rubyjit.delete_25563009FE82B53FAE21F6C481F6EA9AEA3FA61B.__file__(/home/tomcat/tomcat20/webapps/ROOT/WEB-INF/gems/gems/dalli-1.0.5/lib/dalli/client.rb)