Forum: Ruby on Rails Ridiculously Slow View Rendering

Announcement (2017-05-07): www.ruby-forum.com is now read-only since I unfortunately do not have the time to support and maintain the forum any more. Please see rubyonrails.org/community and ruby-lang.org/en/community for other Rails- und Ruby-related community platforms.
Avishai (Guest)
on 2009-04-06 19:15
(Received via mailing list)
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
<div>
        <h2>Users</h2>
         <%= render :partial => "users/user", :collection => @users %>
        <%= will_paginate @users %>
        <% if @users.empty? -%>
                <p class="infobox">Looks like we couldn't find
anything matching your search. Maybe you should consider broadening it?
</p>
        <% end -%>
</div>

#_user.html.erb
<% div_for user do %>
        <h2><%= link_to(image_tag(user.photo.url(:small), :alt =>
user.login, :height => 130, :width => 130, :class => "profile-photo"),
user) %><%= link_to(user.login, user) %></h2>
        <p class="user-location"><%= user.age %> / <%= user.sex %> / <
%= user.city %>, <%= user.state %></p>
        <p class="user-summary"><%= truncate_words(user.about_me ||
"", 80) -%></p>
<% end %>

The template code is here too: http://gist.github.com/90786

Any ideas?

Thanks!

Avishai
Harold (Guest)
on 2009-04-06 20:59
(Received via mailing list)
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.
Frederick C. (Guest)
on 2009-04-06 21:21
(Received via mailing list)
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
Avishai (Guest)
on 2009-04-06 21:39
(Received via mailing list)
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
Avishai (Guest)
on 2009-04-06 21:51
(Received via mailing list)
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
Harold A. Giménez Ch. (Guest)
on 2009-04-06 22:35
(Received via mailing list)
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?
Avishai (Guest)
on 2009-04-06 23:05
(Received via mailing list)
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. <removed_email_address@domain.invalid>
Avishai (Guest)
on 2009-04-07 01:11
(Received via mailing list)
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
Harold A. Giménez Ch. (Guest)
on 2009-04-07 01:19
(Received via mailing list)
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?
glennswest (Guest)
on 2009-04-07 12:36
(Received via mailing list)
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. <removed_email_address@domain.invalid>
This topic is locked and can not be replied to.