JRuby

Intermittent, improper "undefined method" such as: Undefined method id? for module '#<Module:0x64cd6dca>'

Details

  • Type: Bug Bug
  • Status: Closed Closed
  • Priority: Blocker Blocker
  • Resolution: Not A Bug
  • Affects Version/s: JRuby 1.6.5
  • Fix Version/s: None
  • Component/s: Application Error, Rails WAR Deployment
  • Labels:
    None
  • Environment:
    Rails 3.0.10, Jruby 1.6.5, Warbler 1.3.2, Tomcat 7, Mysql 5.1
  • Number of attachments :
    0

Description

Although our application appears to work when manually tested, an automated test that makes concurrent requests to Tomcat running our Warbled WAR sometimes produces idiosyncratic problems from within ActiveRecord, such as:

Undefined method id? for module '#<Module:0x64cd6dca>'

gems/gems/activemodel-3.0.10/lib/active_model/attribute_methods.rb:294:in `(eval)'
org/jruby/RubyModule.java:2254:in `module_eval'
gems/gems/activemodel-3.0.10/lib/active_model/attribute_methods.rb:290:in `define_attribute_methods'
org/jruby/RubyArray.java:1612:in `each'
gems/gems/activemodel-3.0.10/lib/active_model/attribute_methods.rb:279:in `define_attribute_methods'
org/jruby/RubyArray.java:1612:in `each'
gems/gems/activemodel-3.0.10/lib/active_model/attribute_methods.rb:278:in `define_attribute_methods'
gems/gems/activerecord-3.0.10/lib/active_record/attribute_methods.rb:13:in `define_attribute_methods'
gems/gems/activerecord-3.0.10/lib/active_record/attribute_methods.rb:41:in `method_missing'
...<a line of our code that simply accesses a string field on an already loaded active record model object>...

These errors often seem to happen at the beginning of our tests (suggesting a possible race between lazy initialization on a first request and following requests that come too soon afterwards), though I cannot yet confirm they never happens after test start.

That could mean this is possibly related to JRUBY-6254.

The problem is quite common - we basically see some number of these on every test run.

Some additional examples:

Undefined method id_before_type_cast for module '#<Module:0x64cd6dca>'

gems/gems/activemodel-3.0.10/lib/active_model/attribute_methods.rb:294:in `(eval)'
org/jruby/RubyModule.java:2254:in `module_eval'
gems/gems/activemodel-3.0.10/lib/active_model/attribute_methods.rb:290:in `define_attribute_methods'
org/jruby/RubyArray.java:1612:in `each'
gems/gems/activemodel-3.0.10/lib/active_model/attribute_methods.rb:279:in `define_attribute_methods'
org/jruby/RubyArray.java:1612:in `each'
gems/gems/activemodel-3.0.10/lib/active_model/attribute_methods.rb:278:in `define_attribute_methods'
gems/gems/activerecord-3.0.10/lib/active_record/attribute_methods.rb:13:in `define_attribute_methods'
gems/gems/activerecord-3.0.10/lib/active_record/attribute_methods.rb:41:in `method_missing'
...<NOTE that this is generated from the *exact same* line in our code as the different error above>...

And another example:

Undefined method <name of a method we defined>! for module '#<Module:0xadfa6>'

gems/gems/activemodel-3.0.10/lib/active_model/attribute_methods.rb:294:in `(eval)'
org/jruby/RubyModule.java:2254:in `module_eval'
gems/gems/activemodel-3.0.10/lib/active_model/attribute_methods.rb:290:in `define_attribute_methods'
org/jruby/RubyArray.java:1612:in `each'
gems/gems/activemodel-3.0.10/lib/active_model/attribute_methods.rb:279:in `define_attribute_methods'
org/jruby/RubyArray.java:1612:in `each'
gems/gems/activemodel-3.0.10/lib/active_model/attribute_methods.rb:278:in `define_attribute_methods'
gems/gems/activerecord-3.0.10/lib/active_record/attribute_methods.rb:13:in `define_attribute_methods'
gems/gems/activerecord-3.0.10/lib/active_record/attribute_methods.rb:41:in `method_missing'
...<in our code, we modify a field on an already loaded activerecord object; note that <name of a method we defined>! is - or should be - defined on that object's class.>...

Activity

Ascending order - Click to sort in descending order
Hide
Permalink
David Wood added a comment -

Further evidence continues to mount that this is likely a race between lazy initialization on a first request and following requests that come too soon afterwards.

We may get many errors of this type or few or none in a given automated test, but I cannot confirm the problem on subsequent test runs on the same application.

Show
David Wood added a comment - Further evidence continues to mount that this is likely a race between lazy initialization on a first request and following requests that come too soon afterwards. We may get many errors of this type or few or none in a given automated test, but I cannot confirm the problem on subsequent test runs on the same application.
Hide
Permalink
Jeff Solomon added a comment -

We see exactly the same thing, but only when we run a load test script against our server.

I had hoped that upgrading to jruby 1.6.7 with thread safe autoload would fix this issue, but it didn't.

Any ideas on how to debug or make progress on this issue?

Show
Jeff Solomon added a comment - We see exactly the same thing, but only when we run a load test script against our server. I had hoped that upgrading to jruby 1.6.7 with thread safe autoload would fix this issue, but it didn't. Any ideas on how to debug or make progress on this issue?
Hide
Permalink
Charles Oliver Nutter added a comment -

Looks like this one flew under my radar. Blocker for 1.7.

Show
Charles Oliver Nutter added a comment - Looks like this one flew under my radar. Blocker for 1.7.
Hide
Permalink
Charles Oliver Nutter added a comment -

My first instinct is that this might be a Rails issue, but I'm going to proceed assuming there's something we could be doing better. Even if that turns out not to be the case, there's obviously something broken, so we need to find it.

Show
Charles Oliver Nutter added a comment - My first instinct is that this might be a Rails issue, but I'm going to proceed assuming there's something we could be doing better. Even if that turns out not to be the case, there's obviously something broken, so we need to find it.
Hide
Permalink
Jeff Solomon added a comment -

We fixed this by taking a rails patch from 3.2.something. Some class variable needed to be protected with a mutex.

I'm sorry but I can't find the rails patch we copied from.

Show
Jeff Solomon added a comment - We fixed this by taking a rails patch from 3.2.something. Some class variable needed to be protected with a mutex. I'm sorry but I can't find the rails patch we copied from.
Hide
Permalink
Charles Oliver Nutter added a comment -

So are you saying we could close this as not being a JRuby issue?

Show
Charles Oliver Nutter added a comment - So are you saying we could close this as not being a JRuby issue?
Hide
Permalink
Jeff Solomon added a comment -

Yes. It's a rails issue.

We fixed this problem by applying a fix that was put into rails 3.2.1:

https://gist.github.com/1685812#file_active+record

You might want to confirm this for yourself, or the original poster should confirm that this fix indeed solves the problem before you close the bug.

Show
Jeff Solomon added a comment - Yes. It's a rails issue. We fixed this problem by applying a fix that was put into rails 3.2.1: https://gist.github.com/1685812#file_active+record You might want to confirm this for yourself, or the original poster should confirm that this fix indeed solves the problem before you close the bug.
Hide
Permalink
David Wood added a comment -

Interesting. Thank you! We'll investigate further on this end and report back.

Show
David Wood added a comment - Interesting. Thank you! We'll investigate further on this end and report back.
Hide
Permalink
Charles Oliver Nutter added a comment -

As recommended, we will resolve this as Not A Bug for now. If it continues to happen or if you find new evidence that there's something we need to fix, let us know.

Show
Charles Oliver Nutter added a comment - As recommended, we will resolve this as Not A Bug for now. If it continues to happen or if you find new evidence that there's something we need to fix, let us know.

People

  • Assignee:
    Charles Oliver Nutter
    Reporter:
    David Wood
Vote (1)
Watch (3)

Dates

  • Created:
    Updated:
    Resolved: