XDebug: profiling delle applicazioni

Eccoci rapidamente giunti all'ultimo articolo che parla in modo dettagliato di XDebug. Dopo aver introdotto e descritto in modo generico la libreria ed analizzato come utilizzarla in pratica insieme ad Eclipse, in questo articolo ci addentreremo nell'analisi di una funzionalità molto importante: il profiling.

Il profiling di un'applicazione permette di ottenere una lista di informazioni riguardo le performance relative all'esecuzione del codice; queste informazioni variano in base ad alcune opzioni, ma generalmente comprendono i tempi di esecuzione delle funzioni e dei metodi, il numero di volte in cui una funzione o un metodo viene chiamato e tutte le altre statistiche derivate (come ad esempio il tempo di esecuzione cumulativo e quello medio).

Grazie ai dati ottenuti da un'accurata operazione di profiling, possiamo conoscere quali sono i colli di bottiglia all'interno del nostro codice per procedere eventualmente con l'ottimizzazione ove possibile e necessario.

Generazione ed analisi di un profile log

XDebug effettua il profiling del codice generando un file testuale di log. Questo profile log, nonostante non sia di formato binario, non è facilmente interpretabile e spesso risulta importante utilizzare degli appositi tool in grado di analizzare il log e fornirci tutte le informazioni del caso.

Prima di vedere comunque quali e come utilizzare queste applicazioni grafiche, è importante conoscere come generare il file di log e come effettuare una semplice analisi manuale.

Per prima cosa è necessario abilitare il profile impostando l'opzione profiler_enable ad On:

xdebug.profiler_enable = On

Di default il profiler è disabilitato poiché la raccolta di tutti questi dati influisce parecchio (in modo negativo) sulle performance, dato che ogni singola chiamata viene tracciata, anche se nativa.

Dopo aver impostato questa opzione possiamo eseguire il nostro codice ed ottenere il primo profile log; di default il profile log viene salvato nella cartella temporanea di sistema, ma possiamo variare questa impostazione modificando l'opzione di configurazione profiler_output_dir:

xdebug.profiler_output_dir = "/path/to/my/dir"

Il file di log è chiamato cachegrind.out e viene generato viene ogni volta sovrascritto; è possibile istruire comunque XDebug in modo che non sovrascriva il file ma aggiunga alla fine del file il nuovo contenuto impostando l'opzione di configurazione profiler_append:

xdebug.profiler_append = On

Volendo è anche possibile istruire XDebug in modo che esegua il profiling solo di determinati script; effettuare il profiling di ogni pagina potrebbe generare file di log molto ampi e difficilmente comprensibili, soprattutto se si ha a che fare con molte funzionalità superflue che non si vorrebbe analizzare. Impostando correttamente l'opzione di configurazione profiler_enable_trigger, possiamo configurare XDebug in modo che effettui il profile degli script solamente nel caso in cui GET o POST contengano la variabile XDEBUG_PROFILE:

xdebug.profiler_enable_trigger = On

Infine un'ultima opzione interessante è quella che permette di impostare manualmente il modo del file di log. In questo modo possiamo catalogare come preferiamo i log per analizzarli successivamente. Nel nome possiamo utilizzare delle variabili speciali che verranno automaticamente convertite da XDebug quando genererà il nome del file.

Alcune di queste variabili, le più importanti, sono elencate di seguito:

• %p: l'ID del processo che sta eseguendo PHP;
• %r: un numero casuale intero;
• %u: il timestamp in microsecondi;
• %H: il valore della variabile superglobale $_SERVER[ 'HTTP_HOST' ];
• %R: il valore della variabile superglobale $_SERVER[ 'REQUEST_URI' ];

Il nome del file di log può essere quindi modificato impostando correttamente il valore dell'opzione di configurazione profiler_output_name:

xdebug.profiler_output_name = "%u_%p.profile.log"

Una volta ottenute tutte le informazioni necessarie possiamo procedere con l'analisi dei dati. Analizzare correttamente i dati è fondamentale per poter procedere con l'ottimizzazione dei sorgenti. Spesso ci si ritrova ad ottimizzare parti di codice che vengono chiamate pochissimo, oppure che non rappresentano dei reali colli di bottiglia. I punti da ottimizzare con attenzione invece sono quelli in cui il codice viene richiamato parecchie volte ed anche pochissimi millisecondi di differenza possono portare a vistosi miglioramenti di performance.

Senza entrare troppo nei dettagli sull'ottimizzazione (di cui avevo già parlato tempo fa e su cui si potrebbero scrivere interi libri), è bene ricordare una serie di punti fondamentali:

• In primo luogo i colli di bottiglia più comuni si hanno nel caso di eccessive operazioni di input/output. È sempre una buona cosa limitare queste operazioni, utilizzare delle cache se possibile oppure accorpare tutte le operazioni di lettura/scrittura in un numero di chiamate contenuto (ad esempio evitiamo se possibile di chiamare decine di volte echo quando la concatenazione di una stringa o l'utilizzo delle funzioni di output buffering possono portare a miglioramenti visibilmente importanti).
• Il primo passo per l'ottimizzazione è avere dell'hardware adeguato. In molti casi non è possibile ottenere risultati degni di nota se non si utilizza dell'hardware specifico, magari affiancato da soluzioni di supporto quali Memcached.
• Utilizzate il più possibile le operazioni di caching dell'output in modo da non dover generare ogni volta i contenuti da zero anche nel caso in cui questi non siano cambiati dall'ultimo accesso.
• Se possibile installate dei software di caching del bytecode PHP: PHP è un linguaggio interpretato, e come tutti i linguaggi interpretati parecchio tempo viene impiegato per trasformare il codice sorgente in codice intermedio che viene eseguito dalla virtual machine sottostante;

Il resto sta a voi e spesso le ottimizzazioni più importanti sono strettamente legate all'architettura dell'applicazione. Fortunatamente il profiler è in grado di far notare con evidenza quali sono i punti della nostra applicazione che sono più lenti!

Visualizzare un profile log graficamente

Il file di log, come comprensibile dal nome di default che gli viene impostato, è formattato in modo da essere compatibile con il formato Cachegrind. Senza andare eccessivamente nel dettaglio, è importante sapere che la compatibilità con questo formato permette l'utilizzo (si su Windows che su Linux) di tool grafici di supporto che sono in grado di analizzare il log, generare un output leggibile e ricercabile ed anche generare un grafico generale dell'esecuzione del codice.

Su Windows il tool che possiamo utilizzare si chiama WinCacheGrind, che funziona abbastanza bene nonostante l'ultima versione ufficiale sia un po' datata. In generale forse l'utilizzo di una virtual machine su cui far girare KCacheGrind (la versione per Linux che vedremo successivamente e che viene mantenuta più o meno attivamente dalla comunità) è l'opzione migliore.

Dopo aver installato il software ci basta aprire un file di log generato da XDebug per poter navigare in modo molto semplice i dati di profiling. Possiamo anche nascondere le funzioni molto veloci e le chiamate native utilizzando le rispettive opzioni (Hide Fast Functions e Hide Library Functions) che si trovano nel menu Profile.

Su Linux invece possiamo utilizzare KCacheGrind; questa versione viene aggiornata molto più frequentemente di quella windows, ed oltretutto è molto più potente sotto molti punti di vista (tra cui la stabilità).

La schermata iniziale è molto simile a quella della versione Windows; è però possibile visualizzare anche un grafico ad albero che mostra la gerarchia delle chiamate in modo grafico, permettendoci di avere una visuale complessiva dello stato di esecuzione di uno script. I singoli nodi di questo albero rappresentano i file sorgenti che possono essere a loro volta analizzati mostrando le chiamate a funzioni che vengono effettuate all'interno del file. La visualizzazione di queste informazioni avviene attraverso una griglia composta da rettagoli: più alto è il tempo di esecuzione, maggiore sarà la dimensione di questi rettangoli.

Nel caso fosse necessario andare più in dettagli e visualizzare anche i dati di profiling, è possibile fare doppio click sui singoli rettangoli.

Questo tipo di visualizzazione è molto importante ed interessante, e permette di impostare un processo di ottimizzazione scalare al fine di occuparsi inizialmente solo di ciò che più influisce sulle performance globali dell'applicazione, senza comunque perdere di vista gli altri blocchi di codice correlati se necessario.