-
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.
+
2.1. Model
+
+
+
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:
+
+
+
Creating projectem (185.3ms)
+
Please refer to API docs for optional options to benchmark()
+
2.2. Controller
+
Similarly, you could use this helper method inside controllers ( Note that it’s a class method here ):
+
+
+
def process_projects
+ self.class.benchmark("Processing projects") do
+ Project.process(params[:project_ids])
+ Project.update_cached_projects
+ end
+end
+
2.3. View
+
+
+
+
<% benchmark("Showing projects partial") do %>
+ <%= render :partial => @projects %>
+<% end %>
+
+
Rails log files containt basic but very useful information about the time taken to serve each request. A typical log entry looks something like :
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.
-
-
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.
-
-
-
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:
-
-
-
Creating projectem (185.3ms)
-
Please refer to API docs for optional options to benchmark()
-
Similarly, you could use this helper method inside controllers ( Note that it’s a class method here ):
-
-
-
def process_projects
- self.class.benchmark("Processing projects") do
- Project.process(params[:project_ids])
- Project.update_cached_projects
- end
-end
-
-
-
-
<% benchmark("Showing projects partial") do %>
- <%= render :partial => @projects %>
-<% end %>
+
Michael Koziarski has an interesting blog post explaining the importance of using milliseconds as the metric.
diff --git a/railties/doc/guides/source/performance_testing.txt b/railties/doc/guides/source/performance_testing.txt
index 7df384c7af..f42b3686b7 100644
--- a/railties/doc/guides/source/performance_testing.txt
+++ b/railties/doc/guides/source/performance_testing.txt
@@ -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
[lifo@null ~]$ tar -xzvf
[lifo@null ~]$ cd
+----------------------------------------------------------------------------
+
+==== 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 ++ with a full patch to your actual home directory.
+
+[source, shell]
+----------------------------------------------------------------------------
+[lifo@null ruby-version]$ ./configure --prefix=//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 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 ==