Nessun risultato. Prova con un altro termine.
Guide
Notizie
Software
Tutorial

Il profiling delle applicazioni Ruby

Riconoscere le porzioni di codice che mettono sotto sforzo il calcolatore
Riconoscere le porzioni di codice che mettono sotto sforzo il calcolatore
Link copiato negli appunti

A volte, soprattutto in quando si sviluppano applicazioni Web molto complesse, capita che le prestazioni non siano eccellenti e occorre quindi rivederne alcune parti. L'ottimizzazione però porta a buoni risultati solo se si sa con precisione quali parti del programma ne rallentano eccessivamente l'esecuzione. Ruby mette a disposizione diversi strumenti per valutare le prestazioni e per capire quali elementi del programma consumano più risorse.

Ruby-prof

Il migliore strumento attualmente disponibile per effettuare il profiling di codice Ruby è ruby-prof installabile sia attraverso RubyGems sia a partire dai sorgenti. ruby-prof permette di valutare diversi parametri come il tempo di esecuzione delle varie chiamate e il consumo di memoria; possiede inoltre un avanzato sistema di reporting.

È possibile eseguire il profiling con ruby-prof in tre modi. Il metodo meno invasivo consiste nell'eseguire il codice da esaminare con l'utility ruby-prof installata con la libreria:

$ ruby-prof test.rb
...output del programma...
Thread ID: 3083638540
Total: 0.160000

 %self     total     self     wait    child    calls  name
 31.25      0.05     0.05     0.00     0.00    20000  IO#write
 25.00      0.16     0.04     0.00     0.12        1  Integer#times
 25.00      0.04     0.04     0.00     0.00    10000  Fixnum#to_s
 18.75      0.12     0.03     0.00     0.09    10000  Kernel#puts
  0.00      0.16     0.00     0.00     0.16        0  Global#[No method]
  0.00      0.16     0.00     0.00     0.16        1  Kernel#load

Dove test.rb è semplicemente un ciclo del genere:

10_000.times do |i|
   puts i
end

L'output è banale: vengono mostrate le informazioni sui tempi, le percentuali di utilizzo e il numero di chiamate ai vari metodi.

Le opzioni da linea di comando permettono tra l'altro di scegliere il formato del report, il metodo di misurazione e i metodi da mostrare nel report.

In alternativa è possibile utilizzare ruby-prof come libreria:

require 'rubygems'
require 'ruby-prof'

RubyProf.start

10_000.times do |i|
   puts i
end

res = RubyProf.stop

output = RubyProf::FlatPrinter.new(res)
output.print

In questo caso il codice analizzato è quello compreso tra i metodi start e stop di RubyProf. I risultati sono gli stessi di prima. Più concisamente è possibile utilizzare un blocco associato al metodo profile:

res = RubyProf.profile do
  10_000.times do |i|
    puts i
  end
end

Infine c'è la soluzione veloce. Aggiungendo

require 'unprof'

ad un programma si otterrà in output il report dell'intera applicazione. unprof non fa altro che definire il blocco del metodo Kernel#at_exit, che viene chiamato all'uscita dal programma, in questo modo:

require "ruby-prof"

at_exit {
  result = RubyProf.stop
  printer = RubyProf::FlatPrinter.new(result)
  printer.print(STDOUT)
}
RubyProf.start

Così però non è possibile scegliere nessuna impostazione del profiler. Detto questo andiamo a vedere in dettaglio i formati del report e i tipi di misurazione.

Report

I tipi di report a disposizione sono quattro. Nella modalità Flat, vista negli esempi precedenti, viene mostrata per ogni metodo la percentuale di utilizzo, i vari tempi impiegati nell'esecuzione e il numero di chiamate.

Il secondo tipo di report è Graph che, oltre alle informazioni mostrate da Flat, ci dice anche per ogni metodo i nomi dei metodi che chiama e i nomi dei metodi che lo chiamano. Ad esempio tornando al codice visto prima abbiamo:

 %total  %self   total   self   wait  child         calls  Name
-----------------------------------------------------------------------------
100.00%  0.00%    0.19   0.00   0.00   0.19             0  Global#[No method]
                  0.19   0.01   0.00   0.18           1/1  Integer#times
-----------------------------------------------------------------------------
                  0.19   0.01   0.00   0.18           1/1  Global#[No method]
100.00%  5.26%    0.19   0.01   0.00   0.18             1  Integer#times
                  0.18   0.04   0.00   0.14   10000/10000  Kernel#puts
-----------------------------------------------------------------------------
                  0.18   0.04   0.00   0.14   10000/10000  Integer#times
 94.74%  1.05%    0.18   0.04   0.00   0.14         10000  Kernel#puts
                  0.04   0.04   0.00   0.00   10000/10000  Fixnum#to_s
                  0.10   0.10   0.00   0.00   20000/20000  IO#write
-----------------------------------------------------------------------------
                  0.10   0.10   0.00   0.00   20000/20000  Kernel#puts
 52.63%  2.63%    0.10   0.10   0.00   0.00         20000  IO#write
-----------------------------------------------------------------------------
                  0.04   0.04   0.00   0.00   10000/10000  Kernel#puts
 21.05%  1.05%    0.04   0.04   0.00   0.00         10000  Fixnum#to_s

In ogni sezione del report sono riportati il nome e i dati del metodo analizzato contraddistinti dai valori %total e %self mentre nelle righe superiori sono elencati i metodi che lo chiamano e in quelle inferiori i metodi chiamati. Ad esempio considerando la terza sezione del nostro report si deduce che il metodo analizzato è Kernel#puts che è chiamato da Integer#times e che chiama a sua volta Fixnum#to_s e IO#write.

Per ottenere questo report occorre utilizzare la classe RubyProf::GraphPrinter e poi chiamare il metodo print come visto nell'esempio.

C'è poi la modalità HTML Graph (classe RubyProf::GraphHtmlPrinter) che fornisce i dati nello stesso formato ma sotto forma di codice HTML.

Figura 1. Esempio di report HTML
Esempio di report HTML

C'è infine la modalità Call (classe RubyProf::CallTreePrinter) che mostra l'output nel formato CallTree di KCachegrind. Ad esempio:

Esempio di report in formato CallTree

events: process_time

fl=/home/gls/ruby_runtime
fn=Kernel::puts
0 40000
cfl=/home/gls/ruby_runtime
cfn=IO::write
calls=20000 13
13 40000
cfl=/home/gls/ruby_runtime
cfn=Fixnum::to_s
calls=10000 13
13 30000

fl=/home/gls/ruby_runtime
fn=Integer::times
0 80000
cfl=/home/gls/ruby_runtime
cfn=Kernel::puts
calls=10000 13
13 110000

fl=/home/gls/ruby_runtime
fn=Fixnum::to_s
0 30000

fl=/home/gls/test_prof.rb
fn=Global::[No method]
12 0
cfl=/home/gls/ruby_runtime
cfn=Integer::times
calls=1 12
12 190000

fl=/home/gls/ruby_runtime
fn=IO::write
0 40000

Anche in questo caso ogni metodo ha una propria sezione e le proprie informazioni che comprendono anche il nome delle funzioni chiamate dal metodo analizzato. Per maggiori informazioni rimando al sito di KCachegrind.

Da linea di comando i tipi di report vanno impostati attraverso l'opzione --printer che accetta i valori flat, graph, graph_html e call_tree.

Misurazioni

ruby-prof permette di effettuare diversi tipi di misurazione, alcuni disponibili solo per alcune piattaforme. Attualmente le misure disponibili sono:

  • process time: misura il tempo utilizzato dal processo ed è l'impostazione di default
  • wall time: misura il tempo reale di esecuzione, tale valore può risentire degli altri processi in esecuzione sul sistema
  • cpu time: misurazione che utilizza i cicli CPU come unità di misura ed è disponibile solo per processori Pentium e PowerPC
  • object allocations: misura il numero di oggetti allocati da ogni metodo
  • memory usage: misura per ogni metodo l'utilizzo della memoria

Queste ultime due misurazioni richiedono l'utilizzo di un interprete Ruby opportunamente modificato. Tutte le informazioni a riguardo sono nella documentazione di ruby-prof.

Per scegliere tra i vari metodi di misurazione va opportunamente impostato RubyProf.measure_mode che accetta i valori RubyProf::PROCESS_TIME, RubyProf::WALL_TIME, RubyProf::CPU_TIME, RubyProf::ALLOCATIONS e RubyProf::MEMORY. In alternativa è possibile impostare la variabile d'ambiente RUBY_PROF_MEASURE_MODE ad uno dei seguenti valori: process, wall, cpu e allocations.

Da linea di comando invece le modalità di esecuzione vanno impostate attraverso l'opzione --mode che accetta gli stessi valori di RUBY_PROF_MEASURE_MODE.

Ruby Profiler

Oltre alla gemma ruby-prof è possibile utilizzare il profiler distribuito direttamente con Ruby. La differenza tra i due sta nelle prestazioni (ruby-prof è scritto in C ed è notevolmente più veloce) e nelle opzioni disponibili. Per utilizzare il profiler standard basta inserire semplicemente

require 'profile'

nel programma ottenendo in questo modo l'analisi dell'intero sorgente. In pratica il comportamento è simile a quello visto per unprof, in questo caso includendo profile viene definito un blocco END da eseguire all'uscita:

require 'profiler'

END {
  Profiler__::print_profile(STDERR)
}
Profiler__::start_profile

dove profiler è la libreria che implementa il profiler standard di Ruby. Con lo stesso esempio visto prima si ottiene un output simile a quello di ruby-prof:

    % cumulative     self             self    total
 time    seconds  seconds   calls  ms/call  ms/call  name
51.52       0.85     0.85   10000     0.08     0.14  Kernel.puts
23.03       1.23     0.38   20000     0.02     0.02  IO#write
16.36       1.50     0.27       1   270.00  1650.00  Integer#times
 9.09       1.65     0.15   10000     0.02     0.02  Fixnum#to_s
 0.00       1.65     0.00       1     0.00  1650.00  #toplevel

Per avere un maggior controllo delle operazioni occorre includere direttamente 'profiler' ed utilizzare i metodi start_profile, stop_profile e print_profile del modulo Profiler__. In alternativa è possibile chiamare il profiler direttamente da linea di comando utilizzando l'opzione "-r profile" dell'interprete Ruby.


Ti consigliamo anche