MokaByte 90- 9mbre 2004 
Profiling di applicazioni Java
di
S.Rossini
e
G.Morello

Sin da principio, una delle promesse fondamentali del linguaggio Java era di fornire un modello di sviluppo che semplificasse la realizzazione di applicazioni complesse, riducendo i costi di sviluppo e debug. Per questa ragione, il modello proposto da SUN "nasconde" allo sviluppatore alcuni aspetti complessi quali la gestione diretta della memoria e l'accesso alle risorse. Pur con tutte le evoluzioni avute in questi anni, questo principio rimane ancora oggi valido. In realtà però il linguaggio Java rende molto semplice la scrittura di applicazioni formalmente corrette, eleganti e robuste, ma non semplifica affatto il compito di produrre codice efficiente. All'esatto contrario, la presenza di una Virtual Machine ed in generale di uno strato di virtualizzazione, spesso nasconde le implicazioni di performance legate al codice prodotto.
Per questa ragione, per Java, più ancora che per altri linguaggi, diventa critico analizzare il comportamento di quanto sviluppato a runtime.

Introduzione
Non sempre infatti le scarse prestazioni (poor performance) sono dovute alla JVM, nella maggior parte dei casi è piuttosto una cattiva programmazione (poor programming) a generare colli di bottiglia o codice poco efficiente.
In tal senso quindi le attività di Profiling devono essere viste come una parte integrante e significativa dello sviluppo di una qualunque applicazione Java.
In questo articolo si vedrà come sia possibile, mediante Profiling, osservare il comportamento a runtime di un programma Java analizzandone le performance ed il consumo di risorse critiche come CPU e memoria.

 

Profiling: Cos'è ?
Il Profiling è l'attività che permette di osservare il comportamento "fisico" di un programma in esecuzione individuando ad esempio eventuali algoritmi inefficienti, creazione eccessiva di oggetti, bloccaggio I/O, eccessiva chiamata di metodi, uso inefficiente della memoria, memory "leaks" (oggetti non più usati di cui non è stata fatta la garbage collection"), bottlenecks (colli di bottiglia). Per fare Profiling è necessario avere a disposizione strumenti appositi.

 

Strumenti di Profiling
Uno strumento di Profiling permette di analizzare e comprendere il comportamento a runtime di un programma Java (quante volte viene invocato un certo metodo di una certa classe, quanto tempo impiega la sua esecuzione, quanta CPU viene utilizzata, quanta memoria, … ) al fine di migliorare le performance ed il consumo delle risorse Hardware.
Le parti principali di un tool di Profiling sono: Hook, Agent/Handler, Viewer.
L'Hook permette di monitorare un'applicazione a runtime. Gli eventi generati dall'Hook sono inviati al Profiler runtime e la relativa elaborazione è delegata al Profiler Agent / Handler. Questi memorizzano i dati su un opportuno repository (file, DB, …) durante l'esecuzione del programma.
Le informazioni così raccolte possono essere poi analizzate mediante un opportuno tool in grado di visualizzare i dati rilevati (in forma tabellare e/o grafica) e selezionarli secondo gli opportuni criteri di scelta (strumento da non sottovalutare data l'elevata mole di dati raccolti in una tipica attività di Profiling).



Figura 1 - Schema di altro livello di un tool di Profiling


Sul mercato sono disponibili diversi prodotti di Profiling (es. JInsight, JProfile, JPRofiler, JProbe Profiler). In ambito Open source i principali Profiler disponibili sono: JRat, JMP, Eclipse Profiler, Hyades, JmemProf, NetBeans Profiler,… (per la lista dettagliata vedere [OS_PROF]).

 

Funzionamento di un tool di Profiling
Un tool di Profiling può operare in diversi modi. Una prima possibilità è costituita dall'instrumentazione del bytecode (BCI: bytecode intrumentation).
In questo caso il tool "inietta" nel bytecode dell'applicazione, alcune istruzioni che permettono di rilevare e misurare il codice in esecuzione.
Questa operazione può essere compiuta in modo statico (sui .class e/o jar d'interesse prima di eseguire il programma) o in modo dinamico (cioè "on the fly", al caricamento della classe da parte del class loader).
L'operazione di BCI mediante "wrapping" (vedere [J1BCI]) prevede di: rinominare il metodo originario, crearne una nuovo con la stessa firma aggiungendo il codice opportuno per l'instrumentazione e per l'invocazione del nuovo metodo creato.
Il funzionamento di JRat (vedere [JRAT]) è basato principalmente su un'operaziopne questo tipo.

JRat interviene sul bytecode rinominando i metodi delle classi da instrumentare e rendendoli privati e final. Quindi viene aggiunto un nuovo metodo con la stessa signature dell'originario. Tale metodo contiene la logica di instrumentazione e si occupa di invocare il metodo target (cioè quello originario, rinominato e reso private e final).
La figura che segue mostra un semplice esempio del funzionamento BCI statico di JRat.


Figura 2
- Funzionamento BCI di JRat
(clicca per ingrandire l'immagine)

Decompilando il bytecode instrumentato da JRat si nota come siano state aggiunte le istruzioni per calcolare il tempo impiegato dal metodo getSaldo() (System.currentTimeMillis()-start) e le invocazioni all'Hanlder JRat (le classi org.shiftone.jrat.core.HandlerFactory e org.shiftone.jrat.core.spi.MethodHandler).
JRat memorizza i dati rilevati in file di estensione .xrat che sono consultabili mediante il tool grafico JRat Desktop.
JRat mette inoltre a disposizione delle API per instrumentare direttamente in Java l'applicazione; questo approccio è decisamente sconsigliato in quanto prevede la modifica dei sorgenti Java ed introduce una dipendenza esplicita dallo specifico tool di Profiling. Un secondo possibile funzionamento di un Profiling tool prevede l'utilizzo della JVMPI della JVM. La JVMPI (Java Virtual Machine Profiler Interface) è un'interfaccia introdotta con il rilascio del JDK 1.2 e deprecata nel rilascio del JDK1.5.0 a favore della nuova interfaccia nativa Java Virtual Machine Tool Interface (JVMTI) (vedere [JVMPI_JVMTI]).

JVMPI di fatto fornisce un meccanismo di profiling "embedded" nella JVM stessa.
JVMPI definisce un protocollo di comunicazione tra la JVM ed un Profiler Agent, ovvero un modulo di codice preposto all'ascolto di "eventi" generati dalla stessa JVM. Il Profiler Agent si presenta come una DLL (Dynamic Link Library) che viene caricata dal processo java. Il suo compito è quello di ricevere gli eventi dalla JVM, raccogliere le statistiche opportune e fornirle ad un processo esterno, il monitor vero e proprio.

 


Figura 3
- Schema di altro livello di un tool di Profiling che usa JVMPI

In questo caso il Profiler tool usa l'interfaccia nativa per comunicare con la JVM e per ottenere le informazioni dell'applicazione Java in esecuzione.

La libreria nativa del tool viene caricata ed inizializzata mediante l'aggiunta di una direttiva di preprocessing -X da linea di comando (ad esempio, nel caso di JMP [JMP] è -Xrunjmp). Mentre l'applicazione è in esecuzione, la libreria nativa del Profiler riceve i vari tipi di eventi occupandosi di popolare il proprio repository.
Eclipse Profiler (vedere [ECL_PROF_PLG]) si interfaccia con la JVM mediante le API JVMPI. Il Profiler Agent si dichiara "interessato" (listener) all'evento JVMPI_EVENT_CLASS_LOAD_HOOK (vedere [JVMPI]) che è invocato dalla JVM ad ogni caricamento di una classe da parte del class loader.
Il Profiler, al caricamento della classe, effettua un BCI di tipo dinamico inserendo una notifica sia all'ingresso del metodo che alla sua uscita e calcolandone la relativa durata.

Il collezionamento dei dati può avvenire sia mediante instrumentazione diretta del bytecode (statica o dinamica), sia mediante campionamento (sampling).
Con il campionamento, un timer sospende periodicamente (tipicamente ogni 10 ms) tutti gli altri Thread attivi. In quell'istante viene "fotografata" la situazione dello stack di ogni Thread ricavandosi i tempi e le risorse hardware utilizzate (vedere [JPFAQ]).

Come si è visto, lo strumento di Profiling modifica l'ambiente di runtime aggiungendo le operazioni che permettono il monitoring dell'applicazione. Questa"perturbazione", ovviamente, genera in fase di esecuzione un rallentamento ed è quindi opportuno effettuare il profiling in modo mirato e oculato. Per questa ragione, i tool di Profiling permettono di indicare in modo selettivo le classi da monitorare.
Generalmente tale selezione avviene mediante interfaccia grafica, da file di configurazione o da riga di comando (-X) in fase di avvio della JVM.



Figura 4 - Selezione delle classi da monitorare da Eclipse Profiler

Un esempio pratico
Vediamo ora ad un esempio pratico. Riprendiamo in esame il semplice esempio presentato in [MOKA_TDD], e modifichiamo il codice originario rendendo persistente il saldo su DB.

public class Account {
private float saldo = 0;
private String accountId;
private AccountDao dao=null;

public Account(String id)throws Exception{
this.accountId = id;
this.dao=new AccountDao();
}

public void versamento(float somma) throws Exception{
if (somma <= 0){
throw new Exception("Somma rifiutata: " + somma);
}
this.saldo=this.dao.readSaldo(this.accountId);
this.saldo = this.saldo + somma;
this.saldo.saveSaldo(this.accountId, this.saldo);
}
. . . . .
}

Abbiamo quindi la seguente situazione:



Figura 5 - L'esempio proposto

Invocando il metodo versamento si ha la più classica segnalazione "utente": il metodo versamento è … "lento"!
Perché? A causa di chi? Cerchiamo di capirlo profilando la nostra applicazione.
Utilizzando JRat (vedere [JRAT]) è sufficiente instrumentare le classi d'interesse, configurare l'opportuno handler (nel file di configurazione) e lanciare l'applicazione. Come detto, i dati di profiling saranno memorizzati in file di estensione .xrat e saranno consultabili mediante il tool grafico JRat Desktop.


Figura 6 - Le operazioni di BCI con JRat


Per avviare il JRat Desktop basta eseguire il seguente comando:

%JAVA_HOME%/bin/java -jar shiftone-jrat.jar

Dalla voce di menu INSTRUMENT, è possibile selezionare i .class o i jar che si vuole instrumentare (questa operazione è possibile anche da linea di comando o mediante ANT)


Figura 7 - BCI con il JRat Desktop

A questo punto è sufficiente rieseguire l'applicazione inserendo nel classpath il jar di JRat (è necessario visto che il bytecode una volta instrumentato fa riferimento alle classi Handler di JRat), indicando il file di configurazione mediante le proprietà di sistema jrat.configuration.

java -cp classes;shiftone-jrat.jar -Djrat.configuration=myjrat.xml it.mokabyte.samples.AccountMain

Nell'esempio proposto il file di configurazione (myjrat.xml) indica l'handler da utilizzare (TreeMethodHandlerFactory) e le relative classi da monitorare.

<jrat>
<handler>
<include className="it.mokabyte.samples.*" methodName="*"/>
<factory
class="org.shiftone.jrat.provider.tree.TreeMethodHandlerFactory"/>
</handler>
</jrat>

Dalla voce di menu FILE del JRat Desktop, è possibile aprire il file di report per visionare ed analizzare i dati dell'avvenuto profiling.


Figura 8
- Report di Profiling JRat

Il report riporta le informazioni quali: nome del package, classe e metodo invocato, numero di esecuzioni, tempo complessivo, tempo medio di esecuzione del nodo rispetto al nodo parent e tempo percentuale rispetto all'esecuzione del nodo root.
In modo grafico è possibile scorrere l'albero delle chiamate e vedere i nodi piu' critici in termini di tempo di esecuzione (segnati in rosso).
Nell'esempio si vede che è il metodo AccountDao.readSaldo() la causa del ritardo (dura per il 98,8 % del tempo di esecuzione del metodo Account.versamento()).
Come si è visto, JRat è semplice da utilizzare e permette di individuare in modo intuitivo e semplice eventuali colli di bottiglia da indagare. JRat non riporta metriche per quanto riguarda il consumo delle risorse come CPU e memoria.
Questo è possibile con i Profiler che interagiscono con la JVM mediante le API JVMPI come Eclipse Profiler o JMPI.

Con Eclipse Profiler (vedere [ECL_PROF_PLG]), abbiamo la possibilità di effettuare Java profiling in modo integrato nell'IDE di Eclipse.
Una volta installato, il plugin fornisce una propria vista con la quale è possibile configurare e mandare in esecuzione il Profiler.
Oltre a rilevare i tempi di esecuzione a livello di package, classe e metodo, attraverso il grafico delle chiamate (i punti "critici" sono segnati in rosso), è possibile analizzare il grafico d'utilizzo della memoria (totale-verde, usata-blu, libera-giallo).


Figura 9
- I report di Eclipse Profiler

Con Hyades (vedere [Hyades]) è possibile inoltre visualizzare il sequence diagram delle operazioni e la relativa frequenza di chiamate.


Figura 10 -
La vista Execution Flow d Hyades

L'attività di profiling svolta individua il metodo AccountDao.readSaldo() come il responsabile della poca efficienza del metodo Account.versamento(). Individuato il collo di bottiglia, è necessario capire come e se sia possibile rimuverlo.

Innanzitutto è necessario cercare di capire se il tutto è lento a causa di problemi tecnologici (driver JDBC, accesso a DB, …) o applicativi (codice Java inefficiente , SQL non ottimizzato, …).

Andiamo a vedere il codice Java del metodo readSaldo():

Class.forName(<<DRIVER_NAME>>);
con=DriverManager.getConnection(<<JDBC_URL>>,<<DB_USERID>>,<<DB_PWD>>);
stmt = con.createStatement();
rs=stmt.executeQuery("SELECT * FROM moka_account");
while(rs.next()){
String s1=rs.getString(1);
String s2 = new String();
s2=s1;
if(accountId.equals(s2)){
found=true;
String s3=rs.getString(4);
saldo=Float.parseFloat(s3);
}
}
if(!found){
throw new AccountException("AccountDao.readSaldo: Account NOT found!");
}
return saldo;

E' facile vedere come il codice sia altamente inefficiente.

Modifichiamolo inserendo l'utilizzo di un PreparedStatement piuttosto che uno Statement, utilizziamo la clausola WHERE nella SELECT, riusiamo la connessione già aperta in fase di costruzione della classe (proprietà connection) ed eliminiamo la stringa s2 di nessuna utilità.
La versione ragionevole del metodo diventa quindi:

pstmt = this.connection.prepareStatement(
"SELECT balance FROM moka_account WHERE id=?");
pstmt.setString(1, accountId);
rs=pstmt.executeQuery();
if(rs.next()){
saldo=rs.getFloat(1);
return saldo;
}
else{
throw new AccountException("AccountDao.readSaldo: Account NOT found!");
}

Rieseguendo il profiling dell'applicazione modificata si può facilmente vedere quali benefici sono stati ottenuti dalla "razionalizzazione" del codice.


Figura 11 - Report di Profiling dopo la modifica del codice

Si può notare come sia evidente il miglioramento non soltanto a livello di tempi e di consumo di memoria, con l'Execution flow di Hyades è infatti possibile notare la scomparsa di attività onerose e superflue anche a "occhio nudo" (creazione della connessione e processo di tutte le ennuple della tabella moka_account senza utilizzo della condizione WHERE).


Figura 12 -
Execution view: prima e dopo l'intervento applicativo

Conclusioni
Per sua natura, il linguaggio Java consente allo sviluppatore di scrivere applicazioni senza porre le dovute attenzioni al consumo di risorse ed alle performance che questa avrà a runtime.
Per questa ragione, come si è detto, è bene pensare al Profiling non solo a posteriori rispetto allo sviluppo, ma come ad una pratica sistematicamente integrata nel processo di sviluppo.
In questo articolo abbiamo presentato alcuni aspetti generici ed un semplice esempio di Profiling attraverso l'uso di strumenti Open Source.

 

Bibliografia
[MOKA_TDD] S. Rossini, Pratiche di sviluppo del software I parte: Test Driven Development, MokaByte 86 - Giugno 2004
[OS_PROF] Open Source Profilers for Java : http://www.manageability.org/blog/stuff/open-source-profilers-for-java
[J1BCI] JavaOne 2004: Bytecode Instrumentation - Makingit simple - http://www.hp.com/products1/unix/java/pdfs/bytecode.pdf
[JPFAQ] Java Profiler FAQ - JProfiler - http://www.ej-technologies.com/products/jprofiler/java-profiler-faq.html#faq1
[JRAT] http://jrat.sourceforge.net
[JMP] - Memory Profiler- http://www.khelekore.org/jmp/
[ECL_PROF_PLG] http://eclipsecolorer.sourceforge.net/index_profiler.html
[HYADES] http://www.eclipse.org/hyades/
[JVMPI_JVMTI] Kelly O'Hair: The JVMPI Transition to JVMTI - http://java.sun.com/developer/technicalArticles/Programming/jvmpitransition/
[JVMPI] Java Virtual Machine Profiler Interface
http://java.sun.com/j2se/1.5.0/docs/guide/jvmpi/jvmpi.html
[JVMTI] Java Virtual Machine Tool Interface
http://java.sun.com/j2se/1.5.0/docs/guide/jvmti/jvmti.html
[HOTSPOT] White Paper-The Java HotSpot Virtual Machine, v1.4.1:
http://java.sun.com/products/hotspot/docs/whitepaper/Java_Hotspot_v1.4.1/Java_HSpot_WP_v1.4.1_1002_1.html

 

MokaByte® è un marchio registrato da MokaByte s.r.l. 
Java®, Jini® e tutti i nomi derivati sono marchi registrati da Sun Microsystems.
Tutti i diritti riservati. E' vietata la riproduzione anche parziale.
Per comunicazioni inviare una mail a info@mokabyte.it