This project is archived and is in readonly mode.
View rendering 9x slower than Rails 2.2.2
Reported by Chris Heald | February 9th, 2009 @ 04:35 PM | in 2.x
(In case the formatting fails here, a pleasant-to-look at version is at http://pastie.org/private/ervcyl... )
Despite the output logs being just about the exact same, Rails 2.3 RC1 is reporting as significantly slower than Rails 2.2.2 in development mode for my app. There is no visible reason for the slowdown in the logs, but the View rendering for 2.3 reports in as 9x slower than the View rendering in 2.2.2
These results are consistent across multiple page reloads.
Rails 2.3 RC1 Rails 2.2.2
Processing NodesController#blips (for 192 Processing NodesController#blips (for 192
Session ID: 41d43b6eb404659a1b7cf8b1627
Parameters: {"action"=>"blips", "contro Parameters: {"action"=>"blips", "contro
SQL (0.1ms) SET SQL_AUTO_IS_NULL=0
User Columns (2.4ms) SHOW FIELDS FROM User Columns (2.1ms) SHOW FIELDS FROM
List Columns (0.9ms) SHOW FIELDS FROM List Columns (1.1ms) SHOW FIELDS FROM
NodeClass Columns (1.4ms) SHOW FIELDS NodeClass Columns (1.3ms) SHOW FIELDS
NodeClass Load (0.6ms) SELECT * FROM NodeClass Load (0.6ms) SELECT * FROM
Nodes::Movie Columns (1.6ms) SHOW FIE Nodes::Movie Columns (1.6ms) SHOW FIE
Nodes::Movie Load (122.5ms) SELECT * Nodes::Movie Load (129.7ms) SELECT *
Nodes::Movie Load (115.8ms) SELECT * Nodes::Movie Load (116.9ms) SELECT *
CACHE (0.0ms) SELECT * FROM `node_cla CACHE (0.0ms) SELECT * FROM `node_cla
SQL (0.5ms) SELECT count(*) AS count_ SQL (0.5ms) SELECT count(*) AS count_
Node Load (75.6ms) SELECT * FROM `nod Node Load (77.5ms) SELECT * FROM `nod
Node Columns (1.6ms) SHOW FIELDS FROM Node Columns (1.6ms) SHOW FIELDS FROM
CACHE (0.0ms) SELECT count(*) AS coun CACHE (0.0ms) SELECT count(*) AS coun
NodeClass Load (0.6ms) SELECT * FROM NodeClass Load (0.5ms) SELECT * FROM
CACHE (0.0ms) SELECT count(*) AS coun CACHE (0.0ms) SELECT count(*) AS coun
Blip Columns (1.2ms) SHOW FIELDS FROM Blip Columns (1.0ms) SHOW FIELDS FROM
Image Columns (1.0ms) SHOW FIELDS FRO Image Columns (1.0ms) SHOW FIELDS FRO
Blip Load IDs For Limited Eager Loading Blip Load IDs For Limited Eager Loading
Blip Load Including Associations (4.7ms Blip Load Including Associations (4.7ms
SQL (113.3ms) SELECT count(DISTINCT ` SQL (117.1ms) SELECT count(DISTINCT `
Blip Load (0.3ms) SELECT * FROM `blip Blip Load (0.4ms) SELECT * FROM `blip
Vote Load (0.4ms) SELECT * FROM `vote Vote Load (0.2ms) SELECT * FROM `vote
Rendering template within layouts/applica Rendering template within layouts/main
Rendering nodes/blips Rendering nodes/blips
Rendered home/_mini_login_block (0.9ms) Rendered home/_mini_login_block (1.1ms)
Rendered ads/_ad_300 (0.2ms) Rendered ads/_ad_300 (0.1ms)
Image Load (0.9ms) SELECT * FROM `ima Image Load (0.8ms) SELECT * FROM `ima
CACHE (0.0ms) SELECT * FROM `images` CACHE (0.0ms) SELECT * FROM `images`
Image Load (0.6ms) SELECT * FROM `ima Image Load (0.7ms) SELECT * FROM `ima
CACHE (0.0ms) SELECT * FROM `images` CACHE (0.0ms) SELECT * FROM `images`
Image Load (0.4ms) SELECT * FROM `ima Image Load (0.4ms) SELECT * FROM `ima
CACHE (0.0ms) SELECT * FROM `images` CACHE (0.0ms) SELECT * FROM `images`
Image Load (0.4ms) SELECT * FROM `ima Image Load (0.4ms) SELECT * FROM `ima
CACHE (0.0ms) SELECT * FROM `images` CACHE (0.0ms) SELECT * FROM `images`
Image Load (0.4ms) SELECT * FROM `ima Image Load (0.4ms) SELECT * FROM `ima
CACHE (0.0ms) SELECT * FROM `images` CACHE (0.0ms) SELECT * FROM `images`
Rendered nodes/_titlelist (15.3ms) Rendered nodes/_titlelist (15.0ms)
Image Load (0.4ms) SELECT * FROM `ima Image Load (0.4ms) SELECT * FROM `ima
CACHE (0.0ms) SELECT * FROM `images` CACHE (0.0ms) SELECT * FROM `images`
Image Load (0.4ms) SELECT * FROM `ima Image Load (0.4ms) SELECT * FROM `ima
CACHE (0.0ms) SELECT * FROM `images` CACHE (0.0ms) SELECT * FROM `images`
Image Load (0.4ms) SELECT * FROM `ima Image Load (0.4ms) SELECT * FROM `ima
CACHE (0.0ms) SELECT * FROM `images` CACHE (0.0ms) SELECT * FROM `images`
Image Load (0.4ms) SELECT * FROM `ima Image Load (0.4ms) SELECT * FROM `ima
CACHE (0.0ms) SELECT * FROM `images` CACHE (0.0ms) SELECT * FROM `images`
Image Load (0.4ms) SELECT * FROM `ima Image Load (0.3ms) SELECT * FROM `ima
CACHE (0.0ms) SELECT * FROM `images` CACHE (0.0ms) SELECT * FROM `images`
Rendered nodes/_titlelist (11.5ms) Rendered nodes/_titlelist (10.9ms)
User Load (0.9ms) SELECT * FROM `user User Load (0.8ms) SELECT * FROM `user
Rendered nodes/_action_menu (1.1ms) Rendered nodes/_action_menu (0.8ms)
NodeClass Load (0.4ms) SELECT * FROM NodeClass Load (0.4ms) SELECT * FROM
Rendered blips/_blip (266.3ms) Rendered blips/_blip (17.7ms)
CACHE (0.0ms) SELECT * FROM `users` W CACHE (0.0ms) SELECT * FROM `users` W
Rendered nodes/_action_menu (0.7ms) Rendered nodes/_action_menu (0.7ms)
CACHE (0.0ms) SELECT * FROM `node_cla CACHE (0.0ms) SELECT * FROM `node_cla
Rendered blips/_blip (5.4ms) Rendered blips/_blip (5.5ms)
CACHE (0.0ms) SELECT * FROM `users` W CACHE (0.0ms) SELECT * FROM `users` W
Rendered nodes/_action_menu (0.7ms) Rendered nodes/_action_menu (0.7ms)
CACHE (0.0ms) SELECT * FROM `node_cla CACHE (0.0ms) SELECT * FROM `node_cla
Rendered blips/_blip (5.2ms) Rendered blips/_blip (5.2ms)
User Load (0.6ms) SELECT * FROM `user User Load (0.7ms) SELECT * FROM `user
Rendered nodes/_action_menu (0.8ms) Rendered nodes/_action_menu (0.8ms)
CACHE (0.0ms) SELECT * FROM `node_cla CACHE (0.0ms) SELECT * FROM `node_cla
Rendered blips/_blip (6.1ms) Rendered blips/_blip (6.3ms)
CACHE (0.0ms) SELECT * FROM `users` W CACHE (0.0ms) SELECT * FROM `users` W
Rendered nodes/_action_menu (0.7ms) Rendered nodes/_action_menu (0.8ms)
CACHE (0.0ms) SELECT * FROM `node_cla CACHE (0.0ms) SELECT * FROM `node_cla
Rendered blips/_blip (5.1ms) Rendered blips/_blip (5.4ms)
User Load (0.5ms) SELECT * FROM `user User Load (0.5ms) SELECT * FROM `user
Rendered nodes/_action_menu (0.7ms) Rendered nodes/_action_menu (0.8ms)
CACHE (0.0ms) SELECT * FROM `node_cla CACHE (0.0ms) SELECT * FROM `node_cla
Rendered blips/_blip (5.9ms) Rendered blips/_blip (6.0ms)
CACHE (0.0ms) SELECT * FROM `users` W CACHE (0.0ms) SELECT * FROM `users` W
Rendered nodes/_action_menu (0.7ms) Rendered nodes/_action_menu (0.7ms)
Rendered blips/_blip (4.7ms) Rendered blips/_blip (4.9ms)
CACHE (0.0ms) SELECT * FROM `users` W CACHE (0.0ms) SELECT * FROM `users` W
Rendered nodes/_action_menu (0.7ms) Rendered nodes/_action_menu (0.9ms)
CACHE (0.0ms) SELECT * FROM `node_cla CACHE (0.0ms) SELECT * FROM `node_cla
Rendered blips/_blip (5.2ms) Rendered blips/_blip (5.5ms)
CACHE (0.0ms) SELECT * FROM `users` W CACHE (0.0ms) SELECT * FROM `users` W
Rendered nodes/_action_menu (0.7ms) Rendered nodes/_action_menu (0.8ms)
CACHE (0.0ms) SELECT * FROM `node_cla CACHE (0.0ms) SELECT * FROM `node_cla
Rendered blips/_blip (5.2ms) Rendered blips/_blip (5.2ms)
CACHE (0.0ms) SELECT * FROM `users` W CACHE (0.0ms) SELECT * FROM `users` W
Rendered nodes/_action_menu (0.7ms) Rendered nodes/_action_menu (0.7ms)
Rendered blips/_blip (4.6ms) Rendered blips/_blip (4.8ms)
CACHE (0.0ms) SELECT * FROM `users` W CACHE (0.0ms) SELECT * FROM `users` W
Rendered nodes/_action_menu (0.7ms) Rendered nodes/_action_menu (0.7ms)
CACHE (0.0ms) SELECT * FROM `node_cla CACHE (0.0ms) SELECT * FROM `node_cla
Rendered blips/_blip (5.0ms) Rendered blips/_blip (5.0ms)
CACHE (0.0ms) SELECT * FROM `users` W CACHE (0.0ms) SELECT * FROM `users` W
Rendered nodes/_action_menu (0.7ms) Rendered nodes/_action_menu (0.8ms)
CACHE (0.0ms) SELECT * FROM `node_cla CACHE (0.0ms) SELECT * FROM `node_cla
Rendered blips/_blip (5.1ms) Rendered blips/_blip (5.1ms)
CACHE (0.0ms) SELECT * FROM `users` W CACHE (0.0ms) SELECT * FROM `users` W
Rendered nodes/_action_menu (0.7ms) Rendered nodes/_action_menu (0.8ms)
CACHE (0.0ms) SELECT * FROM `node_cla CACHE (0.0ms) SELECT * FROM `node_cla
Rendered blips/_blip (5.0ms) Rendered blips/_blip (5.0ms)
CACHE (0.0ms) SELECT * FROM `users` W CACHE (0.0ms) SELECT * FROM `users` W
Rendered nodes/_action_menu (0.7ms) Rendered nodes/_action_menu (0.7ms)
CACHE (0.0ms) SELECT * FROM `node_cla CACHE (0.0ms) SELECT * FROM `node_cla
Rendered blips/_blip (5.1ms) Rendered blips/_blip (5.2ms)
CACHE (0.0ms) SELECT * FROM `users` W CACHE (0.0ms) SELECT * FROM `users` W
Rendered nodes/_action_menu (0.7ms) Rendered nodes/_action_menu (0.7ms)
CACHE (0.0ms) SELECT * FROM `node_cla CACHE (0.0ms) SELECT * FROM `node_cla
Rendered blips/_blip (5.1ms) Rendered blips/_blip (5.2ms)
Rendered layouts/_head (5.1ms) Rendered layouts/_head (7.1ms)
Rendered layouts/_footer (1.3ms) Rendered layouts/_footer (1.3ms)
Rendered layouts/_main_menu (5.4ms) Rendered layouts/_main_menu (157.5ms)
Cookie set: settings-anon=sort%3Dscore%26
Completed in 3854ms (View: 2775, DB: 608) Completed in 1230ms (View: 314, DB: 629)
Comments and changes to this ticket
-
Chris Heald February 9th, 2009 @ 04:40 PM
Oh, I guess I should add that via the very scientific stopwatch test, Rails 2.3 is actually rendering more slowly - that is, this isn't solely an issue with the reporting.
-
Chris Heald February 9th, 2009 @ 04:56 PM
Yup, that's the magic sauce. My view render time is back down to ~115ms on Rails 2.3, and the page render time is down accordingly. I'll add a note to your ticket.
-
josh February 9th, 2009 @ 08:22 PM
- State changed from new to resolved
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>
People watching this ticket
Referenced by
- 1909 Improve view performance in development and reinstate template reloading in production This patch completely resolved #1922 for me. +1 for inclu...