CSC/ECE 517 Fall 2013/ch1 1w02 pp
Introduction to Profiling
Profiling in general, is an important feature in computer science. It is a technique, in the most basic terms, by which one can analyze the efficiency of the program or code by measuring the program’s time complexity or space complexity and some other performance related parameters. For example, total running time, CPU time, memory used, time taken by each module or function, function calls, response time and many similar important aspects of our program/application. Profiling takes into consideration significant steps or program constructs (like loop statements, individual blocks and modules, statements involving operations and functions like aggregate functions) for performance study. <ref>Profling</ref>
Ruby profiling is analysis of Ruby programs. We make use of profiles that are programs, which takes ruby code as input and on execution gives values for a set of parameters that define the performance of the input ruby program. There are many types of profiling methods like event-based and statistical methods. Ruby mostly uses event-based profilers. Here in case of Ruby profiler, we get the analysis results in various formats like table, graphs etc.
As we can see in the flow diagram, we give the ruby program as input to the Ruby profiling tools and we get a profiler output, which helps us in optimizing out code.
Significance of Profiling
The main purpose of profiling is:
- To analyze the performance of the code, their CPU utilization, memory operations.
- Based on the results presented by the profiler, one can improve upon the code with better constructs and functions and hence we can easily optimize the code in accord with the system requirements.
- We can accurately measure how a program functions or performs in one given environment and with different input data.
- To identify the bottlenecks in a program, the portions that cause program overhead or can slow down the system or need special testing or can raise exception.
Ruby Profiling tools
There are many Profiling tools available for analyzing the ruby programs. Ruby itself has inbuilt profilers in the form of modules. Two such modules are Default profiler and Benchmark module. Also, there is ruby-prof profiler which is a gem file developed to profile ruby code. Below is a description of how one can use these tools to profile ruby codes.
Default Profiler
This is an inbuilt module that can be run by using the command –r profile which in turn imports the profile.rb source file. The profile.rb source file has the program that measures the performance of the system by recording the function calls. Here, the input is a collection of all the function calls made in the code. Specifically, profile.rb uses the method ‘kernel#set_trace_func’ to keep a track of all function calls.
How to use profile.rb to profile our code:
1) Create a ruby file profiler_example.rb
#profile_example.rb code begins
require 'profile'
def slow_method
10000.times do 9999999999999999*999999999
end
end
slow_method
#profile_example.rb code ends
Here, we have declared a function slow_method to simply perform multiplication of two values 10000 times using "times" iterator.
2. Run the default profiler on profiler_example.rb using command
ruby-rprofile profiler_example.rb
3. Output of profiler
% cumulative self self total time seconds seconds calls ms/call ms/call name 65.96 0.06 0.06 1 62.00 94.00 Integer#times 34.04 0.09 0.03 10000 0.00 0.00 Bignum#* 0.00 0.09 0.00 1 0.00 0.00 Array#each 0.00 0.09 0.00 1 0.00 94.00 Object#slow_method 0.00 0.09 0.00 1 0.00 94.00 #toplevel
Note: This output is truncated to show basic functions in ruby. When we run this code, we see a lot of other functions.
Basically, this is considered as an inefficient profiling tool as this increases the execution time of program considerably and the situation worsens if the code size is huge. So we can use this to profile small pieces of code.
But on the other hand, it’s a handy tool as it comes with the ruby library and with the –r command line, it becomes even more convenient, so this tool can certainly be used with the small length codes. Also, this profiler provides great uniformity to the code. We can be sure of the accuracy of the result as while it measures the execution time of each function call and method, it slows down everything to the same level.
Now the output of analysis is displayed in the form of table. Each row represents one method of the program. And the rows are in the sorted order of one of the parameters. It does take into account the time a method takes to run and computes the total as time taken by operation multiplied by number of times operations(or methods) is executed.
Ruby-prof Profiler
ruby-prof is a fast code profiler for Ruby. It is a C extension and therefore is many times faster than the standard Ruby profiler. It supports both flat and graph profiles. For each method, graph profiles show how long the method ran, which methods called it and which all methods were called by it. RubyProf generates both text and html and can output it to a file.
To demonstrate use of ruby-prof profiler we will use flat profile, Steps to be followed :
1. Install ruby-prof gem
gem install ruby-prof
2. Create a ruby code file to profile
#Start of ruby code file to profile
require 'ruby-prof'
RubyProf.start
#code to profile start
def slow_method
for num in 1..10_000 do
is_prime = 1
for x in 2..(num - 1) do
if (num % x == 0)
is_prime = x
break
end
end
if is_prime == 1
puts "#{num} is a prime number"
else
puts "#{num} equals #{is_prime} * #{num/is_prime}"
end
end
end
slow_method
#code to profile end
result = RubyProf.stop
printer = RubyProf::FlatPrinter.new(result)
printer.print(STDOUT)
#End of ruby code file to profile
3. Output of ruby-prof profiler
Thread ID: 17223036 Fiber ID: 20361900 Total: 1.873907 Sort by: self_time
%self total self wait child calls name 2.70 0.051 0.051 0.000 0.000 20000 IO#write 1.59 1.874 0.030 0.000 1.844 10001 *Range#each 0.47 0.009 0.009 0.000 0.000 27540 Fixnum#to_s 0.39 0.058 0.007 0.000 0.051 10000 IO#puts 0.21 0.004 0.004 0.000 0.000 10000 <Class::Range>#allocate 0.20 0.062 0.004 0.000 0.058 10000 Kernel#puts 0.00 1.874 0.000 0.000 1.874 1 Global#[No method] 0.00 1.874 0.000 0.000 1.874 1 Object#slow_method 0.00 0.000 0.000 0.000 0.000 1 Module#method_added
The above code displays all the functions that were called and their execution time sorted in descending order of time taken by them. So, we find the method that consumes a lot of time at the top.
Benchmarking
Benchmarking<rel>Benchmark Ruby Code</rel> can be taken as a profiling tool as it provides measurement results after executing the program in question. Based on the analysis results, one can optimize the code accordingly. All we need to do to use this module is to include benchmark, the step goes as, “require ‘benchmark’. The output from benchmark analysis consists of four main parameters shown from left to right-
User system total real
User CPU Time - Time taken to process user code instructions.
System CPU time - Time taken to execute kernel code instructions.
Total - User + system CPU time.
Total Real time - Time from the start of code execution to the end of code execution measured by clock time.
In order to measure a part of the code, we can use many methods given in Benchmark. Below are the methods that are used to benchmark code.
Illustrating these methods with an example
Benchmark.measure method
Benchmark.measure is used to measure a part of the code, we can use many methods given in Benchmark. Here only one line at a time can be benchmarked.
#Code
require 'benchmark'
puts Benchmark.measure { 602214.times { 3.14159 * 6.626068 } }
#Output 0.062000 0.000000 0.062000 ( 0.056038)
Benchmark.bm method
Benchmark.bm<rel>Benchmark Ruby Code</rel> method is used to benchmark multiple lines of code. We call the method benchmark bm that takes block as input. The block variable is a special object that has report method, which in turn gives the execution time of the block executed.
#Code
Benchmark.bm do |x|
x.report("for:") { for i in 1..n; a = "1"; end }
x.report("times:") { n.times do ; a = "1"; end }
x.report("upto:") { 1.upto(n) do ; a = "1"; end }
end
#Output
user system total real
for: 3.167000 0.000000 3.167000 ( 3.312189)
times: 3.198000 0.000000 3.198000 ( 3.242186)
upto: 3.884000 0.000000 3.884000 ( 3.934225)
Benchmark.bmbm method
Benchmark.bmbm<rel>Benchmark Ruby Code</rel> This method is similar to benchmark bm but it benchmarks or analyses the code twice. The objects in the initial phase are busy with memory allocation or interacting with garbage allocator. So, in the first run, it initializes all variables and forces garbage collector to run and in second run, it measures the code efficiency. The 1st phase is called rehearsal. So with this method, Ruby first comfortably settles down with allocation task and then measures CPU time and other important parameters.
#Code
array = (1..1000000).map { rand }
Benchmark.bmbm do |x|
x.report("sort!") { array.dup.sort! }
x.report("sort") { array.dup.sort }
end
#Output Rehearsal ----------------------------------------- sort! 6.069000 0.015000 6.084000 ( 6.382365) sort 4.617000 0.000000 4.617000 ( 4.724270) ------------------------------- total: 10.701000sec user system total real sort! 3.323000 0.000000 3.323000 ( 3.590205) sort 3.135000 0.000000 3.135000 ( 3.267187)
Benchmarking can be used in places where we have several algorithms for a single problem and we want to test the algorithm in different environment. In this case, each code can be formulated and tested using benchmark. Finally, we get comparisons with respect to real running time. We just need to include benchmarking script that compares various approaches for performance.
==Optimizing Ruby Code Now we have seen how to analyze a code using ruby profiling tools. Now we will see the techniques we can use to optimize our code. Using benchmarking we can compare different algorithms and then use the most efficient algorithm. As we saw in the example of benchmarking, we compared for, upto and times and based on the results of comparison, we narrowed down on the method which has the least execution time. We can also use Ruby-Inline which reduces the execution time of program by a huge factor.
Ruby Inline allows you to write C/Java within your ruby code. It automatically determines if the code in question has changed or not and builds it only when necessary. When we run profilers, we get the time taken by methods/algorithms to execute. Based on it, we can rewrite the methods in C. When we again run the profiler to test the performance, we get surprising results because the execution time reduces.
- Example - how our code will look
class MyTest
def factorial(n)
f = 1
n.downto(2) { |x| f *= x }
f
end
inline :C do |builder|
builder.c "
long factorial_c(int max) {
int i=max, result=1;
while (i >= 2) { result *= i--; }
return result;
}"
end
end
To install RubyInline go to Install Ruby-Inline.
Also you can go through the Ruby-Inline Tutorial.
Conclusion
For large scale applications, where there are thousands of users and transactions, try using Ruby optimizing techniques to optimize the ruby code and improve the performance. Optimization is a special form of refactoring. As such, it is important that you have a good set of unit and functional tests in place before you start optimizing your code. You might want your code to be faster, but you certainly don't want it to produce different results.
Realted Topics
Profiling Ruby on Rails using New Relic
Ruby on Rails profiling tools
References
<references/>