JRuby (please use github issues at http://bugs.jruby.org)
  1. JRuby (please use github issues at http://bugs.jruby.org)
  2. JRUBY-6859

java.lang.ArrayIndexOutOfBoundsException when using --profile.api . MAX_PROFILE_METHODS too low?

    Details

    • Type: Bug Bug
    • Status: Resolved Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: JRuby 1.6.7
    • Fix Version/s: JRuby 1.7.0.RC1
    • Component/s: Core Classes/Modules
    • Labels:
      None
    • Environment:
      Mac OS X 10.7.4
      Java 1.7.0_05
      jruby 1.6.7.2
    • Number of attachments :
      0

      Description

      I get java.lang.ArrayIndexOutOfBoundsException: 100000 while trying to profile my rails app.

      With JRUBY_OPTS set to '--1.9 -Xlaunch.inproc=false --profile.api', running rails s -p 3001 gives:

      Profiling enabled; ^C shutdown will now dump profile info
      Profiling enabled; ^C shutdown will now dump profile info
      => Booting WEBrick
      => Rails 3.2.8 application starting in development on http://0.0.0.0:3001
      => Call with -d to detach
      => Ctrl-C to shutdown server
      spawn> default options = {:method=>:thread}
      Exiting
      LoadError: load error: sass/plugin -- java.lang.ArrayIndexOutOfBoundsException: 100000
                 require at org/jruby/RubyKernel.java:1042
                 require at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/activesupport-3.2.8/lib/active_support/dependencies.rb:251
         load_dependency at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/activesupport-3.2.8/lib/active_support/dependencies.rb:236
                 require at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/activesupport-3.2.8/lib/active_support/dependencies.rb:251
                  (root) at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/haml-3.1.6/lib/sass/rails3_shim.rb:15
           instance_eval at org/jruby/RubyBasicObject.java:1730
            execute_hook at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/activesupport-3.2.8/lib/active_support/lazy_load_hooks.rb:36
          run_load_hooks at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/activesupport-3.2.8/lib/active_support/lazy_load_hooks.rb:43
                    each at org/jruby/RubyArray.java:1615
          run_load_hooks at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/activesupport-3.2.8/lib/active_support/lazy_load_hooks.rb:42
               Bootstrap at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/railties-3.2.8/lib/rails/application/bootstrap.rb:69
           instance_exec at org/jruby/RubyBasicObject.java:1757
                     run at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/railties-3.2.8/lib/rails/initializable.rb:30
        run_initializers at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/railties-3.2.8/lib/rails/initializable.rb:55
                    each at org/jruby/RubyArray.java:1615
        run_initializers at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/railties-3.2.8/lib/rails/initializable.rb:54
             initialize! at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/railties-3.2.8/lib/rails/application.rb:136
                __send__ at org/jruby/RubyBasicObject.java:1698
                    send at org/jruby/RubyKernel.java:2097
          method_missing at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/railties-3.2.8/lib/rails/railtie/configurable.rb:30
                  (root) at /Users/tim/git/1/jux/config/environment.rb:8
                 require at org/jruby/RubyKernel.java:1042
                 require at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/activesupport-3.2.8/lib/active_support/dependencies.rb:251
         load_dependency at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/activesupport-3.2.8/lib/active_support/dependencies.rb:236
                 require at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/activesupport-3.2.8/lib/active_support/dependencies.rb:251
              parse_file at /Users/tim/git/1/jux/config/environment.rb:4
           instance_eval at org/jruby/RubyBasicObject.java:1730
              initialize at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/rack-1.4.1/lib/rack/builder.rb:51
              parse_file at /Users/tim/git/1/jux/config.ru:1
                    eval at org/jruby/RubyKernel.java:1088
              parse_file at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/rack-1.4.1/lib/rack/builder.rb:40
                     app at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/rack-1.4.1/lib/rack/server.rb:200
                     app at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/railties-3.2.8/lib/rails/commands/server.rb:46
             wrapped_app at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/rack-1.4.1/lib/rack/server.rb:301
                   start at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/rack-1.4.1/lib/rack/server.rb:252
                   start at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/railties-3.2.8/lib/rails/commands/server.rb:70
                  (root) at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/railties-3.2.8/lib/rails/commands.rb:55
                     tap at org/jruby/RubyKernel.java:1787
                  (root) at /Users/tim/.rvm/gems/jruby-1.6.7.2/gems/railties-3.2.8/lib/rails/commands.rb:50
                 require at org/jruby/RubyKernel.java:1042
                  (root) at script/rails:6
      

      This does not happen if I remove the --profile.api option.

      Searching jruby 1.6.7.2 source code for instances of 100000 gives:

      $ grep -R 100000 src | grep -v 1000000 
      src/org/jruby/compiler/ASTInspector.java:    public static final int RETRY = 0x100000; // contains a retry
      src/org/jruby/demo/TextAreaReadline.java:    private static final int MAX_DOC_SIZE = 100000;
      src/org/jruby/Ruby.java:    private static final int MAX_PROFILE_METHODS = 100000;
      

      which leads me to believe that MAX_PROFILE_METHODS is too low.

        Activity

        Hide
        Tim Olsen added a comment -

        Problem goes away if I increase MAX_PROFILE_METHODS to 500000. I've made a pull request: https://github.com/jruby/jruby/pull/269

        Show
        Tim Olsen added a comment - Problem goes away if I increase MAX_PROFILE_METHODS to 500000. I've made a pull request: https://github.com/jruby/jruby/pull/269
        Hide
        Charles Oliver Nutter added a comment -

        Fascinating! We should print a warning when we reach the limit and provide a way to increase it.

        Show
        Charles Oliver Nutter added a comment - Fascinating! We should print a warning when we reach the limit and provide a way to increase it.
        Hide
        Charles Oliver Nutter added a comment -

        It appears that I did have a guard for exceeding the maximum number of methods, but it was not quite correct; it checked for index > max and then used max as the size and index as the offset into an array; that would cause the 100000th method to AIOOB.

        I fixed that logic to use >=, to issue a warning when no more methods will be added to the profile, and to allow configuring the maximum number of methods profiled via -Xprofile.max.methods=###### (or -Djruby.profile.max.methods=######).

        commit 3baeea6eec82d127944cef58259e9a2149fa551a
        Author: Charles Oliver Nutter <headius@headius.com>
        Date:   Mon Aug 27 15:05:50 2012 -0500
        
            Fix JRUBY-6859
            
            java.lang.ArrayIndexOutOfBoundsException when using --profile.api . MAX_PROFILE_METHODS too low?
            
            This was actually fixed already in the 1.7 line in aabfa79f4 but
            this commit adds a warning (once) and configurable property to
            bump up the max size.
        
        :100644 100644 f79aa3e... 789da30... M	src/org/jruby/Ruby.java
        :100644 100644 fc4e64a... b3830bd... M	src/org/jruby/RubyInstanceConfig.java
        :100644 100644 6f87b79... 91d007c... M	src/org/jruby/common/IRubyWarnings.java
        :100644 100644 d5e55b9... fbb55b1... M	src/org/jruby/util/cli/Category.java
        :100644 100644 b3d16a0... f5afe1f... M	src/org/jruby/util/cli/Options.java
        
        Show
        Charles Oliver Nutter added a comment - It appears that I did have a guard for exceeding the maximum number of methods, but it was not quite correct; it checked for index > max and then used max as the size and index as the offset into an array; that would cause the 100000th method to AIOOB. I fixed that logic to use >=, to issue a warning when no more methods will be added to the profile, and to allow configuring the maximum number of methods profiled via -Xprofile.max.methods=###### (or -Djruby.profile.max.methods=######). commit 3baeea6eec82d127944cef58259e9a2149fa551a Author: Charles Oliver Nutter <headius@headius.com> Date: Mon Aug 27 15:05:50 2012 -0500 Fix JRUBY-6859 java.lang.ArrayIndexOutOfBoundsException when using --profile.api . MAX_PROFILE_METHODS too low? This was actually fixed already in the 1.7 line in aabfa79f4 but this commit adds a warning (once) and configurable property to bump up the max size. :100644 100644 f79aa3e... 789da30... M src/org/jruby/Ruby.java :100644 100644 fc4e64a... b3830bd... M src/org/jruby/RubyInstanceConfig.java :100644 100644 6f87b79... 91d007c... M src/org/jruby/common/IRubyWarnings.java :100644 100644 d5e55b9... fbb55b1... M src/org/jruby/util/cli/Category.java :100644 100644 b3d16a0... f5afe1f... M src/org/jruby/util/cli/Options.java
        Hide
        Tim Olsen added a comment -

        Awesome. I like your customizable solution better. Thanks!

        Show
        Tim Olsen added a comment - Awesome. I like your customizable solution better. Thanks!

          People

          • Assignee:
            Charles Oliver Nutter
            Reporter:
            Tim Olsen
          • Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: