mirror of
https://github.com/github/rails.git
synced 2026-04-26 03:00:59 -04:00
Keep movin stuff in perf guide
This commit is contained in:
@@ -215,10 +215,19 @@ ul#navMain {
|
||||
</ul>
|
||||
</li>
|
||||
<li>
|
||||
<a href="#_using_and_understanding_the_log_files">Using and understanding the log files</a>
|
||||
<a href="#_helper_methods">Helper methods</a>
|
||||
<ul>
|
||||
|
||||
<li><a href="#_model">Model</a></li>
|
||||
|
||||
<li><a href="#_controller">Controller</a></li>
|
||||
|
||||
<li><a href="#_view">View</a></li>
|
||||
|
||||
</ul>
|
||||
</li>
|
||||
<li>
|
||||
<a href="#_helper_methods">Helper methods</a>
|
||||
<a href="#_request_logging">Request Logging</a>
|
||||
</li>
|
||||
<li>
|
||||
<a href="#_other_profiling_tools">Other Profiling Tools</a>
|
||||
@@ -494,9 +503,55 @@ alias gcrails='/Users/lifo/rubygc/bin/rails'</tt></pre>
|
||||
</div></div>
|
||||
<div class="paragraph"><p>And you’re ready to go. Don’t forget to use <tt>gcruby</tt> and <tt>gcrake</tt> aliases when running performance tests!</p></div>
|
||||
</div>
|
||||
<h2 id="_using_and_understanding_the_log_files">2. Using and understanding the log files</h2>
|
||||
<h2 id="_helper_methods">2. Helper methods</h2>
|
||||
<div class="sectionbody">
|
||||
<div class="paragraph"><p>Rails logs files containt basic but very useful information about the time taken to serve every request. A typical log entry looks something like :</p></div>
|
||||
<div class="paragraph"><p>Rails provides various helper methods inside Active Record, Action Controller and Action View to measure the time taken by a specific code. The method is called <tt>benchmark()</tt> in all three components.</p></div>
|
||||
<h3 id="_model">2.1. Model</h3>
|
||||
<div class="listingblock">
|
||||
<div class="content"><!-- Generator: GNU source-highlight 2.9
|
||||
by Lorenzo Bettini
|
||||
http://www.lorenzobettini.it
|
||||
http://www.gnu.org/software/src-highlite -->
|
||||
<pre><tt>Project<span style="color: #990000">.</span>benchmark<span style="color: #990000">(</span><span style="color: #FF0000">"Creating project"</span><span style="color: #990000">)</span> <span style="font-weight: bold"><span style="color: #0000FF">do</span></span>
|
||||
project <span style="color: #990000">=</span> Project<span style="color: #990000">.</span>create<span style="color: #990000">(</span><span style="color: #FF0000">"name"</span> <span style="color: #990000">=></span> <span style="color: #FF0000">"stuff"</span><span style="color: #990000">)</span>
|
||||
project<span style="color: #990000">.</span>create_manager<span style="color: #990000">(</span><span style="color: #FF0000">"name"</span> <span style="color: #990000">=></span> <span style="color: #FF0000">"David"</span><span style="color: #990000">)</span>
|
||||
project<span style="color: #990000">.</span>milestones <span style="color: #990000"><<</span> Milestone<span style="color: #990000">.</span>find<span style="color: #990000">(:</span>all<span style="color: #990000">)</span>
|
||||
<span style="font-weight: bold"><span style="color: #0000FF">end</span></span></tt></pre></div></div>
|
||||
<div class="paragraph"><p>The above code benchmarks the multiple statments enclosed inside <tt>Project.benchmark("Creating project") do..end</tt> block and prints the results to the log file. The statement inside log files will look like:</p></div>
|
||||
<div class="listingblock">
|
||||
<div class="content"><!-- Generator: GNU source-highlight 2.9
|
||||
by Lorenzo Bettini
|
||||
http://www.lorenzobettini.it
|
||||
http://www.gnu.org/software/src-highlite -->
|
||||
<pre><tt>Creating projectem <span style="color: #990000">(</span><span style="color: #993399">185</span><span style="color: #990000">.</span>3ms<span style="color: #990000">)</span></tt></pre></div></div>
|
||||
<div class="paragraph"><p>Please refer to <a href="http://api.rubyonrails.com/classes/ActiveRecord/Base.html#M001336">API docs</a> for optional options to <tt>benchmark()</tt></p></div>
|
||||
<h3 id="_controller">2.2. Controller</h3>
|
||||
<div class="paragraph"><p>Similarly, you could use this helper method inside <a href="http://api.rubyonrails.com/classes/ActionController/Benchmarking/ClassMethods.html#M000715">controllers</a> ( Note that it’s a class method here ):</p></div>
|
||||
<div class="listingblock">
|
||||
<div class="content"><!-- Generator: GNU source-highlight 2.9
|
||||
by Lorenzo Bettini
|
||||
http://www.lorenzobettini.it
|
||||
http://www.gnu.org/software/src-highlite -->
|
||||
<pre><tt><span style="font-weight: bold"><span style="color: #0000FF">def</span></span> process_projects
|
||||
<span style="font-weight: bold"><span style="color: #0000FF">self</span></span><span style="color: #990000">.</span><span style="font-weight: bold"><span style="color: #0000FF">class</span></span><span style="color: #990000">.</span>benchmark<span style="color: #990000">(</span><span style="color: #FF0000">"Processing projects"</span><span style="color: #990000">)</span> <span style="font-weight: bold"><span style="color: #0000FF">do</span></span>
|
||||
Project<span style="color: #990000">.</span>process<span style="color: #990000">(</span>params<span style="color: #990000">[:</span>project_ids<span style="color: #990000">])</span>
|
||||
Project<span style="color: #990000">.</span>update_cached_projects
|
||||
<span style="font-weight: bold"><span style="color: #0000FF">end</span></span>
|
||||
<span style="font-weight: bold"><span style="color: #0000FF">end</span></span></tt></pre></div></div>
|
||||
<h3 id="_view">2.3. View</h3>
|
||||
<div class="paragraph"><p>And in <a href="http://api.rubyonrails.com/classes/ActionController/Benchmarking/ClassMethods.html#M000715">views</a>:</p></div>
|
||||
<div class="listingblock">
|
||||
<div class="content"><!-- Generator: GNU source-highlight 2.9
|
||||
by Lorenzo Bettini
|
||||
http://www.lorenzobettini.it
|
||||
http://www.gnu.org/software/src-highlite -->
|
||||
<pre><tt><span style="color: #FF0000"><% benchmark("Showing projects partial") do %></span>
|
||||
<span style="color: #FF0000"><%= render :partial =></span> <span style="color: #009900">@projects</span> <span style="color: #990000">%></span>
|
||||
<span style="color: #FF0000"><% end %></span></tt></pre></div></div>
|
||||
</div>
|
||||
<h2 id="_request_logging">3. Request Logging</h2>
|
||||
<div class="sectionbody">
|
||||
<div class="paragraph"><p>Rails log files containt basic but very useful information about the time taken to serve each request. A typical log entry looks something like :</p></div>
|
||||
<div class="listingblock">
|
||||
<div class="content"><!-- Generator: GNU source-highlight 2.9
|
||||
by Lorenzo Bettini
|
||||
@@ -514,49 +569,7 @@ http://www.lorenzobettini.it
|
||||
http://www.gnu.org/software/src-highlite -->
|
||||
<pre><tt>Completed <span style="font-weight: bold"><span style="color: #0000FF">in</span></span> 5ms <span style="color: #990000">(</span>View<span style="color: #990000">:</span> <span style="color: #993399">2</span><span style="color: #990000">,</span> DB<span style="color: #990000">:</span> <span style="color: #993399">0</span><span style="color: #990000">)</span> <span style="color: #990000">|</span> <span style="color: #993399">200</span> OK <span style="color: #990000">[</span>http<span style="color: #990000">:</span><span style="color: #FF6600">//0.0.0.0/</span>items<span style="color: #990000">]</span></tt></pre></div></div>
|
||||
<div class="paragraph"><p>This data is fairly straight forward to understand. Rails uses millisecond(ms) as the metric to measures the time taken. The complete request spent 5 ms inside Rails, out of which 2 ms were spent rendering views and none was spent communication with the database. It’s safe to assume that the remaining 3 ms were spent inside the controller.</p></div>
|
||||
</div>
|
||||
<h2 id="_helper_methods">3. Helper methods</h2>
|
||||
<div class="sectionbody">
|
||||
<div class="paragraph"><p>Rails provides various helper methods inside Active Record, Action Controller and Action View to measure the time taken by a specific code. The method is called <tt>benchmark()</tt> in all three components.</p></div>
|
||||
<div class="listingblock">
|
||||
<div class="content"><!-- Generator: GNU source-highlight 2.9
|
||||
by Lorenzo Bettini
|
||||
http://www.lorenzobettini.it
|
||||
http://www.gnu.org/software/src-highlite -->
|
||||
<pre><tt>Project<span style="color: #990000">.</span>benchmark<span style="color: #990000">(</span><span style="color: #FF0000">"Creating project"</span><span style="color: #990000">)</span> <span style="font-weight: bold"><span style="color: #0000FF">do</span></span>
|
||||
project <span style="color: #990000">=</span> Project<span style="color: #990000">.</span>create<span style="color: #990000">(</span><span style="color: #FF0000">"name"</span> <span style="color: #990000">=></span> <span style="color: #FF0000">"stuff"</span><span style="color: #990000">)</span>
|
||||
project<span style="color: #990000">.</span>create_manager<span style="color: #990000">(</span><span style="color: #FF0000">"name"</span> <span style="color: #990000">=></span> <span style="color: #FF0000">"David"</span><span style="color: #990000">)</span>
|
||||
project<span style="color: #990000">.</span>milestones <span style="color: #990000"><<</span> Milestone<span style="color: #990000">.</span>find<span style="color: #990000">(:</span>all<span style="color: #990000">)</span>
|
||||
<span style="font-weight: bold"><span style="color: #0000FF">end</span></span></tt></pre></div></div>
|
||||
<div class="paragraph"><p>The above code benchmarks the multiple statments enclosed inside <tt>Project.benchmark("Creating project") do..end</tt> block and prints the results inside log files. The statement inside log files will look like:</p></div>
|
||||
<div class="listingblock">
|
||||
<div class="content"><!-- Generator: GNU source-highlight 2.9
|
||||
by Lorenzo Bettini
|
||||
http://www.lorenzobettini.it
|
||||
http://www.gnu.org/software/src-highlite -->
|
||||
<pre><tt>Creating projectem <span style="color: #990000">(</span><span style="color: #993399">185</span><span style="color: #990000">.</span>3ms<span style="color: #990000">)</span></tt></pre></div></div>
|
||||
<div class="paragraph"><p>Please refer to <a href="http://api.rubyonrails.com/classes/ActiveRecord/Base.html#M001336">API docs</a> for optional options to <tt>benchmark()</tt></p></div>
|
||||
<div class="paragraph"><p>Similarly, you could use this helper method inside <a href="http://api.rubyonrails.com/classes/ActionController/Benchmarking/ClassMethods.html#M000715">controllers</a> ( Note that it’s a class method here ):</p></div>
|
||||
<div class="listingblock">
|
||||
<div class="content"><!-- Generator: GNU source-highlight 2.9
|
||||
by Lorenzo Bettini
|
||||
http://www.lorenzobettini.it
|
||||
http://www.gnu.org/software/src-highlite -->
|
||||
<pre><tt><span style="font-weight: bold"><span style="color: #0000FF">def</span></span> process_projects
|
||||
<span style="font-weight: bold"><span style="color: #0000FF">self</span></span><span style="color: #990000">.</span><span style="font-weight: bold"><span style="color: #0000FF">class</span></span><span style="color: #990000">.</span>benchmark<span style="color: #990000">(</span><span style="color: #FF0000">"Processing projects"</span><span style="color: #990000">)</span> <span style="font-weight: bold"><span style="color: #0000FF">do</span></span>
|
||||
Project<span style="color: #990000">.</span>process<span style="color: #990000">(</span>params<span style="color: #990000">[:</span>project_ids<span style="color: #990000">])</span>
|
||||
Project<span style="color: #990000">.</span>update_cached_projects
|
||||
<span style="font-weight: bold"><span style="color: #0000FF">end</span></span>
|
||||
<span style="font-weight: bold"><span style="color: #0000FF">end</span></span></tt></pre></div></div>
|
||||
<div class="paragraph"><p>and <a href="http://api.rubyonrails.com/classes/ActionController/Benchmarking/ClassMethods.html#M000715">views</a>:</p></div>
|
||||
<div class="listingblock">
|
||||
<div class="content"><!-- Generator: GNU source-highlight 2.9
|
||||
by Lorenzo Bettini
|
||||
http://www.lorenzobettini.it
|
||||
http://www.gnu.org/software/src-highlite -->
|
||||
<pre><tt><span style="color: #FF0000"><% benchmark("Showing projects partial") do %></span>
|
||||
<span style="color: #FF0000"><%= render :partial =></span> <span style="color: #009900">@projects</span> <span style="color: #990000">%></span>
|
||||
<span style="color: #FF0000"><% end %></span></tt></pre></div></div>
|
||||
<div class="paragraph"><p>Michael Koziarski has an <a href="http://www.therailsway.com/2009/1/6/requests-per-second">interesting blog post</a> explaining the importance of using milliseconds as the metric.</p></div>
|
||||
</div>
|
||||
<h2 id="_other_profiling_tools">4. Other Profiling Tools</h2>
|
||||
<div class="sectionbody">
|
||||
|
||||
@@ -202,31 +202,47 @@ Tree output is profiling information in calltree format for use by kcachegrind a
|
||||
|
||||
To get the best from Rails performance test cases, you need to build a special Ruby binary with some super powers - GC patch for measuring GC Runs/Time and memory/object allocation profiling. This process is very straight forward. If you've never compiled a Ruby binary before, you can follow the following steps to build a ruby binary inside your home directory:
|
||||
|
||||
==== Compile ====
|
||||
==== Instllation ====
|
||||
|
||||
Compile Ruby and apply this http://rubyforge.org/tracker/download.php/1814/7062/17676/3291/ruby186gc.patch[GC Patch]:
|
||||
|
||||
==== Download and Extract ====
|
||||
|
||||
[source, shell]
|
||||
----------------------------------------------------------------------------
|
||||
[lifo@null ~]$ mkdir rubygc
|
||||
[lifo@null ~]$ wget <download the latest stable ruby from ftp://ftp.ruby-lang.org/pub/ruby>
|
||||
[lifo@null ~]$ tar -xzvf <ruby-version.tar.gz>
|
||||
[lifo@null ~]$ cd <ruby-version>
|
||||
----------------------------------------------------------------------------
|
||||
|
||||
==== Apply the patch ====
|
||||
|
||||
[source, shell]
|
||||
----------------------------------------------------------------------------
|
||||
[lifo@null ruby-version]$ curl http://rubyforge.org/tracker/download.php/1814/7062/17676/3291/ruby186gc.patch | patch -p0
|
||||
[lifo@null ruby-version]$ ./configure --prefix=/Users/lifo/rubygc
|
||||
----------------------------------------------------------------------------
|
||||
|
||||
==== Configure and Install ====
|
||||
|
||||
The following will install ruby in your home directory's +/rubygc+ directory. Make sure to replace +<homedir>+ with a full patch to your actual home directory.
|
||||
|
||||
[source, shell]
|
||||
----------------------------------------------------------------------------
|
||||
[lifo@null ruby-version]$ ./configure --prefix=/<homedir>/rubygc
|
||||
[lifo@null ruby-version]$ make && make install
|
||||
----------------------------------------------------------------------------
|
||||
|
||||
==== Prepare aliases ====
|
||||
|
||||
Add the following lines in your ~/.profile for convenience:
|
||||
For convenience, add the following lines in your ~/.profile after replacing <username> with your :
|
||||
|
||||
----------------------------------------------------------------------------
|
||||
alias gcruby='/Users/lifo/rubygc/bin/ruby'
|
||||
alias gcrake='/Users/lifo/rubygc/bin/rake'
|
||||
alias gcgem='/Users/lifo/rubygc/bin/gem'
|
||||
alias gcirb='/Users/lifo/rubygc/bin/irb'
|
||||
alias gcrails='/Users/lifo/rubygc/bin/rails'
|
||||
alias gcruby='~/rubygc/bin/ruby'
|
||||
alias gcrake='~/rubygc/bin/rake'
|
||||
alias gcgem='~/rubygc/bin/gem'
|
||||
alias gcirb='~/rubygc/bin/irb'
|
||||
alias gcrails='~/rubygc/bin/rails'
|
||||
----------------------------------------------------------------------------
|
||||
|
||||
==== Install rubygems and some basic gems ====
|
||||
@@ -250,9 +266,58 @@ If installing +mysql+ fails, you can try to install it manually:
|
||||
|
||||
And you're ready to go. Don't forget to use +gcruby+ and +gcrake+ aliases when running performance tests!
|
||||
|
||||
== Using and understanding the log files ==
|
||||
== Helper methods ==
|
||||
|
||||
Rails logs files containt basic but very useful information about the time taken to serve every request. A typical log entry looks something like :
|
||||
Rails provides various helper methods inside Active Record, Action Controller and Action View to measure the time taken by a specific code. The method is called +benchmark()+ in all three components.
|
||||
|
||||
=== Model ===
|
||||
|
||||
[source, ruby]
|
||||
----------------------------------------------------------------------------
|
||||
Project.benchmark("Creating project") do
|
||||
project = Project.create("name" => "stuff")
|
||||
project.create_manager("name" => "David")
|
||||
project.milestones << Milestone.find(:all)
|
||||
end
|
||||
----------------------------------------------------------------------------
|
||||
|
||||
The above code benchmarks the multiple statments enclosed inside +Project.benchmark("Creating project") do..end+ block and prints the results to the log file. The statement inside log files will look like:
|
||||
|
||||
[source, ruby]
|
||||
----------------------------------------------------------------------------
|
||||
Creating projectem (185.3ms)
|
||||
----------------------------------------------------------------------------
|
||||
|
||||
Please refer to http://api.rubyonrails.com/classes/ActiveRecord/Base.html#M001336[API docs] for optional options to +benchmark()+
|
||||
|
||||
=== Controller ===
|
||||
|
||||
Similarly, you could use this helper method inside http://api.rubyonrails.com/classes/ActionController/Benchmarking/ClassMethods.html#M000715[controllers] ( Note that it's a class method here ):
|
||||
|
||||
[source, ruby]
|
||||
----------------------------------------------------------------------------
|
||||
def process_projects
|
||||
self.class.benchmark("Processing projects") do
|
||||
Project.process(params[:project_ids])
|
||||
Project.update_cached_projects
|
||||
end
|
||||
end
|
||||
----------------------------------------------------------------------------
|
||||
|
||||
=== View ===
|
||||
|
||||
And in http://api.rubyonrails.com/classes/ActionController/Benchmarking/ClassMethods.html#M000715[views]:
|
||||
|
||||
[source, ruby]
|
||||
----------------------------------------------------------------------------
|
||||
<% benchmark("Showing projects partial") do %>
|
||||
<%= render :partial => @projects %>
|
||||
<% end %>
|
||||
----------------------------------------------------------------------------
|
||||
|
||||
== Request Logging ==
|
||||
|
||||
Rails log files containt basic but very useful information about the time taken to serve each request. A typical log entry looks something like :
|
||||
|
||||
[source, ruby]
|
||||
----------------------------------------------------------------------------
|
||||
@@ -269,50 +334,9 @@ For this section, we're only interested in the last line from that log entry:
|
||||
Completed in 5ms (View: 2, DB: 0) | 200 OK [http://0.0.0.0/items]
|
||||
----------------------------------------------------------------------------
|
||||
|
||||
This data is fairly straight forward to understand. Rails uses millisecond(ms) as the metric to measures the time taken. The complete request spent 5 ms inside Rails, out of which 2 ms were spent rendering views and none was spent communication with the database. It's safe to assume that the remaining 3 ms were spent inside the controller.
|
||||
This data is fairly straight forward to understand. Rails uses millisecond(ms) as the metric to measures the time taken. The complete request spent 5 ms inside Rails, out of which 2 ms were spent rendering views and none was spent communication with the database. It's safe to assume that the remaining 3 ms were spent inside the controller.
|
||||
|
||||
== Helper methods ==
|
||||
|
||||
Rails provides various helper methods inside Active Record, Action Controller and Action View to measure the time taken by a specific code. The method is called +benchmark()+ in all three components.
|
||||
|
||||
[source, ruby]
|
||||
----------------------------------------------------------------------------
|
||||
Project.benchmark("Creating project") do
|
||||
project = Project.create("name" => "stuff")
|
||||
project.create_manager("name" => "David")
|
||||
project.milestones << Milestone.find(:all)
|
||||
end
|
||||
----------------------------------------------------------------------------
|
||||
|
||||
The above code benchmarks the multiple statments enclosed inside +Project.benchmark("Creating project") do..end+ block and prints the results inside log files. The statement inside log files will look like:
|
||||
|
||||
[source, ruby]
|
||||
----------------------------------------------------------------------------
|
||||
Creating projectem (185.3ms)
|
||||
----------------------------------------------------------------------------
|
||||
|
||||
Please refer to http://api.rubyonrails.com/classes/ActiveRecord/Base.html#M001336[API docs] for optional options to +benchmark()+
|
||||
|
||||
Similarly, you could use this helper method inside http://api.rubyonrails.com/classes/ActionController/Benchmarking/ClassMethods.html#M000715[controllers] ( Note that it's a class method here ):
|
||||
|
||||
[source, ruby]
|
||||
----------------------------------------------------------------------------
|
||||
def process_projects
|
||||
self.class.benchmark("Processing projects") do
|
||||
Project.process(params[:project_ids])
|
||||
Project.update_cached_projects
|
||||
end
|
||||
end
|
||||
----------------------------------------------------------------------------
|
||||
|
||||
and http://api.rubyonrails.com/classes/ActionController/Benchmarking/ClassMethods.html#M000715[views]:
|
||||
|
||||
[source, ruby]
|
||||
----------------------------------------------------------------------------
|
||||
<% benchmark("Showing projects partial") do %>
|
||||
<%= render :partial => @projects %>
|
||||
<% end %>
|
||||
----------------------------------------------------------------------------
|
||||
Michael Koziarski has an http://www.therailsway.com/2009/1/6/requests-per-second[interesting blog post] explaining the importance of using milliseconds as the metric.
|
||||
|
||||
== Other Profiling Tools ==
|
||||
|
||||
|
||||
Reference in New Issue
Block a user