Misurare il tempo di esecuzione di una query

Il sistema di debug del nostro CMS non sempre riporta tutte le informazioni che si vorrebbero, una delle più utili è sicuramente il tempo di esecuzione di ciascuna query effettuata per generare la pagina che si sta visualizzando.

Purtroppo per ottenere tale informazione non è sufficiente scrivere un nuovo plugin, ma è necessario modificare i files del nucleo stesso di Joomla!.
Questa modifica comporta che, in caso di aggiornamento del CMS, il lavoro verrà probabilmente sovrascritto. Nel caso specifico non si tratta di un gran problema per due motivi:

• la modifica si effettua in cinque minuti;
• risolto il problema per cui necessitavamo dell'informazione, questa non ci serve più.

Per il motivo sopra indicato questa volta non verrà allegato nessun sorgente, che sarebbe legato ad una singola versione del CMS, ma verrà spiegato il metodo con cui ottenere l'informazione desiderata.

Attenzione!

La modifica è banale, ma richiede comunque la capacità di agire sul codice PHP capendo esattamente che si stia facendo, pena sito offline.

Esecuzione di una query

Joomla prevede l'uso di due classi per l'interfacciamento con il database e seleziona quella da usare a seconda di quale libreria sia disponibile sul server, ovvero mysql o mysqli (i = improved); entrambe le classi estendono JDatabase (/libraries/joomla/database/database.php) che il CMS usa per inviare comandi al server DB e riceverne i dati.

Il metodo su cui dobbiamo concentrare la nostra attenzione è query() per Joomla! 1.5, mentre è execute() per Joomla! 2.5; dato che si tratta di un metodo astratto ne cercheremo l'implementazione all'interno delle due classi derivate rintracciabili in /libraries/joomla/database/database/.

L'indicazione su quale libreria è in uso è facilmente ritrovabile nel file di configurazione (/configuration.php)

Joomla! 1.5

var $dbtype = 'mysql'; // Normally mysql

Joomla! 2.5

public $dbtype = 'mysqli'; 

I due files contenenti le classi si trovano nella cartella /libraries/joomla/database/database/

Misurare il tempo di esecuzione Joomla! 1.5

Essendo la classe usata di default, concentreremo la nostra attenzione sulla classe JDatabaseMySQL (/libraries/joomla/database/database/mysql.php) nella versione presente con Joomla! 1.5.26 (l'ultima disponibile alla stesura di questo articolo).

Individuiamo il codice del metodo query() (inizia alla riga 206) alla riga 223 troveremo il seguente codice:

$this->_cursor = mysql_query( $sql, $this->_resource );

è il codice usato per effettuare la query sul database.

A questo punto dovremo inserire prima di questa istruzione la lettura dell'orologio di sistema, ed una analoga lettura dovrà essere eseguita subito dopo l'istruzione in questione. Sostituiamo pertanto la riga indicata con il seguente codice:

 $time_start = microtime(true);
 $this->_cursor = mysql_query( $sql, $this->_resource );
 $time_end = microtime(true);
 
 if ($this->_debug) {
 $tmpQs=array_pop($this->_log);
 $this->_log[] = sprintf("%s\n/** query takes %0.3f seconds **/", $tmpQs, $time_end - $time_start, $time_end, $time_start);
 }

La seconda parte del codice (if ($this->_debug)...) serve a recuperare la query dall'array delle queries eseguite, in cui è salvata prima della sua esecuzione, e ad aggiungere, in coda alla stessa, il tempo di esecuzione in secondi, con risoluzione ai millesimi.

La modifica al file mysqli.php è praticamente identica, pertanto non ne riporteremo la spiegazione.

Misurare il tempo di esecuzione Joomla! 2.5

Essendo la classe usata di default, concentreremo la nostra attenzione sulla classe JDatabaseMySQL (/libraries/joomla/database/database/mysqli.php) nella versione presente con Joomla! 2.5.13 (l'ultima disponibile alla stesura di questo articolo).

Individuiamo il codice del metodo execute() (inizia alla riga 339) alla riga 382 troveremo il seguente codice:

$this->cursor = mysqli_query($this->connection, $sql);

è il codice usato per effettuare la query sul database.

A questo punto dovremo inserire prima di questa istruzione la lettura dell'orologio di sistema, ed una analoga lettura dovrà essere eseguita subito dopo l'istruzione in questione. Sostituiamo pertanto la riga indicata con il seguente codice:

 $time_start = microtime(true);
 $this->cursor = mysqli_query($this->connection, $sql);
 $time_end = microtime(true);
 
 if ($this->debug) {
 $tmpQs=array_pop($this->log);
 $this->log[] = sprintf("%s\n/** query takes %0.3f seconds **/", $tmpQs, $time_end - $time_start, $time_end, $time_start);
 }

La seconda parte del codice (if ($this->debug)...) serve a recuperare la query dall'array delle queries eseguite, in cui è salvata prima della sua esecuzione, e ad aggiungere, in coda alla stessa, il tempo di esecuzione in secondi, con risoluzione ai millesimi.

La modifica ad altri driver segue lo stesso criterio, ma eviteremo di riportarla qui data la scarsa diffusione degli stessi.

 

Misurare il tempo di esecuzione Joomla! 3.x

Il debug di Joomla! 3.x riporta già una notevole serie di informazioni sulla esecuzione della query accedendo alle funzioni di supporto di MySql, quindi non necessita di alcuna modifica aggiuntiva.

Requisiti

A parte un minimo di perizia da parte del lettore, è richiesta la versione 5 di PHP per il supporto del parametro opzionale get_as_float e che il sistema supporti correttamente la funzione microtime (vedi php.net).

Debug più ricco

All'interno di questo sito potrete trovare un utile rimpiazzo per il plugin base che vi fornirà ulteriori preziose informazioni di debug.