Details

    • Type: Bug Bug
    • Status: Resolved Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: JRuby 1.6
    • Fix Version/s: JRuby 1.7.0.pre1
    • Component/s: None
    • Labels:
      None
    • Environment:
      Ubuntu Linux, running jRuby under RVM
    • Number of attachments :
      0

      Description

      I have a script called "works.rb". It's code is pretty simple:

      require 'jruby/profiler'

      profile_data = JRuby::Profiler.profile do
      1000.times do |n| Hash.new end
      end

      profile_printer = JRuby::Profiler::GraphProfilePrinter.new(profile_data)
      profile_printer.printProfile(STDOUT)}}

      If I run export JRUBY_OPTS="--profile.api" && ruby works.rb everything works as expected. Here's the output:

      Profiling enabled; ^C shutdown will now dump profile info

      Total time: 0.02

      %total %self total self children calls name
      ---------------------------------------------------------------------------------------------------------
      100% 0% 0.02 0.00 0.02 1 (top)
      0.02 0.01 0.01 1/1 Fixnum#times
      ---------------------------------------------------------------------------------------------------------
      0.02 0.01 0.01 1/1 (top)
      100% 43% 0.02 0.01 0.01 1 Fixnum#times
      0.01 0.01 0.00 1000/1000 Class#new
      ---------------------------------------------------------------------------------------------------------
      0.01 0.01 0.00 1000/1000 Fixnum#times
      56% 38% 0.01 0.01 0.00 1000 Class#new
      0.00 0.00 0.00 1000/1000 Hash#initialize
      ---------------------------------------------------------------------------------------------------------
      0.00 0.00 0.00 1000/1000 Class#new
      18% 18% 0.00 0.00 0.00 1000 Hash#initialize

      However, JRUBY_OPTS gets ignored when running "works.rb" inside a rake task. I have the following Rakefile:

      task :fails do
      ruby "works.rb"
      end

      Running export JRUBY_OPTS="--profile.api" && rake fails returns:

      Profiling enabled; ^C shutdown will now dump profile info
      (in /home/goncalossilva/Desktop)

        • Invoke fails (first_time)
        • Execute fails
          /home/goncalossilva/.rvm/rubies/jruby-1.6.0/bin/jruby works.rb

      Total time: 0.00

      %total %self total self children calls name
      ---------------------------------------------------------------------------------------------------------
      100% 100% 0.00 0.00 0.00 0 (top)

        Activity

        Hide
        Charles Oliver Nutter added a comment -

        This is due to the way we process JRUBY_OPTS conflicting with how we typically launch "ruby" commands. JRUBY_OPTS is processed by the command that launches JRuby, which is either a bash script or an executable. Normally, "ruby" commands run by e.g. Kernel#system are launched in-process to avoid a full JVM startup hit. This means that when using Rake's "ruby", we're starting a second JRuby instance in the same JVM, bypassing the launcher.

        We have debated turning off "in-process launching" for some time, but are concerned about the startup hit that may result (as well as the many applications that launch commands like `ruby blah.rb` which wouldnt' find the "jruby" command).

        Workarounds for you for the moment:

        • Run JRuby with -Xlaunch.inproc=false (passed to the outermost JRuby instance). This will avoid the in-process launching.
        • Use RUBYOPT, which is processed by all JRuby runtimes (even in-process ones).

        Leaving this open for discussion about other workarounds and debate about turning off or reducing in-process launching.

        Show
        Charles Oliver Nutter added a comment - This is due to the way we process JRUBY_OPTS conflicting with how we typically launch "ruby" commands. JRUBY_OPTS is processed by the command that launches JRuby, which is either a bash script or an executable. Normally, "ruby" commands run by e.g. Kernel#system are launched in-process to avoid a full JVM startup hit. This means that when using Rake's "ruby", we're starting a second JRuby instance in the same JVM, bypassing the launcher. We have debated turning off "in-process launching" for some time, but are concerned about the startup hit that may result (as well as the many applications that launch commands like `ruby blah.rb` which wouldnt' find the "jruby" command). Workarounds for you for the moment: Run JRuby with -Xlaunch.inproc=false (passed to the outermost JRuby instance). This will avoid the in-process launching. Use RUBYOPT, which is processed by all JRuby runtimes (even in-process ones). Leaving this open for discussion about other workarounds and debate about turning off or reducing in-process launching.
        Hide
        Gonšalo Silva added a comment -

        Actually, using RUBYOPT doesn't seem to work on my setup.

        Doing:
        export RUBYOPT="--profile.api" && rake fails
        still yields no results.

        However, doing:
        export JRUBY_OPTS="-Xlaunch.inproc=false --profile.api" && rake fails
        works like a charm. As long as this is documented, I don't think it's really a problem.

        Thanks!

        Show
        Gonšalo Silva added a comment - Actually, using RUBYOPT doesn't seem to work on my setup. Doing: export RUBYOPT="--profile.api" && rake fails still yields no results. However, doing: export JRUBY_OPTS="-Xlaunch.inproc=false --profile.api" && rake fails works like a charm. As long as this is documented, I don't think it's really a problem. Thanks!
        Hide
        Charles Oliver Nutter added a comment -

        As of JRuby 1.7, we always launch a process for "ruby" and "jruby" commands, which fixes this issue.

        Show
        Charles Oliver Nutter added a comment - As of JRuby 1.7, we always launch a process for "ruby" and "jruby" commands, which fixes this issue.

          People

          • Assignee:
            Charles Oliver Nutter
            Reporter:
            Gonšalo Silva
          • Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: