Rails 3.2.8: Use of ActiveSupport::sum causes extra database queries vs inject #7411

Closed
fierydrake opened this Issue Aug 22, 2012 · 8 comments

Comments

Projects
None yet
7 participants
@fierydrake

Here is the scenario:

class Serving
  has_many :constituents
  has_many :nutritions, :through => :constituents
end

class Constituent
  belongs_to :serving
  belongs_to :nutrition
  attr_accessible :qty_in_grams
end

class Nutrition
  has_many :constituents
  has_many :servings, :through => constituents
  attr_accessible :calories_per_gram
end

I want to calculate the total calories for the serving, I naturally do the following query:

Serving.sum { |serving| 
  serving.constituents.sum { |constituent| 
    constituent.qty_in_grams * constituent.nutrition.calories_per_gram 
  } 
}

This makes a lot of queries, so I use includes to reduce the number of queries down:

Serving.includes(:constituents => :nutrition).sum { |serving| 
  serving.constituents.sum { |constituent| 
    constituent.qty_in_grams * constituent.nutrition.calories_per_gram 
  } 
}

However, this doesn't seem to help. Puzzled, and after a lot of fiddling, I make a change that reduces the queries down to 3.

Serving.includes(:constituents => :nutrition).sum { |serving| 
  serving.constituents.inject(0) { |memo, constituent| 
    memo + (constituent.qty_in_grams * constituent.nutrition.calories_per_gram) 
  } 
}

I don't know why ActiveSupport::sum appears to act differently to inject in this case. Is this a bug? (I searched the issue tracker and didn't find any likely suspects.)

Example logs:

With includes and 2 sums:

Serving Load (1.0ms)  SELECT "servings".* FROM "servings" 
Constituent Load (3.0ms)  SELECT "constituents".* FROM "constituents" WHERE "constituents"."serving_id" IN (1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12)
Nutrition Load (2.7ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" IN (1, 2, 8, 6, 7, 5, 4, 3, 9, 10, 11, 12, 17, 18, 13, 14, 15, 16, 19, 20, 23, 22, 21, 24, 25, 26, 27, 28, 29, 30, 31, 32, 34, 33, 35, 36, 37, 38)
Constituent Load (0.8ms)  SELECT "constituents".* FROM "constituents" WHERE "constituents"."serving_id" = 1
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 1 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 2 LIMIT 1
Constituent Load (1.2ms)  SELECT "constituents".* FROM "constituents" WHERE "constituents"."serving_id" = 2
Nutrition Load (0.8ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 8 LIMIT 1
Nutrition Load (0.7ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 6 LIMIT 1
Nutrition Load (0.7ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 7 LIMIT 1
Nutrition Load (1.1ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 5 LIMIT 1
Nutrition Load (0.8ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 4 LIMIT 1
Nutrition Load (1.2ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 3 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 1 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 9 LIMIT 1
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 10 LIMIT 1
Nutrition Load (0.7ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 11 LIMIT 1
Constituent Load (0.7ms)  SELECT "constituents".* FROM "constituents" WHERE "constituents"."serving_id" = 3
Nutrition Load (1.2ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 12 LIMIT 1
Nutrition Load (0.7ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 17 LIMIT 1
Nutrition Load (1.2ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 18 LIMIT 1
Constituent Load (1.0ms)  SELECT "constituents".* FROM "constituents" WHERE "constituents"."serving_id" = 4
Nutrition Load (0.8ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 13 LIMIT 1
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 14 LIMIT 1
Nutrition Load (4.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 15 LIMIT 1
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 16 LIMIT 1
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 11 LIMIT 1
Nutrition Load (1.7ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 7 LIMIT 1
Constituent Load (1.1ms)  SELECT "constituents".* FROM "constituents" WHERE "constituents"."serving_id" = 5
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 19 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 6 LIMIT 1
Nutrition Load (1.2ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 9 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 7 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 20 LIMIT 1
Constituent Load (0.9ms)  SELECT "constituents".* FROM "constituents" WHERE "constituents"."serving_id" = 6
Nutrition Load (1.6ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 23 LIMIT 1
Nutrition Load (6.5ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 22 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 21 LIMIT 1
Nutrition Load (6.5ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 24 LIMIT 1
Constituent Load (1.2ms)  SELECT "constituents".* FROM "constituents" WHERE "constituents"."serving_id" = 7
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 25 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 26 LIMIT 1
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 27 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 28 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 29 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 30 LIMIT 1
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 31 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 32 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 34 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 33 LIMIT 1
Constituent Load (1.2ms)  SELECT "constituents".* FROM "constituents" WHERE "constituents"."serving_id" = 8
Nutrition Load (5.7ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 25 LIMIT 1
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 26 LIMIT 1
Nutrition Load (1.4ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 27 LIMIT 1
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 28 LIMIT 1
Nutrition Load (1.1ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 29 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 30 LIMIT 1
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 31 LIMIT 1
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 32 LIMIT 1
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 34 LIMIT 1
Nutrition Load (7.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 33 LIMIT 1
Constituent Load (1.0ms)  SELECT "constituents".* FROM "constituents" WHERE "constituents"."serving_id" = 9
Nutrition Load (1.1ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 23 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 22 LIMIT 1
Constituent Load (1.1ms)  SELECT "constituents".* FROM "constituents" WHERE "constituents"."serving_id" = 10
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 25 LIMIT 1
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 26 LIMIT 1
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 27 LIMIT 1
Nutrition Load (1.1ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 28 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 29 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 30 LIMIT 1
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 31 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 32 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 33 LIMIT 1
Constituent Load (1.0ms)  SELECT "constituents".* FROM "constituents" WHERE "constituents"."serving_id" = 11
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 21 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 35 LIMIT 1
Nutrition Load (0.9ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 36 LIMIT 1
Nutrition Load (0.8ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 37 LIMIT 1
Constituent Load (0.9ms)  SELECT "constituents".* FROM "constituents" WHERE "constituents"."serving_id" = 12
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 38 LIMIT 1
Nutrition Load (1.0ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" = 17 LIMIT 1  

With includes, 1 sum, 1 inject:

Serving Load (1.0ms)  SELECT "servings".* FROM "servings" 
Constituent Load (3.7ms)  SELECT "constituents".* FROM "constituents" WHERE "constituents"."serving_id" IN (1, 2, 3, 4, 5, 6 , 7, 8, 9, 10, 11, 12)
Nutrition Load (3.1ms)  SELECT "nutritions".* FROM "nutritions" WHERE "nutritions"."id" IN (1, 2, 8, 6, 7, 5, 4, 3, 9, 10, 11, 12, 17, 18, 13, 14, 15, 16, 19, 20, 23, 22, 21, 24, 25, 26, 27, 28, 29, 30, 31, 32, 34, 33, 35, 36, 37, 38)
@fierydrake

This comment has been minimized.

Show comment
Hide comment
@fierydrake

fierydrake Aug 22, 2012

These example logs come from running the queries in the console. The development.log when rendering the page in the application shows slightly different logs (more of the extra queries are satisfied from the cache, but not all). Running on my aging netbook the difference in timings is as follows:

With includes and 2 sums:

  Rendered servings/index.html.erb within layouts/application (6182.0ms)
Completed 200 OK in 7131ms (Views: 6320.3ms | ActiveRecord: 141.4ms)

With includes, 1 sum and 1 inject:

  Rendered servings/index.html.erb within layouts/application (385.4ms)
Completed 200 OK in 796ms (Views: 429.6ms | ActiveRecord: 14.1ms)

These example logs come from running the queries in the console. The development.log when rendering the page in the application shows slightly different logs (more of the extra queries are satisfied from the cache, but not all). Running on my aging netbook the difference in timings is as follows:

With includes and 2 sums:

  Rendered servings/index.html.erb within layouts/application (6182.0ms)
Completed 200 OK in 7131ms (Views: 6320.3ms | ActiveRecord: 141.4ms)

With includes, 1 sum and 1 inject:

  Rendered servings/index.html.erb within layouts/application (385.4ms)
Completed 200 OK in 796ms (Views: 429.6ms | ActiveRecord: 14.1ms)
@parndt

This comment has been minimized.

Show comment
Hide comment
@parndt

parndt Nov 27, 2012

Contributor

@fierydrake is this still a problem in Rails 3.2.9?

Contributor

parndt commented Nov 27, 2012

@fierydrake is this still a problem in Rails 3.2.9?

@fierydrake

This comment has been minimized.

Show comment
Hide comment
@fierydrake

fierydrake Nov 27, 2012

@parndt I'll check and get back to you. Thanks.

@parndt I'll check and get back to you. Thanks.

@pixeltrix

This comment has been minimized.

Show comment
Hide comment
@pixeltrix

pixeltrix Nov 28, 2012

Member

I saw this problem the other week and I tracked it down to the CollectionAssociation#sum method - the block_given? in that method was returning false even though it has one and it does the DB query version instead. I couldn't track it down any further at the time though thinking about it now it's probably something to do with the association proxy confusing things. I worked around it at the time by using to_a on the association which should already have been loaded by the :include, e.g:

Serving.includes(:constituents => :nutrition).sum { |serving| 
  serving.constituents.to_a.sum { |constituent| 
    constituent.qty_in_grams * constituent.nutrition.calories_per_gram 
  } 
}

@jonleighton any ideas on this one?

Member

pixeltrix commented Nov 28, 2012

I saw this problem the other week and I tracked it down to the CollectionAssociation#sum method - the block_given? in that method was returning false even though it has one and it does the DB query version instead. I couldn't track it down any further at the time though thinking about it now it's probably something to do with the association proxy confusing things. I worked around it at the time by using to_a on the association which should already have been loaded by the :include, e.g:

Serving.includes(:constituents => :nutrition).sum { |serving| 
  serving.constituents.to_a.sum { |constituent| 
    constituent.qty_in_grams * constituent.nutrition.calories_per_gram 
  } 
}

@jonleighton any ideas on this one?

@ghost ghost assigned pixeltrix Nov 28, 2012

@cmonty

This comment has been minimized.

Show comment
Hide comment
@cmonty

cmonty Jan 18, 2013

Just ran into this issue. The culprit isn't block_given? being false, but rather the use of scoped. scoped returns a newly chain-able scope, rather than the collection that is already loaded. Hence, when it calls sum ActiveRecord executes the query (via Relation and Calculations). Using to_a works, because we end up going through the CollectionAssociation which knows our associations are already loaded and is still chain-able.

I really think the scoped.sum should be proxy.to_a.sum if you pass a block into CollectionAssociation#sum.

cmonty commented Jan 18, 2013

Just ran into this issue. The culprit isn't block_given? being false, but rather the use of scoped. scoped returns a newly chain-able scope, rather than the collection that is already loaded. Hence, when it calls sum ActiveRecord executes the query (via Relation and Calculations). Using to_a works, because we end up going through the CollectionAssociation which knows our associations are already loaded and is still chain-able.

I really think the scoped.sum should be proxy.to_a.sum if you pass a block into CollectionAssociation#sum.

@tenderlove

This comment has been minimized.

Show comment
Hide comment
@tenderlove

tenderlove Feb 9, 2014

Member

Does anyone have a reproducible test case for this? I see the Ruby code, but could you add some data loading?

Member

tenderlove commented Feb 9, 2014

Does anyone have a reproducible test case for this? I see the Ruby code, but could you add some data loading?

@matthewd

This comment has been minimized.

Show comment
Hide comment
@matthewd

matthewd May 1, 2014

Member

I think this goes away now that serving.constituents.to_a.sum is the correct spelling, and serving.constituents.sum is exclusively for generating a 'SELECT SUM(..)' and ignores any block.

Member

matthewd commented May 1, 2014

I think this goes away now that serving.constituents.to_a.sum is the correct spelling, and serving.constituents.sum is exclusively for generating a 'SELECT SUM(..)' and ignores any block.

@pixeltrix

This comment has been minimized.

Show comment
Hide comment
@pixeltrix

pixeltrix May 1, 2014

Member

@matthewd yep, I think that's right

Member

pixeltrix commented May 1, 2014

@matthewd yep, I think that's right

@pixeltrix pixeltrix closed this May 1, 2014

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment