154 | Chapter 6: Performance
3.92 0.35 0.02 89 0.22 0.45 Array#each_index
3.92 0.37 0.02 89 0.22 0.34 Inflector.humanize
1.96 0.38 0.01 179 0.06 0.06 Kernel.===
1.96 0.39 0.01 67 0.15 0.15 String#concat
1.96 0.40 0.01 16 0.63 0.63 ActionView::Base#
template_exists?
1.96 0.41 0.01 613 0.02 0.02 String#to_s
1.96 0.42 0.01 7 1.43 1.43 MonitorMixin.synchronize
(and many more lines...)These results include the following columns.
The generated profile shows that we are spending most of our time in five functions:
html_escape (better known as h( )), gsub, compute_public_path, optionvalue
selected?, and<<. This is hard to improve upon, and in fact this particular action is
pretty snappy. There is not much that we can do to reduce time spent in methods
likeArray#<< except find ways to call them fewer times.
This example demonstrates both the power and weakness of flat profiles. Although
they are very useful to get a general idea of which functions are taking the most time,
they do not help very much with long-running or complicated programs. Rails appli-
cations certainly qualify as complicated—even a simple action can easily have hun-
dreds of lines in the profile. It can be difficult to track down where your expensive
functions are being called.
The solution to this complexity is, believe it or not, more complexity—provided we
introduce some structure to the data. We will see later in the chapter how a graph
profile, though it contains a huge amount of data, can offer better insight into where
time is being spent.
Rails Analyzer Tools
The Rails Analyzer Tools are a collection of miscellaneous parts that help with per-
formance tuning. Two of the utilities,benchandcrawl, measure “black-box” perfor-
mance by making rapid-fire HTT Prequests to a site. We can already do this, and
more, with httperf.
Column name Description
% Time Percentage of total time spent in only this function.
Cumulative Seconds Total number of seconds spent in this function, including time spent in functions called by
this one.
Self Seconds Total number of seconds spent in only this function,excluding time spent in functions called by
this one.
Calls Total number of calls to this function during the profiling period.
Self ms/call Average number of milliseconds spent in this function per call, excluding calls to other functions.
Total ms/call Average number of milliseconds spent in this function per call, including calls to other functions.
Name Name of the function being profiled.