This project is archived and is in readonly mode.

#5410 ✓committed
Jeremy Suriel

Multiple database queries when chaining named scopes with rails 2.3.8 and ruby 1.9.2

Reported by Jeremy Suriel | August 19th, 2010 @ 05:10 PM

I attached a sample project (testns) which demonstrates the following problem... In ruby 1.8.7, when chaining named scopes, only 1 query is made as it should. However, when using the same project under ruby 1.9.2, 2 queries are made for the same command. Here is the output for both ruby versions:

script/console output with ruby 1.8.7 (2009-06-12 patchlevel 174) and rails 2.3.8

>>ParentModel.first.test_models.high_priority.ordered SQL (0.2ms) SET NAMES 'utf8'
SQL (0.1ms) SET SQL_AUTO_IS_NULL=0
ParentModel Load (0.3ms) SELECT * FROM parent_models LIMIT 1
ParentModel Columns (1.0ms) SHOW FIELDS FROM parent_models

TestModel Load (0.3ms) SELECT * FROM test_models WHERE (test_models.parent_model_id = 1) AND ((priority > 5) AND (test_models.parent_model_id = 1)) ORDER BY name asc

TestModel Columns (0.9ms) SHOW FIELDS FROM test_models

[#<TestModel id: 11, name: "a11", priority: 11, created_at: "2010-08-19 15:20:23", updated_at: "2010-08-19 15:20:23", parent_model_id: 1>, #<TestModel id: 10, name: "test10", priority: 10, created_at: "2010-08-19 15:20:11", updated_at: "2010-08-19 15:20:11", parent_model_id: 1>, #<TestModel id: 6, name: "test6", priority: 6, created_at: "2010-08-19 15:19:49", updated_at: "2010-08-19 15:19:49", parent_model_id: 1>, #<TestModel id: 7, name: "test7", priority: 7, created_at: "2010-08-19 15:19:54", updated_at: "2010-08-19 15:19:54", parent_model_id: 1>, #<TestModel id: 8, name: "test8", priority: 8, created_at: "2010-08-19 15:20:00", updated_at: "2010-08-19 15:20:00", parent_model_id: 1>, #<TestModel id: 9, name: "test9", priority: 9, created_at: "2010-08-19 15:20:06", updated_at: "2010-08-19 15:20:06", parent_model_id: 1>]

script/console output with ruby-1.9.2-p0 and rails 2.3.8 (same output seen with ruby 1.9.2 rc2...not new to p0)

>>ParentModel.first.test_models.high_priority.ordered SQL (0.1ms) SET NAMES 'utf8'
SQL (0.1ms) SET SQL_AUTO_IS_NULL=0
ParentModel Load (0.2ms) SELECT * FROM parent_models LIMIT 1
ParentModel Columns (1.1ms) SHOW FIELDS FROM parent_models

TestModel Load (0.3ms) SELECT * FROM test_models WHERE (test_models.parent_model_id = 1)

TestModel Load (0.2ms) SELECT * FROM test_models WHERE (test_models.parent_model_id = 1) AND ((priority > 5) AND (test_models.parent_model_id = 1)) ORDER BY name asc

TestModel Columns (0.9ms) SHOW FIELDS FROM test_models

[#<TestModel id: 11, name: "a11", priority: 11, created_at: "2010-08-19 15:20:23", updated_at: "2010-08-19 15:20:23", parent_model_id: 1>, #<TestModel id: 10, name: "test10", priority: 10, created_at: "2010-08-19 15:20:11", updated_at: "2010-08-19 15:20:11", parent_model_id: 1>, #<TestModel id: 6, name: "test6", priority: 6, created_at: "2010-08-19 15:19:49", updated_at: "2010-08-19 15:19:49", parent_model_id: 1>, #<TestModel id: 7, name: "test7", priority: 7, created_at: "2010-08-19 15:19:54", updated_at: "2010-08-19 15:19:54", parent_model_id: 1>, #<TestModel id: 8, name: "test8", priority: 8, created_at: "2010-08-19 15:20:00", updated_at: "2010-08-19 15:20:00", parent_model_id: 1>, #<TestModel id: 9, name: "test9", priority: 9, created_at: "2010-08-19 15:20:06", updated_at: "2010-08-19 15:20:06", parent_model_id: 1>]

Comments and changes to this ticket

  • Stephen Blackstone

    Stephen Blackstone October 19th, 2010 @ 09:56 PM

    Same Problem here.. It also works fine under 1.9.1p243 but not 1.9.2...

    I'm using Rails 2.3.9

    Group
    has_many :topics, :as => :discussable (via a module)

    Topic
    belongs_to :discussable, :polymorphic => true named_scope :unhidden, { :conditions => ['hidden = ?', false] }

    Under rails 1.9.2 without the named_scope this works properly:

    reload! ; Group.find(56).topics.size

    Reloading...
    ...snip show tables etc... Group Load (12.8ms) SELECT FROM groups WHERE (groups.id = 56) Topic Columns (13.6ms) SHOW FIELDS FROM topics SQL (81.7ms) SELECT count() AS count_all FROM topics WHERE (topics.discussable_id = 56 AND topics.discussable_type = 'Group')

    However with the named scope in there:

    reload! ; Group.find(56).topics.unhidden.size

    Group Load (14.3ms) SELECT FROM groups WHERE (groups.id = 56) Topic Load (40.1ms) SELECT FROM topics WHERE (topics.discussable_id = 56 AND topics.discussable_type = 'Group') Topic Columns (13.5ms) SHOW FIELDS FROM topics SQL (11.8ms) SELECT count(*) AS count_all FROM topics WHERE (((hidden = 0) AND (topics.discussable_id = 56 AND topics.discussable_type = 'Group')) AND (topics.discussable_id = 56 AND topics.discussable_type = 'Group'))

    So the problem is under the seond one, it selects all the topics and then
    does select count(*).

    Under rails 1.9.1p243 this worked correctly in both cases.

  • Stephen Blackstone

    Stephen Blackstone October 20th, 2010 @ 06:06 PM

    The problem appears to be when on line 146 in association proxy send gets called with "current_scoped_methods". This causes proxy_respond_to to call respond_to? which causes a method missing which causes a load_target to be called by the association collection.

    /usr/local/ruby19/lib/ruby/gems/1.9.1/gems/activerecord-2.3.9/lib/active_record/base.rb:666:in find_by_sql' /usr/local/ruby19/lib/ruby/gems/1.9.1/gems/activerecord-2.3.9/lib/active_record/base.rb:1589:infind_every' /usr/local/ruby19/lib/ruby/gems/1.9.1/gems/activerecord-2.3.9/lib/active_record/base.rb:619:in find' /usr/local/ruby19/lib/ruby/gems/1.9.1/gems/activerecord-2.3.9/lib/active_record/associations/association_collection.rb:60:infind' /usr/local/ruby19/lib/ruby/gems/1.9.1/gems/activerecord-2.3.9/lib/active_record/associations/association_collection.rb:425:in find_target' /usr/local/ruby19/lib/ruby/gems/1.9.1/gems/activerecord-2.3.9/lib/active_record/associations/association_collection.rb:367:inload_target' /usr/local/ruby19/lib/ruby/gems/1.9.1/gems/activerecord-2.3.9/lib/active_record/associations/association_proxy.rb:219:in method_missing' /usr/local/ruby19/lib/ruby/gems/1.9.1/gems/activerecord-2.3.9/lib/active_record/associations/association_collection.rb:396:inmethod_missing' /usr/local/ruby19/lib/ruby/gems/1.9.1/gems/activerecord-2.3.9/lib/active_record/associations/association_collection.rb:343:in respond_to?' /usr/local/ruby19/lib/ruby/gems/1.9.1/gems/activerecord-2.3.9/lib/active_record/associations/association_collection.rb:343:inproxy_respond_to?' /usr/local/ruby19/lib/ruby/gems/1.9.1/gems/activerecord-2.3.9/lib/active_record/associations/association_proxy.rb:146:in send' /usr/local/ruby19/lib/ruby/gems/1.9.1/gems/activerecord-2.3.9/lib/active_record/named_scope.rb:124:ininitialize' /usr/local/ruby19/lib/ruby/gems/1.9.1/gems/activerecord-2.3.9/lib/active_record/named_scope.rb:90:in new' /usr/local/ruby19/lib/ruby/gems/1.9.1/gems/activerecord-2.3.9/lib/active_record/named_scope.rb:90:inblock in named_scope' /usr/local/ruby19/lib/ruby/gems/1.9.1/gems/activerecord-2.3.9/lib/active_record/associations/association_collection.rb:399:in call' /usr/local/ruby19/lib/ruby/gems/1.9.1/gems/activerecord-2.3.9/lib/active_record/associations/association_collection.rb:399:inmethod_missing'

  • Stephen Blackstone

    Stephen Blackstone October 20th, 2010 @ 06:31 PM

    Sorry about the formatting above =)

    The problem is that in association_collection, method missing is getting called with respond_to somewhere is calling respond_to_missing which is causing a new method_missing on the respond_to_missing which triggers the code path which causes the underlying collection to load.

    This doesn't solve the underlying issue (dealing with the new calls to respond_to_missing?) but does act as a workaround:

    --- association_collection.rb 2010-10-20 13:22:58.629947001 -0400 +++ /root/association_collection.rb 2010-10-20 13:22:54.509947004 -0400 @@ -390,7 +390,7 @@

             if block_given?
               super { |*block_args| yield(*block_args) }
             else
    
    •        super
      
    •        super unless method.to_s == "respond_to_missing?"
           end
         elsif @reflection.klass.scopes.include?(method)
           @reflection.klass.scopes[method].call(self, *args)
      
  • Jeremy Suriel

    Jeremy Suriel October 20th, 2010 @ 07:31 PM

    Stephen, thanks for the workaround. I created the attached rails initializer file and the problem seems to be fixed. I am still concerned however about the new calls to repsond_to_missing as you mentioned, and if this workaround causes issues elsewhere...

  • Stephen Blackstone

    Stephen Blackstone October 20th, 2010 @ 07:48 PM

    • Tag changed from rails 2.3.8, named_scope, ruby-1.9.2 to rails 2.3.8, named_scope, patch, ruby-1.9.2

    Jeremy -

    Most of the places where rails is using method_missing in this morass is guarded by things like:
    if @target.respond_to?(method) || (!@reflection.klass.respond_to?(method) && Class.respond_to?(method)

    The only reason this slips through is because responds_to_missing? became a part of the underlying ruby class..

    Attached is a proper patch off git. This same fix should also backported into 2.3.9..

  • Jeremy Suriel

    Jeremy Suriel October 20th, 2010 @ 07:56 PM

    Got it, thanks for the info. Any idea when/if this patch will be applied to 2.3?

  • Stephen Blackstone

    Stephen Blackstone October 22nd, 2010 @ 06:13 AM

    • Assigned user set to “Ryan Bigg”
  • Ken Collins

    Ken Collins October 29th, 2010 @ 03:12 PM

    Can anyone run the tests for ActiveRecord under 1.9.2? I can not, and created ticket 5887. I verified that this patch does somewhat speed up my app's testing under 1.9.2, but it's still slow and I would like to profile by running the tests and possibly find a few more places that need 1.9.2 help.

  • Ken Collins
  • Jeff Kreeftmeijer

    Jeff Kreeftmeijer November 1st, 2010 @ 05:03 PM

    • Tag cleared.
    • Importance changed from “” to “Low”

    Automatic cleanup of spam.

  • Stephen Blackstone

    Stephen Blackstone November 3rd, 2010 @ 06:23 PM

    • Tag set to patch
    • Assigned user changed from “Ryan Bigg” to “Jeff Kreeftmeijer”

    Here's an updated patch that fixes the underlying problem rather than just covering it up.

    AssociationProxy does this:
    instance_methods.each { |m| undef_method m unless m.to_s =~ /^(?:nil\?|send|object_id|to_a)$|^_|proxy/ }

    Because of this, in Ruby 1.9.2 it will wipe out the default respond_to_missing?

    Since the default is gone, it then sends the method call to method_missing

    The patch just adds an exception to the regular exception so it preserves respond_to_missing if it exists. This should be fully compatible with Ruby 1.8.6 since the method doesn't exist in the first place. It should be trivial to also add the same line to the 2.3.10 codebase to fix the same problem.. (patch is off of git)

  • Jeff Kreeftmeijer

    Jeff Kreeftmeijer November 3rd, 2010 @ 07:12 PM

    • Assigned user changed from “Jeff Kreeftmeijer” to “Aaron Patterson”
  • Stephen Blackstone
  • Aaron Patterson

    Aaron Patterson November 4th, 2010 @ 10:05 PM

    • State changed from “new” to “committed”

    Applied. Thanks!

Create your profile

Help contribute to this project by taking a few moments to create your personal profile. Create your profile »

<h2 style="font-size: 14px">Tickets have moved to Github</h2>

The new ticket tracker is available at <a href="https://github.com/rails/rails/issues">https://github.com/rails/rails/issues</a>

Attachments

Tags

Pages