From 8342174b2800937024a06273d1891730e6cf02cc Mon Sep 17 00:00:00 2001 From: Pratik Naik Date: Sat, 10 Jan 2009 01:10:30 +0000 Subject: [PATCH] Keep movin stuff in perf guide --- .../doc/guides/html/performance_testing.html | 107 +++++++------- .../doc/guides/source/performance_testing.txt | 130 +++++++++++------- 2 files changed, 137 insertions(+), 100 deletions(-) diff --git a/railties/doc/guides/html/performance_testing.html b/railties/doc/guides/html/performance_testing.html index aafb904f32..4a4d15eac6 100644 --- a/railties/doc/guides/html/performance_testing.html +++ b/railties/doc/guides/html/performance_testing.html @@ -215,10 +215,19 @@ ul#navMain {
  • - Using and understanding the log files + Helper methods +
  • - Helper methods + Request Logging
  • Other Profiling Tools @@ -494,9 +503,55 @@ alias gcrails='/Users/lifo/rubygc/bin/rails'

    And you’re ready to go. Don’t forget to use gcruby and gcrake aliases when running performance tests!

    -

    2. Using and understanding the log files

    +

    2. 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.

    +

    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

    +

    And in views:

    +
    +
    +
    <% benchmark("Showing projects partial") do %>
+  <%= render :partial => @projects %>
+<% end %>
    +
    +

    3. 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 :

    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.

    -
    -

    3. 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.

    -
    -
    -
    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
    -

    and views:

    -
    -
    -
    <% 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.

    4. Other Profiling Tools

    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 ==