Slow find with including multiple associations

In a Rails controller action I call

@grid = Grid.find(params[:id], :include => [:grid_properties, :grid_entities => [:entity => :properties]])

Unfortunately it takes really long. Benchmark.realtime (in development mode) tells me 1.8812830448150635, so about 2 seconds (Rails 3.0.7, Postgres 8.4).

When turning on the SQL logging I get the following for this line of code:

Grid Load (0.9ms)  SELECT "grids".* FROM "grids" WHERE "grids"."id" = 2 LIMIT 1
GridProperty Load (2.5ms)  SELECT "grid_properties".* FROM "grid_properties" WHERE ("grid_properties".grid_id = 2) ORDER BY row_order
GridEntity Load (1.3ms)  SELECT "grid_entities".* FROM "grid_entities" WHERE ("grid_ent开发者_如何学JAVAities".grid_id = 2) ORDER BY row_order
Entity Load (3.0ms)  SELECT "entities".* FROM "entities" WHERE ("entities"."id" IN (28,7,3,6,25,11,2,12))
Property Load (6.4ms)  SELECT "properties".* FROM "properties" WHERE ("properties".entity_id IN (28,7,3,6,25,11,2,12))

Every database access seems to be in the low millisecond range. Why does it take so long in the end?

I guess that the time is spent on creating the object by Ruby. How many Properties are in that Grid? The time of 'SELECT FROM properties' looks relatively high.

You could further investigate the problem, if you have some functions where you could place checkpoints - logger.debug "CHECKPOINT: #{Time.now} #{caller(0).first}"

Do you have any 'on_load' callbacks, maybe?