I''m still trying to track down the bottleneck in some of my code and
for
this purpose I''ve hacked something together to time my code. It works
like this
def myslowmethod
BoilerPlate::Stopwatch.measure(''columns_for_attributes'') do
|sw|
# here goes some code
# and here even more
end
end
If you need to time sections within a method, it can be done like this.
Each checkpoint measures the time from the previous checkpoint; the
''real start'' checkpoint is there to skip some upfront
overhead.
def myslowmethod
BoilerPlate::Stopwatch.measure(''columns_for_attributes'') do
|sw|
sw.checkpoint(''real start'')
# here goes some code
sw.checkpoint(''section one'')
# and here even more
sw.checkpoint(''section two'')
end
end
There are still several rough edges:
- "checkpoint" is a bad name, but I was unable to find out what the
proper term is in english.
- For whatever reason (possibly entirely obvious, but still eluding me
right now), the redirection in StopwatchController raises an exception
because @controller apparently is not defined in a call to url_for.
- Time.now is possibly not the best basis for timing.
Anyway, I appreciate suggestions and improvements. Maybe the code is
even useful to anyone beside me.
Michael
module BoilerPlate
class Stopwatch
@@stopwatches = {}
attr_reader :name, :calls, :accumulated_time, :checkpoints
def initialize(name)
@name = name
reset
end
def measure
start
result = yield self
stop
result
end
def self.measure(name, &block)
self.for_name(name).measure(&block)
end
def checkpoint(name)
checkpoint_time = Time.now
@checkpoints[name] ||= 0.0
@checkpoints[name] += (checkpoint_time - @previous_time)
@previous_time = Time.now
@offset_time += (@previous_time - checkpoint_time)
end
def reset
@calls = 0
@accumulated_time = @offset_time = 0.0
@checkpoints = {}
@previous_time = Time.now
end
def self.each(&block)
@@stopwatches.values.each(&block)
end
def self.for_name(name)
@@stopwatches[name] ||= Stopwatch.new(name)
end
def self.calls_for(name)
self.for_name(name).calls
end
def self.accumluated_time_for(name)
self.for_name(name).accumluated_time
end
def self.reset_all
self.each do |sw|
sw.reset
end
end
def self.reset(name)
if sw = self.for_name(name)
sw.reset
end
end
protected
def start
@calls += 1
@offset_time = 0
@start_time = Time.now
@previous_time = @start_time
end
def stop
@stop_time = Time.now
@accumulated_time += (@stop_time - @start_time - @offset_time)
end
end
end
require_dependency ''action_view/helpers/url_helper''
require ''boilerplate/stopwatch''
class StopwatchController < ActionController::Base
include ActionView::Helpers::UrlHelper
def index
template =<<-END
<html>
<% def round3(f); (f * 1000).round.to_f / 1000; end %>
<head>
<title>Stopwatches</title>
<style type="text/css">
table { border:1px solid #ccc; border-collapse:collapse;
margin-top: 1em; }
table .subheading { text-align: center; font-weight: bold; }
td { border:1px solid #ccc; padding: 3px 8px; }
a:link, a:visited, a:active { color: #00f; font-size: medium;
font-weight: normal }
a:hover { background-color: #ff0; }
</style>
</head>
<body>
<h1>Stopwatches <a href="reset_all">[Reset
all]</a></h1>
<% BoilerPlate::Stopwatch.each do |sw| %>
<% calls = sw.calls > 0 ? sw.calls : 1 %>
<h2><%= sw.name %> <a href="reset/<%=
CGI::escape(sw.name)
%>">[Reset]</a></h2>
<table>
<tr><td>Calls</td><td><%= sw.calls
%><td /></tr>
<tr>
<td>Time</td><td><%= round3(sw.accumulated_time)
%>s</td>
<td><%= round3((sw.accumulated_time * 1000)/calls)
%>ms/call</td>
</tr>
<tr><td colspan="3"
class="subheading">Checkpoints</td></tr>
<% sw.checkpoints.each do |name,time| %>
<tr>
<td><%= name %></td><td><%= round3(time)
%>s</td>
<td><%= round3((time * 1000)/calls) %>ms/call</td>
</tr>
<% end %>
</table>
<% end %>
</body>
</html>
END
render_template(template)
end
def reset_all
BoilerPlate::Stopwatch.reset_all
redirect_to :action => ''index''
end
def reset
BoilerPlate::Stopwatch.reset(CGI::unescape(params[:id]))
redirect_to :action => ''index''
end
end
--
Michael Schuerig Life is just as deadly
mailto:michael-q5aiKMLteq4b1SvskN2V4Q@public.gmane.org
As it looks
http://www.schuerig.de/michael/ --Richard Thompson, Sibella
Ruby has Benchmark included in the standard library that is well suited for this purpose. Rails also has a framework for wrapping around it. There is also a `new` development using high resolution hardware clock probably to be released in Ruby 1.8.3. Cheers, Zsombor On 6/27/05, Michael Schuerig <michael-q5aiKMLteq4b1SvskN2V4Q@public.gmane.org> wrote:> > I''m still trying to track down the bottleneck in some of my code and for > this purpose I''ve hacked something together to time my code. It works > like this > > def myslowmethod > BoilerPlate::Stopwatch.measure(''columns_for_attributes'') do |sw| > # here goes some code > # and here even more > end > end > > If you need to time sections within a method, it can be done like this. > Each checkpoint measures the time from the previous checkpoint; the > ''real start'' checkpoint is there to skip some upfront overhead. > > def myslowmethod > BoilerPlate::Stopwatch.measure(''columns_for_attributes'') do |sw| > sw.checkpoint(''real start'') > # here goes some code > sw.checkpoint(''section one'') > # and here even more > sw.checkpoint(''section two'') > end > end > > There are still several rough edges: > - "checkpoint" is a bad name, but I was unable to find out what the > proper term is in english. > - For whatever reason (possibly entirely obvious, but still eluding me > right now), the redirection in StopwatchController raises an exception > because @controller apparently is not defined in a call to url_for. > - Time.now is possibly not the best basis for timing. > > Anyway, I appreciate suggestions and improvements. Maybe the code is > even useful to anyone beside me. > > Michael > > > module BoilerPlate > > class Stopwatch > @@stopwatches = {} > attr_reader :name, :calls, :accumulated_time, :checkpoints > > def initialize(name) > @name = name > reset > end > > def measure > start > result = yield self > stop > result > end > > def self.measure(name, &block) > self.for_name(name).measure(&block) > end > > def checkpoint(name) > checkpoint_time = Time.now > @checkpoints[name] ||= 0.0 > @checkpoints[name] += (checkpoint_time - @previous_time) > @previous_time = Time.now > @offset_time += (@previous_time - checkpoint_time) > end > > def reset > @calls = 0 > @accumulated_time = @offset_time = 0.0 > @checkpoints = {} > @previous_time = Time.now > end > > def self.each(&block) > @@stopwatches.values.each(&block) > end > > def self.for_name(name) > @@stopwatches[name] ||= Stopwatch.new(name) > end > > def self.calls_for(name) > self.for_name(name).calls > end > > def self.accumluated_time_for(name) > self.for_name(name).accumluated_time > end > > def self.reset_all > self.each do |sw| > sw.reset > end > end > > def self.reset(name) > if sw = self.for_name(name) > sw.reset > end > end > > protected > > def start > @calls += 1 > @offset_time = 0 > @start_time = Time.now > @previous_time = @start_time > end > > def stop > @stop_time = Time.now > @accumulated_time += (@stop_time - @start_time - @offset_time) > end > > end > > end > > > > require_dependency ''action_view/helpers/url_helper'' > require ''boilerplate/stopwatch'' > > class StopwatchController < ActionController::Base > include ActionView::Helpers::UrlHelper > > def index > template =<<-END > <html> > <% def round3(f); (f * 1000).round.to_f / 1000; end %> > <head> > <title>Stopwatches</title> > <style type="text/css"> > table { border:1px solid #ccc; border-collapse:collapse; > margin-top: 1em; } > table .subheading { text-align: center; font-weight: bold; } > td { border:1px solid #ccc; padding: 3px 8px; } > a:link, a:visited, a:active { color: #00f; font-size: medium; > font-weight: normal } > a:hover { background-color: #ff0; } > </style> > </head> > <body> > <h1>Stopwatches <a href="reset_all">[Reset all]</a></h1> > <% BoilerPlate::Stopwatch.each do |sw| %> > <% calls = sw.calls > 0 ? sw.calls : 1 %> > <h2><%= sw.name %> <a href="reset/<%= CGI::escape(sw.name) > %>">[Reset]</a></h2> > <table> > <tr><td>Calls</td><td><%= sw.calls %><td /></tr> > <tr> > <td>Time</td><td><%= round3(sw.accumulated_time) %>s</td> > <td><%= round3((sw.accumulated_time * 1000)/calls) > %>ms/call</td> > </tr> > <tr><td colspan="3" class="subheading">Checkpoints</td></tr> > <% sw.checkpoints.each do |name,time| %> > <tr> > <td><%= name %></td><td><%= round3(time) %>s</td> > <td><%= round3((time * 1000)/calls) %>ms/call</td> > </tr> > <% end %> > </table> > <% end %> > </body> > </html> > END > > render_template(template) > end > > def reset_all > BoilerPlate::Stopwatch.reset_all > redirect_to :action => ''index'' > end > > def reset > BoilerPlate::Stopwatch.reset(CGI::unescape(params[:id])) > redirect_to :action => ''index'' > end > > end > > > -- > Michael Schuerig Life is just as deadly > mailto:michael-q5aiKMLteq4b1SvskN2V4Q@public.gmane.org As it looks > http://www.schuerig.de/michael/ --Richard Thompson, Sibella > _______________________________________________ > Rails mailing list > Rails-1W37MKcQCpIf0INCOvqR/iCwEArCW2h5@public.gmane.org > http://lists.rubyonrails.org/mailman/listinfo/rails >-- http://deezsombor.blogspot.com
On Tuesday 28 June 2005 10:12, Dee Zsombor wrote:> Ruby has Benchmark included in the standard library that is well > suited for this purpose. Rails also has a framework for wrapping > around it.If you think so, then please give an example how to use Benchmark to time helper methods or rendering of a view. Michael -- Michael Schuerig There is no matrix, mailto:michael-q5aiKMLteq4b1SvskN2V4Q@public.gmane.org only reality. http://www.schuerig.de/michael/ --Lawrence Fishburn
On 6/28/05, Michael Schuerig <michael-q5aiKMLteq4b1SvskN2V4Q@public.gmane.org> wrote:> please give an example how to use Benchmark to > time helper methods or rendering of a view.See under the /rails/trunk/actionpack/examples/ tree. I think that just wrapping testcode written for helpers will suffice. Hope it helped, Zsombor -- http://deezsombor.blogspot.com
On Tuesday 28 June 2005 17:51, Dee Zsombor wrote:> On 6/28/05, Michael Schuerig <michael-q5aiKMLteq4b1SvskN2V4Q@public.gmane.org> wrote: > > please give an example how to use Benchmark to > > time helper methods or rendering of a view. > > See under the /rails/trunk/actionpack/examples/ tree. I think that > just wrapping testcode written for helpers will suffice.I had a look at benchmark.rb before I wrote stopwatch. I sure don''t understand all the ingenious ways it can be used, but my impression is that for my problem it is too coarse-grained. I don''t see how to measure the time an individual helper method takes or even the time taken by each of the methods the helper method is composed of. In general, I much prefer the approach taken by benchmark.rb, i.e., to isolate performance measurements outside the app instead of measuring in situ. It''s just that have found no way to do this in my case. Michael -- Michael Schuerig Life is just as deadly mailto:michael-q5aiKMLteq4b1SvskN2V4Q@public.gmane.org As it looks http://www.schuerig.de/michael/ --Richard Thompson, Sibella