Details

    • Number of attachments :
      0

      Description

      Why there is a lock here, got me...

      java.lang.Thread.State: BLOCKED (on object monitor)
      at java.util.Hashtable.get(Hashtable.java:333)

      • locked <0x00000005e0162170> (a java.util.Hashtable)
        at java.text.NumberFormat.getInstance(NumberFormat.java:742)
        at java.text.NumberFormat.getNumberInstance(NumberFormat.java:390)
        at org.jruby.util.Sprintf.rubySprintfToBuffer(Sprintf.java:815)
        at org.jruby.util.Sprintf.rubySprintfToBuffer(Sprintf.java:240)
        at org.jruby.util.Sprintf.sprintf(Sprintf.java:214)
        at org.jruby.RubyString.opFormatCommon(RubyString.java:1157)
        at org.jruby.RubyString.op_format(RubyString.java:1136)
        at org.jruby.RubyString$i$1$0$op_format.call(RubyString$i$1$0$op_format.gen:65535)
        at org.jruby.internal.runtime.methods.JavaMethod$JavaMethodOneOrN.call(JavaMethod.java:728)
        at org.jruby.internal.runtime.methods.AliasMethod.call(AliasMethod.java:86)
        at org.jruby.RubyClass.finvoke(RubyClass.java:576)
        at org.jruby.RubyBasicObject.send(RubyBasicObject.java:2778)
        at org.jruby.RubyKernel.send(RubyKernel.java:2084)
        at org.jruby.RubyKernel$s$send.call(RubyKernel$s$send.gen:65535)
        at org.jruby.internal.runtime.methods.JavaMethod$JavaMethodZeroOrOneOrTwoOrNBlock.call(JavaMethod.java:283)
        at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:201)
        at rubyjit.String#%E980BE3DE7F9B6C8EEDF9D9120045507924ECC51.file_(/home/tomcat/tomcat10/webapps/ROOT/WEB-INF/gems/gems/i18n-0.5.0/lib/i18n/core_ext/string/interpolate.rb:101)

        Activity

        Hide
        Charles Oliver Nutter added a comment -

        Yeah, pretty silly. The table it's synchronizing against basically just caches the format strings for a given locale. Because that cache might be used across threads, it's a Hashtable...which is unconditionally synchronized.

        I'm sure there's a potential OpenJDK patch here, but for now I'm going to look into how we can just avoid calling the default methods.

        Show
        Charles Oliver Nutter added a comment - Yeah, pretty silly. The table it's synchronizing against basically just caches the format strings for a given locale. Because that cache might be used across threads, it's a Hashtable...which is unconditionally synchronized. I'm sure there's a potential OpenJDK patch here, but for now I'm going to look into how we can just avoid calling the default methods.
        Hide
        Charles Oliver Nutter added a comment -

        This one is pretty sickening. I added a thread-local map from Local to NumberFormat, since any given thread's only going to be using one at a time (unlike MessageDigest), and the improvement is pretty gross:

        before:

        system ~/projects/jruby $ jruby bench/bench_sprintf.rb 
                  '%g' % 1.0   641602.5 (7.2%) i/s -    3178900 in   4.987003s (cycle=9575)
        4x contended '%g' % 1.0
                               144650.4 (33.7%) i/s -     586908 in   4.908971s (cycle=137)
        
        system ~/projects/jruby $ jruby bench/bench_sprintf.rb 
                  '%g' % 1.0   641014.2 (6.8%) i/s -    3183627 in   4.995059s (cycle=10303)
        4x contended '%g' % 1.0
                               143091.6 (33.9%) i/s -     581298 in   4.908607s (cycle=139)
        

        after:

        system ~/projects/jruby $ jruby bench/bench_sprintf.rb 
                  '%g' % 1.0  1835549.1 (9.1%) i/s -    9061846 in   4.985225s (cycle=8306)
        4x contended '%g' % 1.0
                               248249.2 (20.8%) i/s -    1086442 in   4.904267s (cycle=142)
        
        system ~/projects/jruby $ jruby bench/bench_sprintf.rb 
                  '%g' % 1.0  1628054.7 (9.8%) i/s -    8017965 in   4.986371s (cycle=18955)
        4x contended '%g' % 1.0
                               253320.0 (29.5%) i/s -    1015344 in   4.892082s (cycle=144)
        

        Will commit to master. Keep these coming, they're great!

        Show
        Charles Oliver Nutter added a comment - This one is pretty sickening. I added a thread-local map from Local to NumberFormat, since any given thread's only going to be using one at a time (unlike MessageDigest), and the improvement is pretty gross: before: system ~/projects/jruby $ jruby bench/bench_sprintf.rb '%g' % 1.0 641602.5 (7.2%) i/s - 3178900 in 4.987003s (cycle=9575) 4x contended '%g' % 1.0 144650.4 (33.7%) i/s - 586908 in 4.908971s (cycle=137) system ~/projects/jruby $ jruby bench/bench_sprintf.rb '%g' % 1.0 641014.2 (6.8%) i/s - 3183627 in 4.995059s (cycle=10303) 4x contended '%g' % 1.0 143091.6 (33.9%) i/s - 581298 in 4.908607s (cycle=139) after: system ~/projects/jruby $ jruby bench/bench_sprintf.rb '%g' % 1.0 1835549.1 (9.1%) i/s - 9061846 in 4.985225s (cycle=8306) 4x contended '%g' % 1.0 248249.2 (20.8%) i/s - 1086442 in 4.904267s (cycle=142) system ~/projects/jruby $ jruby bench/bench_sprintf.rb '%g' % 1.0 1628054.7 (9.8%) i/s - 8017965 in 4.986371s (cycle=18955) 4x contended '%g' % 1.0 253320.0 (29.5%) i/s - 1015344 in 4.892082s (cycle=144) Will commit to master. Keep these coming, they're great!
        Hide
        Charles Oliver Nutter added a comment -

        Committed to master...we're close to 1.6.7 so it won't go in that release, but feel free to lobby for it to go into 1.6.8. Otherwise, it will be in 1.7 soon.

        commit 5ca2c954e0bedf1ae9b7a9fce7ed0389c2944039
        Author: Charles Oliver Nutter <headius@headius.com>
        Date:   Mon Feb 20 18:09:03 2012 -0600
        
            Fix JRUBY-6476: org.jruby.util.Sprintf.rubySprintfToBuffer causing thread locks
            
            The OpenJDK impl of NumberFormat has a Hashtable it uses to cache
            per-locale format strings. Unfortunately, this represents a
            bottleneck if you have many threads all hitting NumberFormat at
            once. My fix is to set up thread-local map from Locale to
            NumberFormat, saving an instance and avoiding the locks and lookup
            logic.
            
            The numbers say it all:
            
            before:
            
            system ~/projects/jruby $ jruby bench/bench_sprintf.rb
                      '%g' % 1.0   641602.5 (±7.2%) i/s -    3178900 in   4.987003s (cycle=9575)
            4x contended '%g' % 1.0
                                   144650.4 (±33.7%) i/s -     586908 in   4.908971s (cycle=137)
            
            system ~/projects/jruby $ jruby bench/bench_sprintf.rb
                      '%g' % 1.0   641014.2 (±6.8%) i/s -    3183627 in   4.995059s (cycle=10303)
            4x contended '%g' % 1.0
                                   143091.6 (±33.9%) i/s -     581298 in   4.908607s (cycle=139)
            after:
            
            system ~/projects/jruby $ jruby bench/bench_sprintf.rb
                      '%g' % 1.0  1835549.1 (±9.1%) i/s -    9061846 in   4.985225s (cycle=8306)
            4x contended '%g' % 1.0
                                   248249.2 (±20.8%) i/s -    1086442 in   4.904267s (cycle=142)
            
            system ~/projects/jruby $ jruby bench/bench_sprintf.rb
                      '%g' % 1.0  1628054.7 (±9.8%) i/s -    8017965 in   4.986371s (cycle=18955)
            4x contended '%g' % 1.0
                                   253320.0 (±29.5%) i/s -    1015344 in   4.892082s (cycle=144)
        
        Show
        Charles Oliver Nutter added a comment - Committed to master...we're close to 1.6.7 so it won't go in that release, but feel free to lobby for it to go into 1.6.8. Otherwise, it will be in 1.7 soon. commit 5ca2c954e0bedf1ae9b7a9fce7ed0389c2944039 Author: Charles Oliver Nutter <headius@headius.com> Date: Mon Feb 20 18:09:03 2012 -0600 Fix JRUBY-6476: org.jruby.util.Sprintf.rubySprintfToBuffer causing thread locks The OpenJDK impl of NumberFormat has a Hashtable it uses to cache per-locale format strings. Unfortunately, this represents a bottleneck if you have many threads all hitting NumberFormat at once. My fix is to set up thread-local map from Locale to NumberFormat, saving an instance and avoiding the locks and lookup logic. The numbers say it all: before: system ~/projects/jruby $ jruby bench/bench_sprintf.rb '%g' % 1.0 641602.5 (±7.2%) i/s - 3178900 in 4.987003s (cycle=9575) 4x contended '%g' % 1.0 144650.4 (±33.7%) i/s - 586908 in 4.908971s (cycle=137) system ~/projects/jruby $ jruby bench/bench_sprintf.rb '%g' % 1.0 641014.2 (±6.8%) i/s - 3183627 in 4.995059s (cycle=10303) 4x contended '%g' % 1.0 143091.6 (±33.9%) i/s - 581298 in 4.908607s (cycle=139) after: system ~/projects/jruby $ jruby bench/bench_sprintf.rb '%g' % 1.0 1835549.1 (±9.1%) i/s - 9061846 in 4.985225s (cycle=8306) 4x contended '%g' % 1.0 248249.2 (±20.8%) i/s - 1086442 in 4.904267s (cycle=142) system ~/projects/jruby $ jruby bench/bench_sprintf.rb '%g' % 1.0 1628054.7 (±9.8%) i/s - 8017965 in 4.986371s (cycle=18955) 4x contended '%g' % 1.0 253320.0 (±29.5%) i/s - 1015344 in 4.892082s (cycle=144)

          People

          • Assignee:
            Charles Oliver Nutter
            Reporter:
            Chris Ochs
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: