Advanced Rails - Building Industrial-Strength Web Apps in Record Time

156 | Chapter 6: Performance

First, we need to install the ruby-prof gem:

$ sudo gem install ruby-prof

We need to write an integration script that drives the profiler. As mentioned previ-
ously, this script can be arbitrarily complicated, but ours will be a single request. The
script uses the same methods as integration scripts, except that the script’s execu-
tion is wrapped in an integration runner (technically, the script’s text is inserted into
the runner usinginstance_eval), so the integration session methods can be called as
top-level methods.

test_script.rb
post '/searches', :search => {:pclass => 1, :city_id => 149, :subtype => 'HOUSE'}

We can drive the profiler with this script. We will also specify the number of trials;
this is a fairly long-running action (around half a second on my machine without the
profiling overhead), so we will run 10 trials:

$ script/performance/request -n 10 test_script.rb

This will generate two profiles in thetmpdirectory (and open them usingopenon
OS X). The flat profile, which we have seen before, istmp/profile-flat.txt. The new
graph profile, which is much more detailed, istmp/profile-graph.html.

The graph profile is extremely complicated, because it is a linearized version of the
call graph for every function that was called during profiling. When opened in a
browser, it starts off as shown in Figure 6-2.

We will examine portions of this graph, but a complete description of these fields is
beyond the scope of this book. An introduction is available at http://ruby-prof.
rubyforge.org/graph.txt.

The profile is divided into blocks, which are separated by horizontal lines. Each
block in this profile is centered around one function—the one in boldface that has
values in the first two columns (%Totaland%Self). If we only look at that one line
from each block, we have a fairly standard flat profile, like the one we saw previ-
ously from Ruby’s Profiler. The%Totalcolumn indicates the percentage of overall
time spent in this method and any methods it calls (and recursively on down); the
%Self column excludes children and only relates to the current method.

The added value that we receive from the graph profile is the parent and child infor-
mation in each block. Each function has zero or more parents (functions that called
this function) and zero or more children (functions called by this function). Parents
are listed above the current function within a block, and children are listed below the
current function.