Tom
2006-Dec-01 00:18 UTC
Apparently poor performance in partial rendering - string concatenation problems?
Hi all,
I have a page which displays search results, and each result has a
common format. So I have a partial that describes an individual search
result, and I iterate on that partial to show the results.
I''m finding performance is abysmal, and to my surprise it''s
unrelated
to:
- my database query (runs fast)
- calculations done in the partial (I''ve removed them all and
experimentally just put static html in the partial)
It really seems to all be in string concatenation. For example, in my
search results page if I do this on my search results page, it runs in
under a HALF a second (with 50 items):
output = []
bookmark_list.each{|bm| output <<
render_to_string(:partial=>''list_item'', :object=>bm)}
However as soon as I take that output variable and print it to the
screen, the execution time jumps up to almost THREE seconds:
<%=output%>
That one line seems to slam the server - and the only thing that line
does is print the output (yes, it also does an array.join, but I''ve
added that and found no serious performance impact).
The big bummer here is that it means that even if I cached the output
it would save me nothing, because the big slowdown is when I add that
output to the body of the page. It seems like something is really slow
when appending that big string to the page.
Does anyone know why this is happening? It''s really surprising to me,
and I''m not even sure what workarounds are available. Interestingly,
I''ve found if I cut the search results partial
(''list_item'') so all of
the HTML is on one line, it cut the execution time down from about 3
seconds to just under 2 seconds. There''s definitely something at work
here that I''m not understanding. Since the use of partials is so
common, it seems like these kinds of operations would not be unusual,
so I''m hoping someone out there has some insight to what''s
going on.
Thank you in advance!
Tom Lianza
--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups
"Ruby on Rails: Talk" group.
To post to this group, send email to
rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org
To unsubscribe from this group, send email to
rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org
For more options, visit this group at
http://groups.google.com/group/rubyonrails-talk?hl=en
-~----------~----~----~----~------~----~------~--~---
Jeff Pritchard
2006-Dec-01 03:41 UTC
Re: Apparently poor performance in partial rendering - strin
Tom Lianza wrote:> Hi all, > > I have a page which displays search results, and each result has a > common format. So I have a partial that describes an individual search > result, and I iterate on that partial to show the results. > > > Does anyone know why this is happening? It''s really surprising to me, > and I''m not even sure what workarounds are available. Interestingly, > I''ve found if I cut the search results partial (''list_item'') so all of > the HTML is on one line, it cut the execution time down from about 3 > seconds to just under 2 seconds. There''s definitely something at work > here that I''m not understanding. Since the use of partials is so > common, it seems like these kinds of operations would not be unusual, > so I''m hoping someone out there has some insight to what''s going on. > > Thank you in advance! > Tom LianzaTom, I don''t know the answer, but I think it will almost certainly have something to do with what you are using for a server. Is this local using Webrick? Or is it deployed and using a real webserver, and if so, which one? If it is all local so far, it might make sense to try setting up an alternative server such as Apache or Lightpd and see if the problem goes away altogether. What you choose would probably depend on what your development machine is. I use Lighty on my Mac and everything always seems really fast. jp -- Posted via http://www.ruby-forum.com/. --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
Jeff Pritchard
2006-Dec-01 03:56 UTC
Re: Apparently poor performance in partial rendering - strin
Tom Lianza wrote:> Hi all, > > I have a page which displays search results, and each result has a > common format. So I have a partial that describes an individual search > result, and I iterate on that partial to show the results. > > Thank you in advance! > Tom LianzaIt just occurred to me that it might be instructive to see what that line of text looks like before you output it. I''m wondering if the end result might be that you are doing 50 separate ajax renders to make the stuff show up on the screen (instead of one big render). jp -- Posted via http://www.ruby-forum.com/. --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
Jeff Pritchard wrote:> Tom Lianza wrote: > > Hi all, > > > > I have a page which displays search results, and each result has a > > common format. So I have a partial that describes an individual search > > result, and I iterate on that partial to show the results. > > > > > > Does anyone know why this is happening? It''s really surprising to me, > > and I''m not even sure what workarounds are available. Interestingly, > > I''ve found if I cut the search results partial (''list_item'') so all of > > the HTML is on one line, it cut the execution time down from about 3 > > seconds to just under 2 seconds. There''s definitely something at work > > here that I''m not understanding. Since the use of partials is so > > common, it seems like these kinds of operations would not be unusual, > > so I''m hoping someone out there has some insight to what''s going on. > > > > Thank you in advance! > > Tom Lianza > > Tom, I don''t know the answer, but I think it will almost certainly have > something to do with what you are using for a server. Is this local > using Webrick? Or is it deployed and using a real webserver, and if so, > which one?Sorry, I should have been more clear about where those numbers are coming from. I''ve been benchmarking the system via the command-line functional tests to get those numbers. I''m not using a client, a web server, or doing anything over a network connection - I''ve intentionally eliminated all of those variables. I''m just using the standard functional test framework provided with Rails. For what it''s worth, my benchmarks are comparable on my mac (dual core mini) and laptop (gentoo linux, 2ghz). The benchmarks look like this. The first column represents the number of items in the search result. You can see the execution time grows fairly linearly: user system total real 0 0.130000 0.000000 0.130000 ( 0.150675) 1 0.070000 0.000000 0.070000 ( 0.081635) 2 0.110000 0.000000 0.110000 ( 0.116907) 3 0.110000 0.000000 0.110000 ( 0.121843) 4 0.120000 0.000000 0.120000 ( 0.121839) 5 0.310000 0.000000 0.310000 ( 0.315779) 6 0.310000 0.000000 0.310000 ( 0.313566) 7 0.300000 0.000000 0.300000 ( 0.315578) 8 0.310000 0.000000 0.310000 ( 0.319840) 9 0.310000 0.000000 0.310000 ( 0.323880) 10 0.540000 0.010000 0.550000 ( 0.549162) 11 0.510000 0.000000 0.510000 ( 0.520871) 12 0.550000 0.000000 0.550000 ( 0.551898) 13 0.550000 0.000000 0.550000 ( 0.558383) 14 0.550000 0.010000 0.560000 ( 0.559715) 15 0.740000 0.010000 0.750000 ( 0.750723) 16 0.780000 0.000000 0.780000 ( 0.788720) 17 0.750000 0.010000 0.760000 ( 0.756788) 18 0.790000 0.000000 0.790000 ( 0.812792) 19 0.790000 0.000000 0.790000 ( 0.816859) 20 1.020000 0.000000 1.020000 ( 1.048609) 21 1.010000 0.000000 1.010000 ( 1.024415) 22 1.010000 0.000000 1.010000 ( 1.026359) 23 1.010000 0.000000 1.010000 ( 1.030071) 24 1.020000 0.010000 1.030000 ( 1.032542) 25 1.250000 0.010000 1.260000 ( 1.264821) 26 1.250000 0.010000 1.260000 ( 1.271283) 27 1.270000 0.010000 1.280000 ( 1.323564) 28 1.280000 0.000000 1.280000 ( 1.305153) 29 1.290000 0.000000 1.290000 ( 1.314197) 30 1.520000 0.000000 1.520000 ( 1.537685) 31 1.570000 0.010000 1.580000 ( 1.616285) 32 1.570000 0.010000 1.580000 ( 1.591001) 33 1.560000 0.010000 1.570000 ( 1.581793) 34 1.560000 0.010000 1.570000 ( 1.583032) 35 1.820000 0.000000 1.820000 ( 1.848094) 36 1.830000 0.010000 1.840000 ( 1.844669) 37 1.820000 0.010000 1.830000 ( 1.853609) 38 1.870000 0.010000 1.880000 ( 1.890035) 39 1.870000 0.010000 1.880000 ( 1.894273) 40 2.090000 0.010000 2.100000 ( 2.116339) 41 2.130000 0.010000 2.140000 ( 2.158593) 42 2.170000 0.020000 2.190000 ( 2.223613) 43 2.190000 0.010000 2.200000 ( 2.251828) 44 2.190000 0.010000 2.200000 ( 2.213679) 45 2.420000 0.020000 2.440000 ( 2.490541) 46 2.480000 0.020000 2.500000 ( 2.622734) 47 2.460000 0.010000 2.470000 ( 2.567351) 48 2.490000 0.010000 2.500000 ( 2.517507) 49 2.530000 0.010000 2.540000 ( 2.644702) 50 2.810000 0.020000 2.830000 ( 2.852417) --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
Frederick Cheung
2006-Dec-01 09:27 UTC
Re: Apparently poor performance in partial rendering - strin
That''s very odd, I''ve never seen anything like that. I''ve you tried profiling to make sure where the slow down is ? How much text does each partial generate ? I''m pretty sure I''ve done similar type things with no where near such a rendering slowdown. Fred -- Posted via http://www.ruby-forum.com/. --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
Steve Longdo
2006-Dec-02 01:53 UTC
Re: Apparently poor performance in partial rendering - string concatenation problems?
Don''t render_to_string use render_partial instead:
<% for item in @list %>
<%= render_partial ''item'', item %>
<% end %>
On 11/30/06, Tom <tlianza-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org >
wrote:>
>
> Hi all,
>
> I have a page which displays search results, and each result has a
> common format. So I have a partial that describes an individual search
> result, and I iterate on that partial to show the results.
>
> I''m finding performance is abysmal, and to my surprise
it''s unrelated
> to:
> - my database query (runs fast)
> - calculations done in the partial (I''ve removed them all and
> experimentally just put static html in the partial)
>
> It really seems to all be in string concatenation. For example, in my
> search results page if I do this on my search results page, it runs in
> under a HALF a second (with 50 items):
>
> output = []
> bookmark_list.each{|bm| output <<
> render_to_string(:partial=>''list_item'',
:object=>bm)}
>
> However as soon as I take that output variable and print it to the
> screen, the execution time jumps up to almost THREE seconds:
>
> <%=output%>
>
> That one line seems to slam the server - and the only thing that line
> does is print the output (yes, it also does an array.join, but
I''ve
> added that and found no serious performance impact).
>
> The big bummer here is that it means that even if I cached the output
> it would save me nothing, because the big slowdown is when I add that
> output to the body of the page. It seems like something is really slow
> when appending that big string to the page.
>
> Does anyone know why this is happening? It''s really surprising to
me,
> and I''m not even sure what workarounds are available.
Interestingly,
> I''ve found if I cut the search results partial
(''list_item'') so all of
> the HTML is on one line, it cut the execution time down from about 3
> seconds to just under 2 seconds. There''s definitely something at
work
> here that I''m not understanding. Since the use of partials is so
> common, it seems like these kinds of operations would not be unusual,
> so I''m hoping someone out there has some insight to
what''s going on.
>
> Thank you in advance!
> Tom Lianza
>
>
> >
>
--
Thanks,
-Steve
http://www.stevelongdo.com
--~--~---------~--~----~------------~-------~--~----~
You received this message because you are subscribed to the Google Groups
"Ruby on Rails: Talk" group.
To post to this group, send email to
rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org
To unsubscribe from this group, send email to
rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org
For more options, visit this group at
http://groups.google.com/group/rubyonrails-talk?hl=en
-~----------~----~----~----~------~----~------~--~---
Steve Longdo
2006-Dec-02 01:57 UTC
Re: Apparently poor performance in partial rendering - strin
Possibly Tom is running into a GC problem which relates to the expansion of Strings and lots of temporary objects as described by _why (Check out Mistake#1): http://whytheluckystiff.net/articles/theFullyUpturnedBin.html On 12/1/06, Frederick Cheung <rails-mailing-list-ARtvInVfO7ksV2N9l4h3zg@public.gmane.org> wrote:> > > That''s very odd, I''ve never seen anything like that. I''ve you tried > profiling to make sure where the slow down is ? > How much text does each partial generate ? I''m pretty sure I''ve done > similar type things with no where near such a rendering slowdown. > > Fred > > -- > Posted via http://www.ruby-forum.com/. > > > >-- Thanks, -Steve http://www.stevelongdo.com --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
Tom
2006-Dec-02 02:51 UTC
Re: Apparently poor performance in partial rendering - string concatenation problems?
Steve Longdo wrote:> Don''t render_to_string use render_partial instead: > > <% for item in @list %> > <%= render_partial ''item'', item %> > <% end %>It may not have been obvious from my code snippet, but the reason I was trying render_to_string was because I was trying to avoid the exact problem that _why describes in Mistake #1. I was doing render_to_string so that I could use the (more efficient) concatenation to an array (the thing named ''output'' in my snippet), rather than relying on <%=render_partial which, as I understand it, actually uses the less efficient string<< under the hood. Either way I do it, I don''t see a substantial performance difference, unfortunately. The time it takes to render the partial is the same in both cases. Perhaps there''s something I''m misunderstanding here. --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
Frederick Cheung wrote:> That''s very odd, I''ve never seen anything like that. I''ve you tried > profiling to make sure where the slow down is ? > How much text does each partial generate ? I''m pretty sure I''ve done > similar type things with no where near such a rendering slowdown. > > FredThanks for the response, Fred. I also appreciate the validation that it feels like something is wrong here :) So, looking though the code I think I see what makes my problem different from most - I''m taking this partial and sending it back as part of an RJS template. It looks like there is a ton of string-scanning happening to convert the html down to JavaScript-able code, which is really slow. By all means, take a look at the profiling output and let me know if you agree. I also see a suspicious url_for command in there, but I have trouble knowing if that''s a serious contributor to the problem, or if it''s in my code or the rjs code. This is what appear to be the relevant blocks (in order, with irrelevant blocks omitted, if you see the word ''giftalicious'' that''s the name of my controller): -------------------------------------------------------------------------------- 4.14 3.40 0.74 18/22 String#each_char 0.00 0.00 0.00 4/22 String#_expand_ch 91.59% 75.22% 4.14 3.40 0.74 22 String#scan 0.12 0.12 0.00 77076/77798 String#<< 0.47 0.47 0.00 535034/538922 String#= 0.07 0.07 0.00 69833/70041 Fixnum#> 0.00 0.00 0.00 6/22 Array#push 0.08 0.08 0.00 69833/69851 String#length -------------------------------------------------------------------------------- 0.00 0.00 0.00 18/69851 ActionController::Rescue#perform_action 0.08 0.08 0.00 69833/69851 String#scan 1.77% 1.77% 0.08 0.08 0.00 69851 String#length -------------------------------------------------------------------------------- 4.14 0.00 4.14 18/18 Object#returning 91.59% 0.00% 4.14 0.00 4.14 18 String#each_char 0.00 0.00 0.00 18/64 Kernel#block_given? 4.14 3.40 0.74 18/22 String#scan -------------------------------------------------------------------------------- 0.00 0.00 0.00 4/538922 Hash#each 0.00 0.00 0.00 30/538922 <Object::ActionController::Routing::RouteSet>#generate_path_for_giftalicious 0.00 0.00 0.00 1/538922 ActionView::Helpers::AssetTagHelper#compute_public_path 0.00 0.00 0.00 53/538922 Array#each 0.00 0.00 0.00 86/538922 Array#include? 0.00 0.00 0.00 1/538922 GiftaliciousController#users_list 0.00 0.00 0.00 375/538922 ActiveRecord::Associations::ClassMethods::JoinDependency#construct_association 0.00 0.00 0.00 3/538922 ActionView::Base::CompiledTemplates#_run_rhtml_giftalicious__sidebar_user_banner 0.00 0.00 0.00 9/538922 Mysql::Result#each 0.00 0.00 0.00 375/538922 ActiveRecord::Associations::ClassMethods::JoinDependency#construct 0.00 0.00 0.00 1823/538922 Kernel#== 0.00 0.00 0.00 6/538922 ActiveRecord::Associations::ClassMethods::JoinDependency::JoinAssociation#table_alias_for 0.00 0.00 0.00 75/538922 ActionController::Base#render_with_no_layout 0.00 0.00 0.00 46/538922 String#tr! 0.00 0.00 0.00 2/538922 ActiveRecord::Calculations::ClassMethods#validate_calculation_options 0.00 0.00 0.00 24/538922 Fixnum#= 0.47 0.47 0.00 535034/538922 String#scan 0.00 0.00 0.00 975/538922 ERB::Compiler::ExplicitScanner#scan 10.40% 10.40% 0.47 0.47 0.00 538922 String#=-------------------------------------------------------------------------------- 0.00 0.00 0.00 1/77798 ActiveRecord::Associations::HasManyAssociation#find 0.00 0.00 0.00 9/77798 ActionController::Rescue#perform_action 0.00 0.00 0.00 1/77798 ActionView::Helpers::AssetTagHelper#compute_public_path 0.00 0.00 0.00 20/77798 Array#each 0.00 0.00 0.00 2/77798 ActiveRecord::Associations::ClassMethods#construct_finder_sql_with_included_associations 0.00 0.00 0.00 2/77798 ActiveRecord::Calculations::ClassMethods#construct_calculation_sql 0.00 0.00 0.00 10/77798 ActiveRecord::ConnectionAdapters::AbstractAdapter#format_log_entry 0.00 0.00 0.00 8/77798 ERB::Compiler::Buffer#close 0.00 0.00 0.00 1/77798 GiftaliciousController#users_list 0.00 0.00 0.00 5/77798 <Class::ActiveRecord::Base>#add_conditions! 0.00 0.00 0.00 4/77798 ActionController::UrlRewriter#rewrite_url 0.00 0.00 0.00 2/77798 <Class::ActiveRecord::Base>#construct_finder_sql 0.00 0.00 0.00 18/77798 Object#returning 0.12 0.12 0.00 77076/77798 String#scan 0.00 0.00 0.00 1/77798 ActiveRecord::ConnectionAdapters::MysqlAdapter#add_limit_offset! 0.00 0.00 0.00 252/77798 ERB::Compiler::Buffer#cr 0.00 0.00 0.00 4/77798 ActionController::Benchmarking#perform_action_without_rescue 0.00 0.00 0.00 1/77798 <Class::ActiveRecord::Base>#add_joins! 0.00 0.00 0.00 381/77798 ERB::Compiler::ExplicitScanner#scan 2.65% 2.65% 0.12 0.12 0.00 77798 String#<< -------------------------------------------------------------------------------- 0.00 0.00 0.00 1/25 Array#each 4.14 0.00 4.14 18/25 <Module::ActiveSupport::JSON>#raise_on_circular_reference 0.00 0.00 0.00 6/25 Hash#default 91.59% 0.00% 4.14 0.00 4.14 25 Proc#call 0.00 0.00 0.00 6/6064 Hash#[] 4.14 0.00 4.14 18/32 Object#returning 0.00 0.00 0.00 1/2 Test::Unit::Util::Observable#notify_listeners 4.14 0.00 4.14 18/18 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#javascript_object_for 91.59% 0.00% 4.14 0.00 4.14 18 Object#to_json 4.14 0.00 4.14 18/18 <Module::ActiveSupport::JSON>#encode -------------------------------------------------------------------------------- 4.14 0.00 4.14 18/32 Proc#call 0.00 0.00 0.00 1/32 <Class::ActionController::Base>#view_class 0.00 0.00 0.00 1/32 ActionController::Base#process 0.00 0.00 0.00 1/32 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#to_s 0.00 0.00 0.00 11/32 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#record 91.59% 0.00% 4.14 0.00 4.14 32 Object#returning 0.00 0.00 0.00 18/77798 String#<< 0.00 0.00 0.00 1/1 <Class::ActionView::Base>#debug_rjs 0.00 0.00 0.00 1/864 Kernel#send 4.14 0.00 4.14 18/18 String#each_char 0.00 0.00 0.00 1/1 <Class::ActionController::Base>#master_helper_module 0.00 0.00 0.00 11/11 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#<< 0.00 0.00 0.00 1/77 ActionController::Base#add_variables_to_assigns -------------------------------------------------------------------------------- 4.34 0.00 4.34 1/1 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator#initialize 96.02% 0.00% 4.34 0.00 4.34 1 Object#instance_exec 4.34 0.00 4.34 1/1 Method#[] 0.00 0.00 0.00 1/1 Proc#bind -------------------------------------------------------------------------------- 4.34 0.00 4.34 1/1 Object#instance_exec 96.02% 0.00% 4.34 0.00 4.34 1 Method#[] 0.00 0.00 0.00 1/9 ActionController::TestSession#[] 0.00 0.00 0.00 3/3 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#show 0.00 0.00 0.00 2/10058 Hash#[] 0.01 0.00 0.01 1/1 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#insert_html 0.00 0.00 0.00 2/627 NilClass#nil? 4.33 0.00 4.33 6/6 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#replace_html 0.00 0.00 0.00 1/9 HashWithIndifferentAccess#include? 0.00 0.00 0.00 1/1 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#hide 0.00 0.00 0.00 1/10 User#user_name -------------------------------------------------------------------------------- 0.00 0.00 0.00 1/864 ActiveRecord::Associations::HasManyAssociation#find 0.00 0.00 0.00 307/864 Array#each 0.00 0.00 0.00 83/864 ActionView::Base#compile_and_render_template 4.52 0.00 4.52 1/864 ActionController::Base#process_without_filters 0.00 0.00 0.00 1/864 ActionController::Base#perform_action_without_filters 0.00 0.00 0.00 3/864 ActionController::Routing::RouteSet#generate_path 0.00 0.00 0.00 375/864 ActiveRecord::Associations::ClassMethods::JoinDependency#construct_association 0.00 0.00 0.00 1/864 ActiveRecord::Associations::HasManyAssociation#count_records 0.00 0.00 0.00 4/864 ActiveRecord::Associations::AssociationProxy#sanitize_sql 0.00 0.00 0.00 4/864 ActiveRecord::Reflection::AssociationReflection#klass 0.00 0.00 0.00 75/864 #<Module:0xb7633acc>#render_to_string 0.00 0.00 0.00 1/864 ActiveRecord::Associations::HasAndBelongsToManyAssociation#find 0.00 0.00 0.00 1/864 Object#returning 0.00 0.00 0.00 1/864 ActionController::TestProcess#build_request_uri 0.00 0.00 0.00 1/864 Class#const_missing 0.00 0.00 0.00 4/864 <Class::ActiveRecord::Base>#define_attr_method 0.00 0.00 0.00 1/864 ActionView::Helpers::UrlHelper#url_for 100.00% 0.00% 4.52 0.00 4.52 864 Kernel#send 0.00 0.00 0.00 3/3 <Object::ActionController::Routing::RouteSet>#generate_path_for_giftalicious 4.52 0.00 4.52 1/10 ActionController::Rescue#perform_action 0.16 0.00 0.16 1/1 ActionView::Base::CompiledTemplates#_run_rhtml_giftalicious__bookmark_list 0.00 0.00 0.00 76/76 ActionController::Base#template_class 0.00 0.00 0.00 4/14 <Class::ActiveRecord::Base>#sanitize_sql 0.00 0.00 0.00 76/76 ActionController::Base#ignore_missing_templates 0.11 0.00 0.11 75/75 ActionController::Base#render_to_string 0.00 0.00 0.00 2/6 <Class::ActiveRecord::Base>#extract_options_from_args! 0.00 0.00 0.00 75/1602 Kernel#instance_variable_get 0.00 0.00 0.00 75/210 Kernel#respond_to? 0.00 0.00 0.00 75/75 ActionView::Base::CompiledTemplates#_run_rhtml_giftalicious__list_item 0.17 0.00 0.17 1/1 GiftaliciousController#users_list 0.00 0.00 0.00 375/2407 Kernel#instance_variable_set 0.00 0.00 0.00 450/1715 Symbol#to_s 0.00 0.00 0.00 1/2 ActionController::Base#rewrite_options 0.00 0.00 0.00 1/1 ActionView::Base::CompiledTemplates#_run_rhtml_giftalicious__sidebar_user_banner 4.35 0.00 4.35 1/1 ActionView::Base::CompiledTemplates#_run_rjs_giftalicious_users_list 0.00 0.00 0.00 4/4 <Class::ActiveRecord::Base>#compute_type 0.00 0.00 0.00 1/1 ActionView::Base::CompiledTemplates#_run_rhtml_giftalicious__sidebar_results_viewtoggle 0.00 0.00 0.00 1/1 ActionView::Base::CompiledTemplates#_run_rhtml_giftalicious__sidebar_custom_item 0.00 0.00 0.00 1/1 Module#include 0.00 0.00 0.00 1/1 GiftaliciousController#private_filter 0.00 0.00 0.00 1/1 ActionView::Base::CompiledTemplates#_run_rhtml_giftalicious__sidebar_tag_cloud 0.00 0.00 0.00 1/1 ApplicationController#set_charset 0.00 0.00 0.00 1/1 GiftaliciousController#returns_rjs 0.00 0.00 0.00 450/1212 ActiveRecord::Reflection::MacroReflection#name 0.00 0.00 0.00 76/76 ActionController::Base#template_root 0.00 0.00 0.00 1/1 ActionController::Base#url_for 0.00 0.00 0.00 1/3 ActiveRecord::Base#read_attribute 0.00 0.00 0.00 4/4 Module#alias_method 0.00 0.00 0.00 300/300 ActiveRecord::Associations::AssociationProxy#target 0.00 0.00 0.00 1/2 Class#const_missing 0.00 0.00 0.00 1/1 ActionView::Base::CompiledTemplates#_run_rhtml_giftalicious__filterbar_tag_cloud 0.00 0.00 0.00 300/1120 Kernel#nil? 0.00 0.00 0.00 76/161 ActionController::Base#logger 0.01 0.00 0.01 375/622 Class#new 0.01 0.00 0.01 1/1 ActionView::Base::CompiledTemplates#_run_rhtml_giftalicious__sidebar_user_summary 0.00 0.00 0.00 75/170 Array#empty? -------------------------------------------------------------------------------- 0.00 0.00 0.00 1/622 ActionController::Flash::InstanceMethods#flash_without_components 0.00 0.00 0.00 1/622 <Module::SearchHelper>#construct_filter_where 0.00 0.00 0.00 8/622 ERB#initialize 4.35 0.00 4.35 1/622 ActionView::Helpers::PrototypeHelper#update_page 0.00 0.00 0.00 1/622 ActionController::Base#initialize_template_class 0.00 0.00 0.00 1/622 Kernel#require__ 0.00 0.00 0.00 1/622 <Class::ActionController::Base>#view_class 0.00 0.00 0.00 8/622 <Class::ERB::Compiler::Scanner>#make_scanner 0.00 0.00 0.00 1/622 <Module::SearchHelper>#construct_filter_orderby 0.00 0.00 0.00 1/622 Kernel#catch 0.00 0.00 0.00 1/622 GiftaliciousController#users_list 0.00 0.00 0.00 1/622 GiftaliciousHelper#get_avatar_image_tag 0.01 0.00 0.01 375/622 Kernel#send 0.00 0.00 0.00 5/622 ActiveRecord::Associations::ClassMethods::JoinDependency#build 0.00 0.00 0.00 2/622 Logger#initialize 0.00 0.00 0.00 8/622 ERB::Compiler#compile 0.00 0.00 0.00 1/622 ActionController::Base#initialize_current_url 0.00 0.00 0.00 1/622 Test::Unit::Assertions#build_message 0.00 0.00 0.00 9/622 Mysql::Result#each 0.00 0.00 0.00 2/622 ActiveRecord::Associations::ClassMethods::JoinDependency#initialize 0.00 0.00 0.00 1/622 <Class::ActionController::Base>#action_methods 0.00 0.00 0.00 2/622 <Class::Tag>#get_cloud_for_bookmarks 0.00 0.00 0.00 1/622 ActionController::TestProcess#build_request_uri 0.00 0.00 0.00 1/622 ActiveSupport::CoreExtensions::Hash::IndifferentAccess#with_indifferent_access 0.00 0.00 0.00 169/622 <Module::Benchmark>#measure 0.00 0.00 0.00 1/622 Logger::LogDevice#initialize 0.00 0.00 0.00 8/622 ActionView::Base#create_template_source 0.00 0.00 0.00 8/622 ERB::Compiler::ExplicitScanner#scan 0.00 0.00 0.00 1/622 Set#initialize 0.00 0.00 0.00 1/622 ActionView::Base::CompiledTemplates#_run_rhtml_giftalicious__sidebar_user_summary 96.46% 0.00% 4.36 0.00 4.36 622 Class#new 0.00 0.00 0.00 169/169 Benchmark::Tms#initialize 0.00 0.00 0.00 1/1 Test::Unit::Assertions::AssertionMessage#initialize 0.00 0.00 0.00 605/761 <Class::Object>#allocate 0.00 0.00 0.00 8/8 <Class::StringScanner>#allocate 0.02 0.00 0.02 8/8 ERB#initialize 0.00 0.00 0.00 1/1 <Class::Class>#allocate 0.00 0.00 0.00 1/1 ActiveRecord::Associations::HasManyAssociation#initialize 0.00 0.00 0.00 8/8 ERB::Compiler::Scanner#initialize 0.00 0.00 0.00 5/5 ActiveRecord::Associations::ClassMethods::JoinDependency::JoinAssociation#initialize 0.00 0.00 0.00 4/122 Array#- 0.00 0.00 0.00 1/1 Logger#initialize 0.00 0.00 0.00 1/1 HashWithIndifferentAccess#initialize 0.00 0.00 0.00 1/6 ActiveRecord::Associations::ClassMethods::JoinDependency::JoinBase#initialize 0.01 0.01 0.00 76/76 ActiveRecord::Associations::HasAndBelongsToManyAssociation#initialize 0.00 0.00 0.00 1/1 MonitorMixin#initialize 0.00 0.00 0.00 2/4 Hash#initialize 0.00 0.00 0.00 4/25 <Class::Hash>#allocate 0.00 0.00 0.00 1/1 ActiveRecord::Associations::ClassMethods::JoinDependency#initialize 0.00 0.00 0.00 1/1 Class#initialize 0.00 0.00 0.00 8/8 StringScanner#initialize 0.00 0.00 0.00 1/1 ActionView::Base#initialize 0.00 0.00 0.00 301/378 ActiveRecord::Associations::AssociationProxy#initialize 0.00 0.00 0.00 1/1 Logger::Formatter#initialize 4.35 0.00 4.35 1/1 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator#initialize 0.00 0.00 0.00 4/4 Array#initialize 0.00 0.00 0.00 1/1 ActionController::Flash::FlashHash#initialize 0.00 0.00 0.00 9/9 ActiveRecord::ConnectionAdapters::Column#initialize 0.00 0.00 0.00 1/1 Logger::LogDevice#initialize 0.00 0.00 0.00 8/8 ERB::Compiler::Buffer#initialize 0.00 0.00 0.00 2/2 ActionController::UrlRewriter#initialize 0.00 0.00 0.00 8/8 ERB::Compiler#initialize 0.00 0.00 0.00 1/1 Set#initialize -------------------------------------------------------------------------------- 0.00 0.00 0.00 4/15 <Class::ActiveRecord::Base>#column_names 4.14 0.00 4.14 11/15 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#arguments_for_call 91.59% 0.00% 4.14 0.00 4.14 15 Array#map 4.14 0.00 4.14 18/18 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#javascript_object_for -------------------------------------------------------------------------------- 4.33 0.00 4.33 6/6 Method#[] 95.80% 0.00% 4.33 0.00 4.33 6 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#replace_html 4.13 0.00 4.13 6/11 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#call 0.20 0.00 0.20 6/7 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#render -------------------------------------------------------------------------------- 0.00 0.00 0.00 3/11 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#show 0.01 0.00 0.01 1/11 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#insert_html 4.13 0.00 4.13 6/11 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#replace_html 0.00 0.00 0.00 1/11 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#hide 91.59% 0.00% 4.14 0.00 4.14 11 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#call 4.14 0.00 4.14 11/11 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#arguments_for_call 0.00 0.00 0.00 11/11 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#record -------------------------------------------------------------------------------- 4.14 0.00 4.14 11/11 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#call 91.59% 0.00% 4.14 0.00 4.14 11 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#arguments_for_call 4.14 0.00 4.14 11/15 Array#map 0.00 0.00 0.00 11/154 Array#join -------------------------------------------------------------------------------- 4.35 0.00 4.35 1/1 Class#new 96.24% 0.00% 4.35 0.00 4.35 1 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator#initialize 4.34 0.00 4.34 1/1 Object#instance_exec 0.01 0.00 0.01 1/1 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator#include_helpers_from_context -------------------------------------------------------------------------------- 4.35 0.00 4.35 1/1 ActionView::Base::CompiledTemplates#_run_rjs_giftalicious_users_list 96.24% 0.00% 4.35 0.00 4.35 1 ActionView::Helpers::PrototypeHelper#update_page 0.00 0.00 0.00 1/1 ActionView::Helpers::PrototypeHelper::JavaScriptGenerator::GeneratorMethods#to_s 4.35 0.00 4.35 1/622 Class#new -------------------------------------------------------------------------------- 4.35 0.00 4.35 1/1 Kernel#send 96.24% 0.00% 4.35 0.00 4.35 1 ActionView::Base::CompiledTemplates#_run_rjs_giftalicious_users_list 4.35 0.00 4.35 1/1 ActionView::Helpers::PrototypeHelper#update_page 0.00 0.00 0.00 1/10058 Hash#[] -------------------------------------------------------------------------------- 4.35 0.00 4.35 83/83 ActionView::Base#render_file 96.24% 0.00% 4.35 0.00 4.35 83 ActionView::Base#render_template 0.00 0.00 0.00 83/10058 Hash#[] 4.35 0.01 4.34 83/83 ActionView::Base#compile_and_render_template -------------------------------------------------------------------------------- 0.00 0.00 0.00 82/83 ActionView::Base#render 4.35 0.00 4.35 1/83 ActionController::Base#render_file 96.24% 0.00% 4.35 0.00 4.35 83 ActionView::Base#render_file 0.00 0.00 0.00 83/84 ActionView::Base#pick_template_extension 4.35 0.00 4.35 83/83 ActionView::Base#render_template 0.00 0.00 0.00 83/1715 Symbol#to_s 0.00 0.00 0.00 83/94 ActionView::Base#full_template_path 0.00 0.00 0.00 83/84 ActionView::Base#path_and_extension -------------------------------------------------------------------------------- 4.35 0.01 4.34 83/83 ActionView::Base#render_template 96.24% 0.22% 4.35 0.01 4.34 83 ActionView::Base#compile_and_render_template 0.00 0.00 0.00 83/10058 Hash#[] 0.01 0.00 0.01 83/83 ActionView::Base#evaluate_assigns 0.00 0.00 0.00 83/864 Kernel#send 0.00 0.00 0.00 9/9 ActionView::Base#read_template_file 0.00 0.00 0.00 83/83 ActionView::Base#compile_template? 0.02 0.00 0.02 9/9 ActionView::Base#compile_template 0.00 0.00 0.00 83/88 ActiveSupport::CoreExtensions::Hash::Keys#symbolize_keys --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---
Tom wrote:> Frederick Cheung wrote: > > That''s very odd, I''ve never seen anything like that. I''ve you tried > > profiling to make sure where the slow down is ? > > How much text does each partial generate ? I''m pretty sure I''ve done > > similar type things with no where near such a rendering slowdown. > > > > Fred > > Thanks for the response, Fred. I also appreciate the validation that > it feels like something is wrong here :) > > So, looking though the code I think I see what makes my problem > different from most - I''m taking this partial and sending it back as > part of an RJS template. It looks like there is a ton of > string-scanning happening to convert the html down to JavaScript-able > code, which is really slow.FYI, I found this patch which will be part of rails 1.2 that supposedly helps alleviate this problem: "Performance problems with .to_json as used for .rjs templates" http://dev.rubyonrails.org/ticket/3473 Tom --~--~---------~--~----~------------~-------~--~----~ You received this message because you are subscribed to the Google Groups "Ruby on Rails: Talk" group. To post to this group, send email to rubyonrails-talk-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org To unsubscribe from this group, send email to rubyonrails-talk-unsubscribe-/JYPxA39Uh5TLH3MbocFFw@public.gmane.org For more options, visit this group at http://groups.google.com/group/rubyonrails-talk?hl=en -~----------~----~----~----~------~----~------~--~---