Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with
or
.
Download ZIP

Loading…

Weird JIT behaviour causing Rails to fail serving request #802

Closed
kenips opened this Issue · 29 comments
@kenips

Not sure how to debug this - some insights will be appreciated - but it appears that the JIT compiler has some behaviour causing Rails to fail with NoMethodError (super: no superclass method 'request_parameters') after sometime.

See rails/rails#10916 for backtrace.

@headius
Owner

Ok, I've seen similar reports and thought I had fixed a similar issue. I need information:

  • JRuby version (--version line would be nice)
  • JVM version

The previous issue I fixed was that under JVM + invokedynamic, super invocations were not dispatching to the original name of an aliased method, causing something like this. I suspect if there are still issues, it's a similar flaw.

@kenips

hey @headius, thanks for looking into this. I can't reproduce this locally but it happens consistently on heroku.

I'm using JRuby 1.7..4 and heroku declares their JVM as openjdk7-latest. Let me get a print out of ruby -v in a moment.

@kenips

Actually, faster than I thought, I have it:

jruby 1.7.4 (1.9.3p392) 2013-05-16 fffffff on OpenJDK 64-Bit Server VM 1.7.0_17-b02 +indy [linux-amd64]
@louismrose

I'm also seeing this issue on Heroku, with the following versions of JRuby and Java:

jruby 1.7.4 (1.9.3p392) 2013-05-16 fffffff on OpenJDK 64-Bit Server VM 1.7.0_17-b02 +indy [linux-amd64]

java version "1.7.0_17"
OpenJDK Runtime Environment (IcedTea7 2.3.8) (Ubuntu build 1.7.0_17-b02)
OpenJDK 64-Bit Server VM (build 23.7-b01, mixed mode)

@louismrose

Switching to JRuby 1.7.3 seems to have fixed this issue for us.

@headius
Owner

We do not recommend running invokedynamic on Java 7 earlier than b40, but it may be ok if it's the only thing running on that JVM.

Is it possible for you to try disabling invokedynamic and see if you can still reproduce? Should be -Xcompile.invokedynamic=false at JRuby command line or -Djruby.compile.invokedynamic=false at Java command line (not sure how that translates to Heroku).

@kenips

@schneems any idea on this? Or can we get the JVM updated on heroku for the ruby build pack?

@kenips

Tried this on heroku with heroku config:add JRUBY_OPTS="-Xcompile.invokedynamic=false" and it works fine. Thanks!

@kenips kenips closed this
@headius
Owner

Well I wouldn't be so fast to close this :-)

So we know it's indy-related. I'd like to figure out why.

Do you have any way to reproduce this locally?

@headius headius reopened this
@quixoten

I'm seeing this issue when running specs. Disabling the JIT fixes the problem. Disabling invokedynamic has no affect. The errors are all from line 17 of this file. The error only occurs when running all specs. Running a single spec or even all specs in a single file still works.

Java Version

java version "1.7.0_40"
OpenJDK Runtime Environment (IcedTea 2.4.1) (ArchLinux build 7.u40_2.4.1-1-x86_64)
OpenJDK 64-Bit Server VM (build 24.0-b50, mixed mode)

JRuby Version

jruby 1.7.4 (1.9.3p392) 2013-05-16 2390d3b on OpenJDK 64-Bit Server VM 1.7.0_40-b31 +indy [linux-amd64]
@headius
Owner

Ok...I guess we need to dig deeper.

Those of you able to reproduce this, I have a few flags for you.

-Xjit.logging=true will show methods as they jit...that may help us figure out the method that jit right before it fails
-Xcompile.dump=true will actually dump the bytecode for each method; if we get close to narrowing down the method, you or I can use that to get the bytecode and see if there's an obvious problem.

This is obviously a difficult thing for me to investigate. I would also be willing to connect up to your application instances to try to debug the issue in place. Heroku has installed some special support to allow you to give us temporary access, and it may go more quickly.

I take jit issues very seriously...they're just hard to track down.

@lbredeso

I found a way to reproduce this in my app and stumbled across this thread. Here's my setup:

Java Version

java version "1.7.0_19"
OpenJDK Runtime Environment (rhel-2.3.9.1.el6_4-x86_64)
OpenJDK 64-Bit Server VM (build 23.7-b01, mixed mode)

JRuby Version

jruby 1.7.4 (1.9.3p392) 2013-05-16 2390d3b on OpenJDK 64-Bit Server VM 1.7.0_19-mockbuild_2013_04_17_19_18-b00 +indy [linux-amd64]

I used your suggested flags and created a gist with the logs leading up to the error here (apologies if it's way too much information): https://gist.github.com/lbredeso/6067998

@kenips

Just want to report that Heroku has updated their ruby stack to run on 7u25 so now it works on heroku with invoke dynamic on!

@kenips

Nevermind - spoke too soon. Still seeing on 7u25. @headius if you need access please let me know.

@AndyKriger

Was also seeing this with 1.7.4; rolled back to 1.7.3 and the problem went away. We are not using JIT at all - precompiled Ruby in a war (using warble to build the war). Turned off compilation in the war and the problem still exists. Turned off JIT compliation and we still saw the problem.

This error manifests for us when using Ruby Net::HTTP to authenticate against digest auth on the Rails controller.

EDIT: Removed code that muddied the water as it actually had nothing to do with the problem.

@AndyKriger

Disabled both the authentication and some custom middleware we were using and the problem still exists. So, it seems to be in line with the other reports in this issue.

@abrandoned

This seems to isolate the issue to the handling of alias and calls to super, see replication and comparisons below // cc @headius

puts `ruby --version`

class Parent
  def test
    puts "PARENT"
  end
end

class Child < Parent
  def test
    puts "CHILD"
    super
  end

  alias :test_alias :test
end

o = Child.new
o.test_alias
ruby 1.9.3p374 (2013-01-15 revision 38858) [x86_64-linux]
CHILD
PARENT

ruby 2.0.0p247 (2013-06-27 revision 41674) [x86_64-linux]
CHILD
PARENT

jruby 1.7.2 (1.9.3p327) 2013-01-04 302c706 on OpenJDK 64-Bit Server VM 1.7.0_25-b30 +indy [linux-amd64]
CHILD
PARENT

jruby 1.7.4 (1.9.3p392) 2013-05-16 2390d3b on OpenJDK 64-Bit Server VM 1.7.0_25-b30 +indy [linux-amd64]
CHILD
NoMethodError: super: no superclass method `test_alias'
    test at jruby_802.rb:38
  (root) at jruby_802.rb:45
@abrandoned

another update, when compile mode is set to OFF it seems to work

$ ruby -J-Djruby.compile.mode=OFF jruby_802.rb 
jruby 1.7.4 (1.9.3p392) 2013-05-16 2390d3b on OpenJDK 64-Bit Server VM 1.7.0_25-b30 +indy [linux-amd64]
CHILD
PARENT

Here is a gist of compile.dump=true when the compile mode is JIT https://gist.github.com/abrandoned/6237012

@liveh2o

I am able to replicate this on OS X, but only if I explicitly enable invokedynamic:

$ ruby -Xcompile.invokedynamic=true 802.rb
CHILD
NoMethodError: super: no superclass method `test_alias'
    test at 802.rb:10
  (root) at 802.rb:16

If I also turn off the JIT, it works just fine:

$ ruby -Xcompile.invokedynamic=true -J-Djruby.compile.mode=OFF 802.rb
CHILD
PARENT

Here is a gist of compile.dump=true with invokedynamic enabled on JRuby 1.7.4 (1.9.3p392) 2013-05-16 2390d3b on Java HotSpot(TM) 64-Bit Server VM 1.7.0_25-b15 [darwin-x86_64]: https://gist.github.com/liveh2o/6237163.

@quixoten

The example from @abrandoned replicates the error on my box as well. I'm seeing the same behavior as @liveh2o mentions above, i.e., disabling invokedynamic or JIT gets it working again.

jruby 1.7.4 (1.9.3p392) 2013-05-16 2390d3b on OpenJDK 64-Bit Server VM 1.7.0_40-b31 +indy [linux-amd64]

java version "1.7.0_40"
OpenJDK Runtime Environment (IcedTea 2.4.1) (ArchLinux build 7.u40_2.4.1-2-x86_64)
OpenJDK 64-Bit Server VM (build 24.0-b50, mixed mode)
@kenips

I reported the the super calls as a separate issue - now perhaps they are the same. #937

@headius
Owner

Reproduced with @abrandoned's example! I'm on the job!

@headius
Owner

I have a fix. Sorry that I did not notice the reproduction sooner.

@kenips It is possible that your bug is the same root cause as this one, since it is super-related and works with invokedynamic off. Once I mark this fixed, perhaps you can try to reproduce your issue again against JRuby master?

@headius headius closed this issue from a commit
@headius headius Use proper original name for frame created via indy logic.
Super still uses frame name to do the lookup of the superclass's
method, so when super is present we have to push a frame with the
name of the currently-executing method. Normally this is the name
at the call site, but when the call is to an aliased method the
original name must be used to invoke the actual method. In the
non-indy logic, this is done by calling through AliasMethod, which
inserts the original name into the call path for use in frames. In
the indy logic, where we unwrap AliasMethod to bind more directly,
we were not carrying along the original name and were always using
the name at the call site. This caused the target method to have
the aliased name in its frame and to attempt to super up that name
instead of the original name.

The fix was to propagate the original name from method unwrapping
through to all places where framing is needed.

In the future, the super name will be statically calculated for
most cases, since it does not change for normal method
definitions.

Fixes #802 and #937.
484b4b4
@headius headius closed this in 484b4b4
@pschambacher

Hey I've just met this error. So it's a bug of JRuby 1.7.4 and upgrading to 1.7.5 or downgrading to 1.7.3 should fix it, right ?

@dre-hh

no longer experiencing the issue at jurby 1.7.6

@headius
Owner

@pierre-schambacher Yes, upgrading to 1.7.5+ will fix the problem.

@mindscratch

Just noting, I've built a WAR using Warbler with JRuby 1.7.4 and deployed it to Tomcat 7 which was running with Java 7u25 and began running into this issue when we upgraded Java to 7u45. I stopped tomcat, set JRUBY_OPTS to be --1.9 -Xcompile.invokedynamic=true -J-Djruby.compile.mode=OFF and I'm still having the same trouble.

Should the JRUBY_OPTS "trick" have worked? I'm going to try JRuby 1.7.5 to see if that'll work for me, but thought I'd inquire about my attempt at a work around in the meantime.

@mindscratch

Actually, I've been able to upgrade to JRuby 1.7.5 and so far things seem to be working.

@dre-hh

Why not even upgrading to 1.7.6 ;) ?
As far as i remmeber we experienced some other on 1.7.5 concering rails, but i don't remember which ones XD
1.7.6 is performing like a charm and the last version number increment indicates that this is just a patch release

@jorispz jorispz referenced this issue from a commit in jorispz/sonar
@simonbrandhof simonbrandhof SONAR-4045 downgrade to jruby 1.7.3 29f9168
@jaydeebee jaydeebee referenced this issue from a commit
Commit has since been removed from the repository and is no longer available.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Something went wrong with that request. Please try again.