Permalink
Browse files

Some more perf guide stuff

  • Loading branch information...
1 parent 79eba81 commit a2a0b44a9adb2c34770f2eef7e8db435bcdce55c @lifo lifo committed Jan 9, 2009
View
2 railties/doc/guides/html/activerecord_validations_callbacks.html
@@ -635,7 +635,7 @@ <h3 id="_the_tt_validates_presence_of_tt_helper">3.9. The <tt>validates_presence
<td class="icon">
<img src="./images/icons/note.png" alt="Note" />
</td>
-<td class="content">If you want to validate the presence of a boolean field (where the real values are true and false), you will want to use validates_inclusion_of :field_name, :in &#8658; [true, false] This is due to the way Object#blank? handles boolean values. false.blank? # &#8658; true</td>
+<td class="content">If you want to validate the presence of a boolean field (where the real values are true and false), you will want to use validates_inclusion_of :field_name, :in =&gt; [true, false] This is due to the way Object#blank? handles boolean values. false.blank? # =&gt; true</td>
</tr></table>
</div>
<div class="paragraph"><p>The default error message for <tt>validates_presence_of</tt> is "<em>can&#8217;t be empty</em>".</p></div>
View
218 railties/doc/guides/html/performance_testing.html
@@ -222,17 +222,9 @@ <h2 id="site_title_tagline">Sustainable productivity for web-application develop
</li>
<li>
<a href="#_other_profiling_tools">Other Profiling Tools</a>
- <ul>
-
- <li><a href="#_httperf">httperf</a></li>
-
- <li><a href="#_rails_analyzer">Rails Analyzer</a></li>
-
- <li><a href="#_palmist">Palmist</a></li>
-
- <li><a href="#_new_relic">New Relic</a></li>
-
- </ul>
+ </li>
+ <li>
+ <a href="#_commercial_products_dedicated_to_rails_perfomance">Commercial products dedicated to Rails Perfomance</a>
</li>
<li>
<a href="#_changelog">Changelog</a>
@@ -361,41 +353,123 @@ <h2 id="_performance_test_cases">3. Performance Test Cases</h2>
<h3 id="_modes">3.1. Modes</h3>
<div class="paragraph"><p>Performance test cases can be run in two modes : Benchmarking and Profling.</p></div>
<h4 id="_benchmarking">3.1.1. Benchmarking</h4>
-<div class="paragraph"><p>Benchmarking helps you find out how fast are your test cases. To run performance tests in benchmarking mode:</p></div>
+<div class="paragraph"><p>Benchmarking helps you find out how fast are your test cases. Each Test case is run <tt>4 times</tt> in this mode. To run performance tests in benchmarking mode:</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: #990000">[</span>lifo@null application <span style="color: #990000">(</span>master<span style="color: #990000">)]</span>$ rake <span style="font-weight: bold"><span style="color: #0000FF">test</span></span><span style="color: #990000">:</span>benchmark</tt></pre></div></div>
+<pre><tt>$ rake <span style="font-weight: bold"><span style="color: #0000FF">test</span></span><span style="color: #990000">:</span>benchmark</tt></pre></div></div>
<h4 id="_profiling">3.1.2. Profiling</h4>
-<div class="paragraph"><p>Profiling helps introspect into your test cases and figure out which are the slow parts. To run performance tests in profiling mode:</p></div>
+<div class="paragraph"><p>Profiling helps introspect into your test cases and figure out which are the slow parts. Each Test case is run <tt>1 time</tt> in this mode. To run performance tests in profiling mode:</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: #990000">[</span>lifo@null application <span style="color: #990000">(</span>master<span style="color: #990000">)]</span>$ rake <span style="font-weight: bold"><span style="color: #0000FF">test</span></span><span style="color: #990000">:</span>profile</tt></pre></div></div>
+<pre><tt>$ rake <span style="font-weight: bold"><span style="color: #0000FF">test</span></span><span style="color: #990000">:</span>profile</tt></pre></div></div>
<h3 id="_metrics">3.2. Metrics</h3>
<div class="paragraph"><p>Benchmarking and profiling run performance test cases in various modes to help precisely figure out the where the problem lies.</p></div>
-<h4 id="_process_time">3.2.1. Process Time</h4>
+<h4 id="_wall_time">3.2.1. Wall Time</h4>
+<div class="paragraph"><p>Measures the real world time elapsed during the test run. It is affected by any other processes concurrently running on the system.</p></div>
+<div class="paragraph"><p>Mode : Benchmarking</p></div>
+<h4 id="_process_time">3.2.2. Process Time</h4>
<div class="paragraph"><p>Measures the time taken by the process. It is unaffected by any other processes running concurrently on the same system. Hence, process time is likely to be constant for any given performance test, irrespective of the machine load.</p></div>
-<div class="paragraph"><p>Mode : Benchmarking, Profiling</p></div>
-<h4 id="_memory">3.2.2. Memory</h4>
+<div class="paragraph"><p>Mode : Profiling</p></div>
+<h4 id="_memory">3.2.3. Memory</h4>
<div class="paragraph"><p>Measures the amount of memory used for the performance test case.</p></div>
-<div class="paragraph"><p>Mode : Benchmarking, Profiling</p></div>
-<h4 id="_objects">3.2.3. Objects</h4>
+<div class="paragraph"><p>Mode : Benchmarking, Profiling [Requires specially compiled Ruby]</p></div>
+<h4 id="_objects">3.2.4. Objects</h4>
<div class="paragraph"><p>Measures the number of objects allocated for the performance test case.</p></div>
-<div class="paragraph"><p>Mode : Benchmarking, Profiling</p></div>
-<h4 id="_gc_runs">3.2.4. GC Runs</h4>
+<div class="paragraph"><p>Mode : Benchmarking, Profiling [Requires specially compiled Ruby]</p></div>
+<h4 id="_gc_runs">3.2.5. GC Runs</h4>
<div class="paragraph"><p>Measures the number of times GC was invoked for the performance test case.</p></div>
-<div class="paragraph"><p>Mode : Benchmarking</p></div>
-<h4 id="_gc_time">3.2.5. GC Time</h4>
+<div class="paragraph"><p>Mode : Benchmarking [Requires specially compiled Ruby]</p></div>
+<h4 id="_gc_time">3.2.6. GC Time</h4>
<div class="paragraph"><p>Measures the amount of time spent in GC for the performance test case.</p></div>
-<div class="paragraph"><p>Mode : Benchmarking</p></div>
+<div class="paragraph"><p>Mode : Benchmarking [Requires specially compiled Ruby]</p></div>
<h3 id="_understanding_the_output">3.3. Understanding the output</h3>
+<div class="paragraph"><p>Performance tests generate different outputs inside <tt>tmp/performance</tt> directory based on the mode it is run in and the metric.</p></div>
<h4 id="_benchmarking_2">3.3.1. Benchmarking</h4>
+<div class="paragraph"><p>In benchmarking mode, performance tests generate two types of outputs :</p></div>
+<h5 id="_command_line">Command line</h5>
+<div class="paragraph"><p>This is the primary form of output in benchmarking mode. Example :</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>BrowsingTest<span style="font-style: italic"><span style="color: #9A1900">#test_homepage (31 ms warmup)</span></span>
+ wall_time<span style="color: #990000">:</span> <span style="color: #993399">6</span> ms
+ memory<span style="color: #990000">:</span> <span style="color: #993399">437.27</span> KB
+ objects<span style="color: #990000">:</span> <span style="color: #993399">5514</span>
+ gc_runs<span style="color: #990000">:</span> <span style="color: #993399">0</span>
+ gc_time<span style="color: #990000">:</span> <span style="color: #993399">19</span> ms</tt></pre></div></div>
+<h5 id="_csv_files">CSV files</h5>
+<div class="paragraph"><p>Performance tests results are also appended to <tt>.csv</tt> files inside <tt>tmp/performance/&lt;Class&gt;#&lt;test&gt;_&lt;metric&gt;.csv</tt> file. For example, running the default <tt>BrowsingTest#test_homepage</tt> will generate following five files :</p></div>
+<div class="ulist"><ul>
+<li>
+<p>
+BrowsingTest#test_homepage_gc_runs.csv
+</p>
+</li>
+<li>
+<p>
+BrowsingTest#test_homepage_gc_time.csv
+</p>
+</li>
+<li>
+<p>
+BrowsingTest#test_homepage_memory.csv
+</p>
+</li>
+<li>
+<p>
+BrowsingTest#test_homepage_objects.csv
+</p>
+</li>
+<li>
+<p>
+BrowsingTest#test_homepage_wall_time.csv
+</p>
+</li>
+</ul></div>
+<div class="paragraph"><p>As the results are appended to these files each time the performance tests are run in benchmarking mode, it enables you gather data over a sustainable period of time which can be very helpful with various performance analysis.</p></div>
+<div class="paragraph"><p>Sample output of +BrowsingTest#test_homepage_wall_time.csv + :</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>measurement<span style="color: #990000">,</span>created_at<span style="color: #990000">,</span>app<span style="color: #990000">,</span>rails<span style="color: #990000">,</span>ruby<span style="color: #990000">,</span>platform
+<span style="color: #993399">0.00738224999999992</span><span style="color: #990000">,</span><span style="color: #993399">2009</span>-<span style="color: #993399">01</span>-08T03<span style="color: #990000">:</span><span style="color: #993399">40</span><span style="color: #990000">:</span>29Z<span style="color: #990000">,,</span><span style="color: #993399">2.3</span><span style="color: #990000">.</span><span style="color: #993399">0</span><span style="color: #990000">.</span>master<span style="color: #990000">.</span><span style="color: #993399">0744148</span><span style="color: #990000">,</span>ruby-<span style="color: #993399">1.8</span><span style="color: #990000">.</span><span style="color: #993399">6.110</span><span style="color: #990000">,</span>i686-darwin<span style="color: #993399">9.0</span><span style="color: #990000">.</span><span style="color: #993399">0</span>
+<span style="color: #993399">0.00755874999999984</span><span style="color: #990000">,</span><span style="color: #993399">2009</span>-<span style="color: #993399">01</span>-08T03<span style="color: #990000">:</span><span style="color: #993399">46</span><span style="color: #990000">:</span>18Z<span style="color: #990000">,,</span><span style="color: #993399">2.3</span><span style="color: #990000">.</span><span style="color: #993399">0</span><span style="color: #990000">.</span>master<span style="color: #990000">.</span><span style="color: #993399">0744148</span><span style="color: #990000">,</span>ruby-<span style="color: #993399">1.8</span><span style="color: #990000">.</span><span style="color: #993399">6.110</span><span style="color: #990000">,</span>i686-darwin<span style="color: #993399">9.0</span><span style="color: #990000">.</span><span style="color: #993399">0</span>
+<span style="color: #993399">0.00762099999999993</span><span style="color: #990000">,</span><span style="color: #993399">2009</span>-<span style="color: #993399">01</span>-08T03<span style="color: #990000">:</span><span style="color: #993399">49</span><span style="color: #990000">:</span>25Z<span style="color: #990000">,,</span><span style="color: #993399">2.3</span><span style="color: #990000">.</span><span style="color: #993399">0</span><span style="color: #990000">.</span>master<span style="color: #990000">.</span><span style="color: #993399">0744148</span><span style="color: #990000">,</span>ruby-<span style="color: #993399">1.8</span><span style="color: #990000">.</span><span style="color: #993399">6.110</span><span style="color: #990000">,</span>i686-darwin<span style="color: #993399">9.0</span><span style="color: #990000">.</span><span style="color: #993399">0</span>
+<span style="color: #993399">0.00603075000000008</span><span style="color: #990000">,</span><span style="color: #993399">2009</span>-<span style="color: #993399">01</span>-08T04<span style="color: #990000">:</span><span style="color: #993399">03</span><span style="color: #990000">:</span>29Z<span style="color: #990000">,,</span><span style="color: #993399">2.3</span><span style="color: #990000">.</span><span style="color: #993399">0</span><span style="color: #990000">.</span>master<span style="color: #990000">.</span><span style="color: #993399">0744148</span><span style="color: #990000">,</span>ruby-<span style="color: #993399">1.8</span><span style="color: #990000">.</span><span style="color: #993399">6.111</span><span style="color: #990000">,</span>i686-darwin<span style="color: #993399">9.1</span><span style="color: #990000">.</span><span style="color: #993399">0</span>
+<span style="color: #993399">0.00619899999999995</span><span style="color: #990000">,</span><span style="color: #993399">2009</span>-<span style="color: #993399">01</span>-08T04<span style="color: #990000">:</span><span style="color: #993399">03</span><span style="color: #990000">:</span>53Z<span style="color: #990000">,,</span><span style="color: #993399">2.3</span><span style="color: #990000">.</span><span style="color: #993399">0</span><span style="color: #990000">.</span>master<span style="color: #990000">.</span><span style="color: #993399">0744148</span><span style="color: #990000">,</span>ruby-<span style="color: #993399">1.8</span><span style="color: #990000">.</span><span style="color: #993399">6.111</span><span style="color: #990000">,</span>i686-darwin<span style="color: #993399">9.1</span><span style="color: #990000">.</span><span style="color: #993399">0</span>
+<span style="color: #993399">0.00755449999999991</span><span style="color: #990000">,</span><span style="color: #993399">2009</span>-<span style="color: #993399">01</span>-08T04<span style="color: #990000">:</span><span style="color: #993399">04</span><span style="color: #990000">:</span>55Z<span style="color: #990000">,,</span><span style="color: #993399">2.3</span><span style="color: #990000">.</span><span style="color: #993399">0</span><span style="color: #990000">.</span>master<span style="color: #990000">.</span><span style="color: #993399">0744148</span><span style="color: #990000">,</span>ruby-<span style="color: #993399">1.8</span><span style="color: #990000">.</span><span style="color: #993399">6.110</span><span style="color: #990000">,</span>i686-darwin<span style="color: #993399">9.0</span><span style="color: #990000">.</span><span style="color: #993399">0</span>
+<span style="color: #993399">0.00595999999999997</span><span style="color: #990000">,</span><span style="color: #993399">2009</span>-<span style="color: #993399">01</span>-08T04<span style="color: #990000">:</span><span style="color: #993399">05</span><span style="color: #990000">:</span>06Z<span style="color: #990000">,,</span><span style="color: #993399">2.3</span><span style="color: #990000">.</span><span style="color: #993399">0</span><span style="color: #990000">.</span>master<span style="color: #990000">.</span><span style="color: #993399">0744148</span><span style="color: #990000">,</span>ruby-<span style="color: #993399">1.8</span><span style="color: #990000">.</span><span style="color: #993399">6.111</span><span style="color: #990000">,</span>i686-darwin<span style="color: #993399">9.1</span><span style="color: #990000">.</span><span style="color: #993399">0</span>
+<span style="color: #993399">0.00740450000000004</span><span style="color: #990000">,</span><span style="color: #993399">2009</span>-<span style="color: #993399">01</span>-09T03<span style="color: #990000">:</span><span style="color: #993399">54</span><span style="color: #990000">:</span>47Z<span style="color: #990000">,,</span><span style="color: #993399">2.3</span><span style="color: #990000">.</span><span style="color: #993399">0</span><span style="color: #990000">.</span>master<span style="color: #990000">.</span><span style="color: #993399">859e150</span><span style="color: #990000">,</span>ruby-<span style="color: #993399">1.8</span><span style="color: #990000">.</span><span style="color: #993399">6.110</span><span style="color: #990000">,</span>i686-darwin<span style="color: #993399">9.0</span><span style="color: #990000">.</span><span style="color: #993399">0</span>
+<span style="color: #993399">0.00603150000000008</span><span style="color: #990000">,</span><span style="color: #993399">2009</span>-<span style="color: #993399">01</span>-09T03<span style="color: #990000">:</span><span style="color: #993399">54</span><span style="color: #990000">:</span>57Z<span style="color: #990000">,,</span><span style="color: #993399">2.3</span><span style="color: #990000">.</span><span style="color: #993399">0</span><span style="color: #990000">.</span>master<span style="color: #990000">.</span><span style="color: #993399">859e150</span><span style="color: #990000">,</span>ruby-<span style="color: #993399">1.8</span><span style="color: #990000">.</span><span style="color: #993399">6.111</span><span style="color: #990000">,</span>i686-darwin<span style="color: #993399">9.1</span><span style="color: #990000">.</span><span style="color: #993399">0</span>
+<span style="color: #993399">0.00771250000000012</span><span style="color: #990000">,</span><span style="color: #993399">2009</span>-<span style="color: #993399">01</span>-09T15<span style="color: #990000">:</span><span style="color: #993399">46</span><span style="color: #990000">:</span>03Z<span style="color: #990000">,,</span><span style="color: #993399">2.3</span><span style="color: #990000">.</span><span style="color: #993399">0</span><span style="color: #990000">.</span>master<span style="color: #990000">.</span><span style="color: #993399">859e150</span><span style="color: #990000">,</span>ruby-<span style="color: #993399">1.8</span><span style="color: #990000">.</span><span style="color: #993399">6.110</span><span style="color: #990000">,</span>i686-darwin<span style="color: #993399">9.0</span><span style="color: #990000">.</span><span style="color: #993399">0</span></tt></pre></div></div>
<h4 id="_profiling_2">3.3.2. Profiling</h4>
+<h5 id="_command_line_2">Command line</h5>
+<div class="paragraph"><p>This is the very basic form of output in profiling mode. Example :</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>BrowsingTest<span style="font-style: italic"><span style="color: #9A1900">#test_homepage (58 ms warmup)</span></span>
+ process_time<span style="color: #990000">:</span> <span style="color: #993399">63</span> ms
+ memory<span style="color: #990000">:</span> <span style="color: #993399">832.13</span> KB
+ objects<span style="color: #990000">:</span> <span style="color: #993399">7882</span></tt></pre></div></div>
+<h5 id="_flat">Flat</h5>
+<div class="paragraph"><p>Flat output shows the total amount of time spent in each method. <a href="http://ruby-prof.rubyforge.org/files/examples/flat_txt.html">Check ruby prof documentation for a better explaination</a>.</p></div>
+<h5 id="_graph">Graph</h5>
+<div class="paragraph"><p>Graph output shows how long each method takes to run, which methods call it and which methods it calls. <a href="http://ruby-prof.rubyforge.org/files/examples/graph_txt.html">Check ruby prof documentation for a better explaination</a>.</p></div>
+<h5 id="_tree">Tree</h5>
+<div class="paragraph"><p>Tree output is profiling information in calltree format for use by kcachegrind and similar tools.</p></div>
<h3 id="_preparing_ruby_and_ruby_prof">3.4. Preparing Ruby and Ruby-prof</h3>
<div class="paragraph"><p>Before we go ahead, Rails performance testing requires you to build a special Ruby binary with some super powers - GC patch for measuring GC Runs/Time. This process is very straight forward. If you&#8217;ve never compiled a Ruby binary before, you can follow the following steps to build a ruby binary inside your home directory:</p></div>
<h4 id="_compile">3.4.1. Compile</h4>
@@ -469,103 +543,61 @@ <h3 id="_generating_performance_test">3.5. Generating performance test</h3>
</div>
<h2 id="_other_profiling_tools">4. Other Profiling Tools</h2>
<div class="sectionbody">
-<div class="paragraph"><p>There are a lot of great profiling tools out there. Some free, some not so free. This is a sort list detailing some of them.</p></div>
-<h3 id="_httperf">4.1. httperf</h3>
-<div class="paragraph"><p><a href="http://www.hpl.hp.com/research/linux/httperf/">http://www.hpl.hp.com/research/linux/httperf/</a></p></div>
-<div class="paragraph"><p>A necessary tool in your arsenal. Very useful for load testing your website.</p></div>
-<div class="paragraph"><p>#TODO write and link to a short article on how to use httperf. Anybody have a good tutorial availble.</p></div>
-<h3 id="_rails_analyzer">4.2. Rails Analyzer</h3>
-<div class="paragraph"><p>The Rails Analyzer project contains a collection of tools for Rails. It&#8217;s open source and pretty speedy. It&#8217;s not being actively worked on but is still contains some very useful tools.</p></div>
<div class="ulist"><ul>
<li>
<p>
-The Production Log Analyzer examines Rails log files and gives back a report. It also includes action_grep which will give you all log results for a particular action.
+<a href="http://www.hpl.hp.com/research/linux/httperf/">httperf</a>
</p>
</li>
<li>
<p>
-The Action Profiler similar to Ruby-Prof profiler.
+<a href="http://rails-analyzer.rubyforge.org/">Rails Analyzer</a>
</p>
</li>
<li>
<p>
-rails_stat which gives a live counter of requests per second of a running Rails app.
+<a href="http://www.flyingmachinestudios.com/projects/">Palmist</a>
</p>
</li>
+</ul></div>
+</div>
+<h2 id="_commercial_products_dedicated_to_rails_perfomance">5. Commercial products dedicated to Rails Perfomance</h2>
+<div class="sectionbody">
+<div class="ulist"><ul>
<li>
<p>
-The SQL Dependency Grapher allows you to visualize the frequency of table dependencies in a Rails application.
+<a href="http://www.newrelic.com">New Relic</a>
+</p>
+</li>
+<li>
+<p>
+<a href="http://www.fiveruns.com">Fiveruns</a>
+</p>
+</li>
+<li>
+<p>
+<a href="http://scoutapp.com">Scout</a>
</p>
</li>
</ul></div>
-<div class="paragraph"><p>Their project homepage can be found at <a href="http://rails-analyzer.rubyforge.org/">http://rails-analyzer.rubyforge.org/</a></p></div>
-<div class="paragraph"><p>The one major caveat is that it needs your log to be in a different format from how rails sets it up specifically SyslogLogger.</p></div>
-<h4 id="_sysloglogger">4.2.1. SyslogLogger</h4>
-<div class="paragraph"><p>SyslogLogger is a Logger work-alike that logs via syslog instead of to a file. You can add SyslogLogger to your Rails production environment to aggregate logs between multiple machines.</p></div>
-<div class="paragraph"><p>More information can be found out at <a href="http://rails-analyzer.rubyforge.org/hacks/classes/SyslogLogger.html">http://rails-analyzer.rubyforge.org/hacks/classes/SyslogLogger.html</a></p></div>
-<div class="paragraph"><p>If you don&#8217;t have access to your machines root system or just want something a bit easier to implement there is also a module developed by Geoffrey Grosenbach</p></div>
-<h4 id="_a_hodel_3000_compliant_logger_for_the_rest_of_us">4.2.2. A Hodel 3000 Compliant Logger for the Rest of Us</h4>
-<div class="paragraph"><p>Directions taken from
-<a href="http://topfunky.net/svn/plugins/hodel_3000_compliant_logger/lib/hodel_3000_compliant_logger.rb">link to module file</a></p></div>
-<div class="paragraph"><p>Just put the module in your lib directory and add this to your environment.rb in it&#8217;s config portion.</p></div>
-<div class="listingblock">
-<div class="content">
-<pre><tt>require 'hodel_3000_compliant_logger'
-config.logger = Hodel3000CompliantLogger.new(config.log_path)</tt></pre>
-</div></div>
-<div class="paragraph"><p>It&#8217;s that simple. Your log output on restart should look like this.</p></div>
-<div class="listingblock">
-<div class="title">Hodel 3000 Example</div>
-<div class="content">
-<pre><tt>Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]:
-Parameters: {"action"=&gt;"shipping", "controller"=&gt;"checkout"}
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]: 
-[4;36;1mBook Columns (0.003155) SHOW FIELDS FROM `books`
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]: 
-[4;35;1mBook Load (0.000881) SELECT * FROM `books` WHERE (`books`.`id` = 1 AND (`books`.`sold` = 1)) 
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]: 
-[4;36;1mShippingAddress Columns (0.002683) SHOW FIELDS FROM `shipping_addresses`
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]: 
-[4;35;1mBook Load (0.000362) SELECT ounces FROM `books` WHERE (`books`.`id` = 1) 
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]:
-Rendering template within layouts/application
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]:
-Rendering checkout/shipping
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]: 
-[4;36;1mBook Load (0.000548) SELECT * FROM `books`
-WHERE (sold = 0) LIMIT 3
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]: 
-[4;35;1mAuthor Columns (0.002571) SHOW FIELDS FROM `authors`
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]:
-Author Load (0.000811) SELECT * FROM `authors` WHERE (`authors`.`id` = 1) 
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]:
-Rendered store/_new_books (0.01358)
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]:
-Completed in 0.37297 (2 reqs/sec) | Rendering: 0.02971 (7%) | DB: 0.01697 (4%) | 200 OK [https://secure.jeffbooks/checkout/shipping]</tt></pre>
-</div></div>
-<h3 id="_palmist">4.3. Palmist</h3>
-<div class="paragraph"><p>An open source mysql query analyzer. Full featured and easy to work with. Also requires Hodel 3000
-<a href="http://www.flyingmachinestudios.com/projects/">http://www.flyingmachinestudios.com/projects/</a></p></div>
-<h3 id="_new_relic">4.4. New Relic</h3>
-<div class="paragraph"><p><a href="http://www.newrelic.com/">http://www.newrelic.com/</a></p></div>
-<div class="paragraph"><p>Pretty nifty performance tools, pricey though. They do have a basic free
-service both for when in development and when you put your application into production. Very simple installation and signup.</p></div>
-<div class="paragraph"><p>#TODO more in-depth without being like an advertisement.</p></div>
-<h4 id="_manage">4.4.1. Manage</h4>
-<div class="paragraph"><p>Like new relic a production monitoring tool.</p></div>
</div>
-<h2 id="_changelog">5. Changelog</h2>
+<h2 id="_changelog">6. Changelog</h2>
<div class="sectionbody">
<div class="paragraph"><p><a href="http://rails.lighthouseapp.com/projects/16213-rails-guides/tickets/4">Lighthouse ticket</a></p></div>
<div class="ulist"><ul>
<li>
<p>
+January 9, 2009: Rewrite by Pratik
+</p>
+</li>
+<li>
+<p>
October 17, 2008: First revision by Pratik
</p>
</li>
<li>
<p>
-September 6, 2008: Initial version by Matthew Bergman &lt;<a href="mailto:MzbPhoto@gmail.com">MzbPhoto@gmail.com</a>&gt;
+September 6, 2008: Initial version by Matthew Bergman
</p>
</li>
</ul></div>
View
196 railties/doc/guides/source/performance_testing.txt
@@ -102,62 +102,139 @@ Performance test cases can be run in two modes : Benchmarking and Profling.
==== Benchmarking ====
-Benchmarking helps you find out how fast are your test cases. To run performance tests in benchmarking mode:
+Benchmarking helps you find out how fast are your test cases. Each Test case is run +4 times+ in this mode. To run performance tests in benchmarking mode:
[source, shell]
----------------------------------------------------------------------------
-[lifo@null application (master)]$ rake test:benchmark
+$ rake test:benchmark
----------------------------------------------------------------------------
==== Profiling ====
-Profiling helps introspect into your test cases and figure out which are the slow parts. To run performance tests in profiling mode:
+Profiling helps introspect into your test cases and figure out which are the slow parts. Each Test case is run +1 time+ in this mode. To run performance tests in profiling mode:
[source, shell]
----------------------------------------------------------------------------
-[lifo@null application (master)]$ rake test:profile
+$ rake test:profile
----------------------------------------------------------------------------
=== Metrics ===
Benchmarking and profiling run performance test cases in various modes to help precisely figure out the where the problem lies.
+==== Wall Time ====
+
+Measures the real world time elapsed during the test run. It is affected by any other processes concurrently running on the system.
+
+Mode : Benchmarking
+
==== Process Time ====
Measures the time taken by the process. It is unaffected by any other processes running concurrently on the same system. Hence, process time is likely to be constant for any given performance test, irrespective of the machine load.
-Mode : Benchmarking, Profiling
+Mode : Profiling
==== Memory ====
Measures the amount of memory used for the performance test case.
-Mode : Benchmarking, Profiling
+Mode : Benchmarking, Profiling [Requires specially compiled Ruby]
==== Objects ====
Measures the number of objects allocated for the performance test case.
-Mode : Benchmarking, Profiling
+Mode : Benchmarking, Profiling [Requires specially compiled Ruby]
==== GC Runs ====
Measures the number of times GC was invoked for the performance test case.
-Mode : Benchmarking
+Mode : Benchmarking [Requires specially compiled Ruby]
==== GC Time ====
Measures the amount of time spent in GC for the performance test case.
-Mode : Benchmarking
+Mode : Benchmarking [Requires specially compiled Ruby]
=== Understanding the output ===
+Performance tests generate different outputs inside +tmp/performance+ directory based on the mode it is run in and the metric.
+
==== Benchmarking ====
+In benchmarking mode, performance tests generate two types of outputs :
+
+===== Command line =====
+
+This is the primary form of output in benchmarking mode. Example :
+
+[source, shell]
+----------------------------------------------------------------------------
+BrowsingTest#test_homepage (31 ms warmup)
+ wall_time: 6 ms
+ memory: 437.27 KB
+ objects: 5514
+ gc_runs: 0
+ gc_time: 19 ms
+----------------------------------------------------------------------------
+
+===== CSV files =====
+
+Performance tests results are also appended to +.csv+ files inside +tmp/performance/<Class>#<test>_<metric>.csv+ file. For example, running the default +BrowsingTest#test_homepage+ will generate following five files :
+
+ - BrowsingTest#test_homepage_gc_runs.csv
+ - BrowsingTest#test_homepage_gc_time.csv
+ - BrowsingTest#test_homepage_memory.csv
+ - BrowsingTest#test_homepage_objects.csv
+ - BrowsingTest#test_homepage_wall_time.csv
+
+As the results are appended to these files each time the performance tests are run in benchmarking mode, it enables you gather data over a sustainable period of time which can be very helpful with various performance analysis.
+
+Sample output of +BrowsingTest#test_homepage_wall_time.csv + :
+
+[source, shell]
+----------------------------------------------------------------------------
+measurement,created_at,app,rails,ruby,platform
+0.00738224999999992,2009-01-08T03:40:29Z,,2.3.0.master.0744148,ruby-1.8.6.110,i686-darwin9.0.0
+0.00755874999999984,2009-01-08T03:46:18Z,,2.3.0.master.0744148,ruby-1.8.6.110,i686-darwin9.0.0
+0.00762099999999993,2009-01-08T03:49:25Z,,2.3.0.master.0744148,ruby-1.8.6.110,i686-darwin9.0.0
+0.00603075000000008,2009-01-08T04:03:29Z,,2.3.0.master.0744148,ruby-1.8.6.111,i686-darwin9.1.0
+0.00619899999999995,2009-01-08T04:03:53Z,,2.3.0.master.0744148,ruby-1.8.6.111,i686-darwin9.1.0
+0.00755449999999991,2009-01-08T04:04:55Z,,2.3.0.master.0744148,ruby-1.8.6.110,i686-darwin9.0.0
+0.00595999999999997,2009-01-08T04:05:06Z,,2.3.0.master.0744148,ruby-1.8.6.111,i686-darwin9.1.0
+0.00740450000000004,2009-01-09T03:54:47Z,,2.3.0.master.859e150,ruby-1.8.6.110,i686-darwin9.0.0
+0.00603150000000008,2009-01-09T03:54:57Z,,2.3.0.master.859e150,ruby-1.8.6.111,i686-darwin9.1.0
+0.00771250000000012,2009-01-09T15:46:03Z,,2.3.0.master.859e150,ruby-1.8.6.110,i686-darwin9.0.0
+----------------------------------------------------------------------------
+
==== Profiling ====
+===== Command line =====
+
+This is the very basic form of output in profiling mode. Example :
+
+[source, shell]
+----------------------------------------------------------------------------
+BrowsingTest#test_homepage (58 ms warmup)
+ process_time: 63 ms
+ memory: 832.13 KB
+ objects: 7882
+----------------------------------------------------------------------------
+
+===== Flat =====
+
+Flat output shows the total amount of time spent in each method. http://ruby-prof.rubyforge.org/files/examples/flat_txt.html[Check ruby prof documentation for a better explaination].
+
+===== Graph =====
+
+Graph output shows how long each method takes to run, which methods call it and which methods it calls. http://ruby-prof.rubyforge.org/files/examples/graph_txt.html[Check ruby prof documentation for a better explaination].
+
+===== Tree =====
+
+Tree output is profiling information in calltree format for use by kcachegrind and similar tools.
+
=== Preparing Ruby and Ruby-prof ===
Before we go ahead, Rails performance testing requires you to build a special Ruby binary with some super powers - GC patch for measuring GC Runs/Time. 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:
@@ -240,102 +317,19 @@ Which you can modify to suit your needs.
== Other Profiling Tools ==
-There are a lot of great profiling tools out there. Some free, some not so free. This is a sort list detailing some of them.
-
-=== httperf ===
-http://www.hpl.hp.com/research/linux/httperf/[http://www.hpl.hp.com/research/linux/httperf/]
-
-A necessary tool in your arsenal. Very useful for load testing your website.
-
-#TODO write and link to a short article on how to use httperf. Anybody have a good tutorial availble.
-
-
-=== Rails Analyzer ===
-
-The Rails Analyzer project contains a collection of tools for Rails. It's open source and pretty speedy. It's not being actively worked on but is still contains some very useful tools.
-
-* The Production Log Analyzer examines Rails log files and gives back a report. It also includes action_grep which will give you all log results for a particular action.
-
-* The Action Profiler similar to Ruby-Prof profiler.
-
-* rails_stat which gives a live counter of requests per second of a running Rails app.
-
-* The SQL Dependency Grapher allows you to visualize the frequency of table dependencies in a Rails application.
-
-Their project homepage can be found at http://rails-analyzer.rubyforge.org/[http://rails-analyzer.rubyforge.org/]
-
-The one major caveat is that it needs your log to be in a different format from how rails sets it up specifically SyslogLogger.
-
-==== SyslogLogger ====
-
-SyslogLogger is a Logger work-alike that logs via syslog instead of to a file. You can add SyslogLogger to your Rails production environment to aggregate logs between multiple machines.
-
-More information can be found out at http://rails-analyzer.rubyforge.org/hacks/classes/SyslogLogger.html[http://rails-analyzer.rubyforge.org/hacks/classes/SyslogLogger.html]
-
-If you don't have access to your machines root system or just want something a bit easier to implement there is also a module developed by Geoffrey Grosenbach
-
-==== A Hodel 3000 Compliant Logger for the Rest of Us ====
-
-Directions taken from
-http://topfunky.net/svn/plugins/hodel_3000_compliant_logger/lib/hodel_3000_compliant_logger.rb[link to module file]
-
-Just put the module in your lib directory and add this to your environment.rb in it's config portion.
-
-------------------------------------------------------------
-require 'hodel_3000_compliant_logger'
-config.logger = Hodel3000CompliantLogger.new(config.log_path)
--------------------------------------------------------------
-
-It's that simple. Your log output on restart should look like this.
-
-.Hodel 3000 Example
-----------------------------------------------------------------------------
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]:
-Parameters: {"action"=>"shipping", "controller"=>"checkout"}
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]: 
-[4;36;1mBook Columns (0.003155) SHOW FIELDS FROM `books`
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]: 
-[4;35;1mBook Load (0.000881) SELECT * FROM `books` WHERE (`books`.`id` = 1 AND (`books`.`sold` = 1)) 
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]: 
-[4;36;1mShippingAddress Columns (0.002683) SHOW FIELDS FROM `shipping_addresses`
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]: 
-[4;35;1mBook Load (0.000362) SELECT ounces FROM `books` WHERE (`books`.`id` = 1) 
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]:
-Rendering template within layouts/application
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]:
-Rendering checkout/shipping
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]: 
-[4;36;1mBook Load (0.000548) SELECT * FROM `books`
-WHERE (sold = 0) LIMIT 3
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]: 
-[4;35;1mAuthor Columns (0.002571) SHOW FIELDS FROM `authors`
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]:
-Author Load (0.000811) SELECT * FROM `authors` WHERE (`authors`.`id` = 1) 
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]:
-Rendered store/_new_books (0.01358)
-Jul 15 11:45:43 matthew-bergmans-macbook-pro-15 rails[16207]:
-Completed in 0.37297 (2 reqs/sec) | Rendering: 0.02971 (7%) | DB: 0.01697 (4%) | 200 OK [https://secure.jeffbooks/checkout/shipping]
-----------------------------------------------------------------------------
-
-=== Palmist ===
-An open source mysql query analyzer. Full featured and easy to work with. Also requires Hodel 3000
-http://www.flyingmachinestudios.com/projects/[http://www.flyingmachinestudios.com/projects/]
-
-=== New Relic ===
-http://www.newrelic.com/[http://www.newrelic.com/]
-
-Pretty nifty performance tools, pricey though. They do have a basic free
-service both for when in development and when you put your application into production. Very simple installation and signup.
-
-#TODO more in-depth without being like an advertisement.
-
-==== Manage ====
+* http://www.hpl.hp.com/research/linux/httperf/[httperf]
+* http://rails-analyzer.rubyforge.org/[Rails Analyzer]
+* http://www.flyingmachinestudios.com/projects/[Palmist]
-Like new relic a production monitoring tool.
+== Commercial products dedicated to Rails Perfomance ==
+* http://www.newrelic.com[New Relic]
+* http://www.fiveruns.com[Fiveruns]
+* http://scoutapp.com[Scout]
== Changelog ==
http://rails.lighthouseapp.com/projects/16213-rails-guides/tickets/4[Lighthouse ticket]
+* January 9, 2009: Rewrite by Pratik
* October 17, 2008: First revision by Pratik
-* September 6, 2008: Initial version by Matthew Bergman <MzbPhoto@gmail.com>
+* September 6, 2008: Initial version by Matthew Bergman

0 comments on commit a2a0b44

Please sign in to comment.