Hi,
I’ve been experiencing some severe slowness in rendering the views in
my users/index action. It’s really not doing anything fancy at all,
and has been driving me nuts the last few days. I’m running Rails
2.2… does anyone have any idea how to resolve this? Look at home
much time is being consumed by the view. Obviously those response
times are unacceptable, and this is with 3 instances of Thin running
in production on a VPS…
#production.log
Rendering users/index
Completed in 11386ms (View: 8693, DB: 151)
Rendering users/index
Completed in 5024ms (View: 3286, DB: 16)
Rendering users/index
Completed in 11692ms (View: 8811, DB: 105
Rendering users/index
Completed in 11184ms (View: 8116, DB: 364)
Rendering sessions/new
Completed in 1696ms (View: 1012, DB: 0)
Rendering users/index
Completed in 8361ms (View: 6898, DB: 107)
#users/index.html.erb
Users
<%= render :partial => "users/user", :collection => @users %>
<%= will_paginate @users %>
<% if @users.empty? -%>
Looks like we couldn't find
anything matching your search. Maybe you should consider broadening it?
<% end -%>
#_user.html.erb
<% div_for user do %>
<%= link_to(image_tag(user.photo.url(:small), :alt =>
user.login, :height => 130, :width => 130, :class => “profile-photo”),
user) %><%= link_to(user.login, user) %>
<%= user.age %> / <%= user.sex %> / <
%= user.city %>, <%= user.state %>
<%= truncate_words(user.about_me ||
“”, 80) -%>
<% end %>
The template code is here too: http://gist.github.com/90786
Any ideas?
Thanks!
Avishai
I can’t find anything fundamentally wrong on your views, but we
haven’t seen any controller and model code.
Try benchmarking/profiling your app to find out exactly what the
bottleneck is. See
http://guides.rubyonrails.org/performance_testing.html
A good start may be your DB. What RDMS are you using? Do you have
proper indexes?
Have you tried running the SQL directly (pick it up from the logs) and
finding out if it’s a problem with Rails at all?
How big is the user.about_me column be? If it’s huge you may be
hitting a bandwidth bottleneck (DB => web server).
Not much more occurs to me at this point, but hope that points you on
the right direction.
On 6 Apr 2009, at 16:14, Avishai wrote:
Hi,
I’ve been experiencing some severe slowness in rendering the views in
my users/index action. It’s really not doing anything fancy at all,
and has been driving me nuts the last few days. I’m running Rails
2.2… does anyone have any idea how to resolve this? Look at home
much time is being consumed by the view. Obviously those response
times are unacceptable, and this is with 3 instances of Thin running
in production on a VPS…
I’d turn up your log level. If for example each user partial was
loading its photo from the database 1 by 1 then you’d see a zillion
sql queries in your log.
Fred
Fred, I took your suggestion to up the log level and this is what it
reveals:
Processing UsersController#index [GET]
Parameters: {“action”=>“index”, “controller”=>“users”, “page”=>“11”}
User Load (26.0ms) SELECT * FROM users ORDER BY users.created_at
DESC LIMIT 100, 10
SQL (0.2ms) SELECT count(*) AS count_all FROM users
Rendering template within layouts/application
Rendering users/index
Rendered users/_user (3.7ms)
Rendered users/_user (2.9ms)
Rendered users/_user (3.1ms)
Rendered users/_user (42.6ms)
Rendered users/_user (39.6ms)
Rendered users/_user (121.2ms)
Rendered users/_user (32.9ms)
Rendered users/_user (4.9ms)
Rendered users/_user (14.7ms)
Rendered users/_user (2.7ms)
User Load (0.2ms) SELECT * FROM users WHERE (users.id = 1)
LIMIT 1
Rendered users/_search (3.0ms)
Rendered users/_user_bar (2.1ms)
Completed in 319ms (View: 288, DB: 27)
However, once I hit refresh a bunch of times, all those partials drop
to only a few ms each. Including the ones that show as 40, 120, etc
above. Those long ones all had text in the about_me…
-Avishai
This is good to know.
“Completed in 319ms (View: 288, DB: 27)”
319ms is not hardly close to your original 11386ms.
I notice that your params below do not have any of the “search” criteria
([:user][:interests], etc). If you run the view using the criteria, does
performance degrade?
Interesting. Maybe something is going on in the controller. I’ve tried
running the resulting SQL queries directly, and they still seem to be
fetching pretty quickly…
The controller contains a lot of conditionals, maybe that’s the issue?
I’ve used Newrelic RPM to analyze my SQL, and it looks like for
everything there’s no USING FILESYSTEM, so indexes are set up
properly… The about_me column is a regular freetext column (TEXT i
think), so the length varies anywhere from zero to a few paragraphs of
text. The photos are handled with paperclip, but are just URLs, not
the actual files in the DB. Could it still be a bandwidth still be an
issue DB => webserver if they’re on the same box?
Controller code is at the end here: http://gist.github.com/90786
Cheers,
Avishai
I tried a bunch of different searches, and it’s actually loading
reasonably quickly still… < 500ms at least.
Also, in the process I upgraded from Rails 2.2.1 to 2.3.2, so maybe
that helped somewhat too.
-Avishai
On Apr 6, 2:13 pm, Harold A. Giménez Ch. [email protected]
When I leave the params off and just go for a straight index, I’m
still seeing this:
Processing UsersController#index [GET]
Parameters: {“action”=>“index”, “controller”=>“users”}
User Load (5.6ms) SELECT * FROM users ORDER BY users.created_at
DESC LIMIT 0, 10
SQL (0.4ms) SELECT count() AS count_all FROM users
Rendering template within layouts/application
Rendering users/index
Rendered users/_user (432.4ms)
Rendered users/_user (133.4ms)
Rendered users/_user (96.1ms)
Rendered users/_user (202.4ms)
Rendered users/_user (26.1ms)
Rendered users/_user (55.6ms)
Rendered users/_user (51.3ms)
Rendered users/_user (21.8ms)
Rendered users/_user (38.3ms)
Rendered users/_user (47.9ms)
User Load (9.3ms) SELECT * FROM users WHERE (users.id = 1)
LIMIT 1
Rendered users/_search (67.1ms)
SQL (3.8ms) SELECT count() AS count_all FROM messages WHERE
(messages.receiver_id = 1 AND (messages.read = 0))
Rendered users/_user_bar (134.7ms)
Completed in 1861ms (View: 1534, DB: 19)
I had thought that it had something had to do with the size of the
about_me as mentioned before, but I checked again, and some of those
long-rendering user partials had no content for the about_me field…
Any other ideas as to why this could be taking so long to render?
Thanks a lot
Avishai
Yep I agree there, you should create thumbs that
are totally separate. Otherwise your sending megs instead of
K. And you can create the thumbs on new user signup. I’ve done
that, and it woks really well. Really need to check your image sizes.
On Apr 7, 5:18 am, Harold A. Giménez Ch. [email protected]
To be honest, I really don’t know what’s going on, but I would try
commenting out the image_tag. First of all, it is probably causing
another
trip to the DB per user. Second, I don’t know how heavy the images are,
but
using height and width may be hiding the fact that they’re big, and
you’re
just using html to scale them down on your view. Do you see similar
results
when completely removing the images on that _user partial?