So I am using mini-profiler and it gives me some nice stats.
However, one thing I have noticed is that I have gotten a lot of the SQL calls down to a minimum and now the biggest thing is the rendering of the various partials and HTML.
For instance, here are 2 different examples of issues I am facing:
Mini-Profiler
GET http://localhost:3000/ 14.0 +0.0
Executing action: index 9.5 +9.0
Rendering: home/index 7.8 +16.0
Rendering: home/_row 7.9 +22.0
Rendering: layouts/application 1038.7 +32.0
Rendering: layouts/_navigation 6.0 +586.0
Development.log
Started GET "/" for 127.0.0.1 at 2013-05-17 18:00:26 -0500
Processing by HomeController#index as HTML
Item Load (0.6ms) SELECT "items".* FROM "items" WHERE "items"."is_approved" = 't'
ActsAsTaggableOn::Tag Load (0.6ms) SELECT "tags".* FROM "tags" INNER JOIN "taggings" ON "tags"."id" = "taggings"."tag_id" WHERE "taggings"."taggable_id" = 13 AND "taggings"."taggable_type" = 'Item' AND (taggings.context = 'tags' AND taggings.tagger_id IS NULL)
Rendered home/_row.html.erb (8.0ms)
Rendered home/index.html.erb within layouts/application (15.7ms)
Rendered layouts/_social_media.html.erb (0.5ms)
(0.4ms) SELECT items.id FROM "items"
ActsAsTaggableOn::Tag Load (0.7ms) SELECT tags.*, taggings.tags_count AS count FROM "tags" JOIN (SELECT taggings.tag_id, COUNT(taggings.tag_id) AS tags_count FROM "taggings" INNER JOIN items ON items.id = taggings.taggable_id WHERE (taggings.taggable_type = 'Item' AND taggings.context = 'tags') AND (taggings.taggable_id IN(13)) GROUP BY taggings.tag_id HAVING COUNT(taggings.tag_id) > 0) AS taggings ON taggings.tag_id = tags.id ORDER BY count LIMIT 5
Rendered layouts/_navigation.html.erb (6.1ms)
Rendered layouts/_site_nav.html.erb (0.6ms)
Rendered layouts/_messages.html.erb (0.2ms)
Rendered layouts/_footer.html.erb (0.1ms)
Completed 200 OK in 1069ms (Views: 1066.0ms | ActiveRecord: 2.3ms)
The output from Mini-Profiler at the top, shows that the main application.html.erb
is adding significantly to load time.
Here is another example of another app where the views are the ones that take the most time to render:
Started GET "/" for 127.0.0.1 at 2013-05-17 17:55:01 -0500
User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."id" = 1 LIMIT 1
Processing by HomeController#index as HTML
Category Load (0.2ms) SELECT "categories".* FROM "categories" LIMIT 6
Banner Load (0.2ms) SELECT "banners".* FROM "banners" INNER JOIN "banner_types" ON "banner_types"."id" = "banners"."banner_type_id" WHERE (banner_types.name = 'Featured')
Banner Load (0.2ms) SELECT "banners".* FROM "banners" INNER JOIN "banner_types" ON "banner_types"."id" = "banners"."banner_type_id" WHERE (banner_types.name = 'Side')
Product Load (0.3ms) SELECT "products".* FROM "products"
Vendor Load (0.3ms) SELECT "vendors".* FROM "vendors" WHERE "vendors"."id" IN (12, 11, 10)
Vendor Load (0.2ms) SELECT "vendors".* FROM "vendors"
User Load (0.2ms) SELECT "users".* FROM "users"
Rendered home/_popular_products.html.erb (16.1ms)
Rendered home/_popular_stores.html.erb (2.4ms)
Rendered home/index.html.erb within layouts/application (26.4ms)
Piggybak::Sellable Load (0.2ms) SELECT "sellables".* FROM "sellables" WHERE "sellables"."id" = 1 LIMIT 1
Rendered layouts/_login_nav.html.erb (8.2ms)
Rendered layouts/_navigation.html.erb (0.8ms)
CACHE (0.0ms) SELECT "vendors".* FROM "vendors"
Rendered layouts/_store_dropdown.html.erb (2.2ms)
Rendered layouts/_header.html.erb (18.1ms)
Rendered layouts/_messages.html.erb (0.3ms)
Rendered layouts/_footer.html.erb (0.9ms)
Completed 200 OK in 242ms (Views: 209.8ms | ActiveRecord: 1.9ms)
Granted, this particular time is just 209.8ms
, but it has been as high as 5,000ms
at various loading times.
How can I optimize the rendering of these views & partials? Or what tool can I use to at least figure out what is causing the long load time so I can chip away at it slowly?