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 name='w'>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.

Ruby Profiling Tools

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 <ref>Profiling and optimizing Ruby code using profile.rb(default profiler)</ref>

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 <ref name='in'>HOWTO: INSTALLING, UPDATING AND REMOVING RUBYGEMS</ref>

 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<ref>Benchmark Ruby Code</ref> 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 <ref name='be'>Benchmark examples</ref> 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 <ref name='be'>Benchmark examples</ref> 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 <ref name='be'>Benchmark examples</ref> 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 collector. 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 <ref>Ruby Inline</ref> 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 test cases 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 unexpected results. Ruby code optimization Tutorial

Realted Topics

Profiling Ruby on Rails using New Relic
Ruby on Rails profiling tools

References

<references/>