CSC/ECE 517 Fall 2013/ch1 1w02 pp
Introduction to Profiling
Profiling in general, is an important feature in computer science. It is technique, in the most basic terms, by which one can analyze the efficiency of the program or code by measuring the programs time complexity or space complexity, and some other related performance parameters. For Example, the time complexity includes 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 up the significant steps or constructs (like loop statements, statements involving operations and functions like aggregate functions, individual blocks and modules) in the program source code for performance study.
Ruby profiling is analysis of Ruby programs. We make use of profiles that are programs, which takes ruby code as input and on execution give values for a set of parameters that define the performance of the input ruby program. There are many types of profiling method 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 the flow we give the ruby program as input to the Ruby profiling tools and that's it we will get a profiler output, which will help 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 and also to find out bottlenecks in our program.
- 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 actually cause program overhead or can slow down the system o 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, Benchmark module. Also there is ruby-prof profiler which is a gem file developed to profile ruby code. We will look how to use these tools to profile our ruby code.
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. This 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
As we can see the ruby code, we have declared a function slow_method to just perform multiplication of two values 10000 times using "times" iterator.
2. Run the deafult 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 you will run this code you will 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 represent each 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* number of times operation/method execution is performed.
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 methods it called. RubyProf generate both text and html and can output it to standard out or 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 the all the functions that were called and time it took to execute sorted in descending order, so that we can see the most time consuming method at the top.
Benchmarking
Benchmarking 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 to end of the execution of code instruction measured as 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 method is used to benchmark multiple lines of code.How do we go about it? We call the method benchmark bm that takes block as input. The block variable is a special object that has report method that 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. This method is similar to benchmark bm but it benchmarks or analyses the code twice. The objects in the initial phase are busy getting memory and interacting with garbage allocator like, a few objects might be busy with memory allocation while other objects might be interacting with garbage collector. So in the first run, it initializes all variables and forces garbage collector to run and then runs to measure the code efficiency. This phase is called rehearsal. So, with this method Ruby first comfortably settles with allocating task and then this 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 and algorithms, in that case each code can be formulated and tested using benchmark finally getting the comparisons between real running time of each method. Simply 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 function we can use 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 and builds it only when necessary. When we run profilers and figure out the methods/algorithms taking time to execute, we can rewrite that method in C. When we again run the profiler to test the performance, you will be surprised to see that the execution time will be reduced.
- 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 user, and many 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's 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
Profling Benchmark Ruby Code Becnhamrk examples Event-based profiling Profiling and optimizing Ruby code Introduction to Ruby code optimization HOWTO: INSTALLING, UPDATING AND REMOVING RUBYGEMS Ruby code optimaization Tutorial