Misura delle prestazioni

di Alessandro Rubini

Riprodotto con il permesso di Linux & C, Edizioni Vinco.

La misura delle prestazioni è da sempre una fase importante dello sviluppo informatico: ogni scelta progettuale, sia hardware sia software, va sempre misurata per valutarne la bontà; ogni realizzazione finita va poi confrontata con le alternative per lo meno a fini commerciali e di immagine.

Naturalmente, in un sistema complesso la misurazione delle prestazioni di un segmento di codice (o di un componente hardware) è influenzata da tanti parametri; spesso anzi i tempi di esecuzione di una procedura variano notevolmente tra più esecuzioni successive senza che apparentemente vi siano stati cambiamenti nelle condizioni di misura.

In questo articolo vengono presentate tecniche per la misura delle prestazioni di un programma o parti di esso, sottolineando alcune delle condizioni che influiscono sui risultati della misura stessa. Data la vastità del problema in oggetto, la trattazione non può essere esaustiva: sarà perciò limitata ai meccanismi di più basso livello e alla misurazione di attività molto circoscritte, con l'obiettivo di acquisire un'idea generale del problema e saper usare gli strumenti di basso livello per iniziare a sporcarsi le mani.

Precisione, portabilità, invasività

Le varie tecniche di misura differiscono per diversi aspetti, di cui il più visibile è la precisione di misura, ovvero la granularità dello strumento di misura adottato: tale granularità può essere per esempio di un centesimo di secondo, di un microsecondo, di un nanosecondo.

Riquadro 1 - Misurare per ottimizzare

Le prime due regole di programmazione di Rob Pike ci ricordano che (in forma ridotta e semplificata):

Lo stesso Donald Knuth, autore di The Art of Computer Programming, ci ricorda che «L'ottimizzazione prematura è la radice di tutti i mali» (attribuito a C. A. R. Hoare).

Un'altro aspetto di cui tenere conto è la portabilità dello strumento di misura: portabilità tra applicazioni diverse, tra sistemi operativi diversi o tra processori diversi che eseguono lo stesso sistema operativo. In queste pagine ci occuperemo solo della portabilità tra processori diversi, essendo il nostro ambito di lavoro unicamente GNU/Linux.

Infine, occorre tenere conto di quanto la misura in se modifichi il comportamento del codice misurato: mentre l'utente che osserva il programma con un cronometro in mano non ha influenza sull'esecuzione del codice, una misurazione più precisa richiede la partecipazione attiva del codice sotto esame o quanto meno la raccolta attiva dei dati sulla stessa macchina dove sta girando il codice misurato.

Secondo questi parametri, possiamo dare una valutazione delle tecniche più usate per la misura dei tempi di esecuzione di frammenti di codice:

Listato 1 - trig.c

#include <math.h>
#include <asm/msr.h>

int main(int argc, char **argv)
{
    unsigned long t1, t2, tsccost;
    double f;

    rdtscl(t1); /* read time stamp counter    */
    rdtscl(t2); /* as a "long" (32 bit) value */
    tsccost = t2 - t1;

    rdtscl(t1); /* time stamp counter, 32 bits */
    f = sin(1.0);
    rdtscl(t2);
    printf("sin(1) takes %5li cycles\n", t2 - t1 - tsccost);

    rdtscl(t1); /* time stamp counter, 32 bits */
    f = tan(1.0);
    rdtscl(t2);
    printf("tan(1) takes %5li cycles\n", t2 - t1 - tsccost);

    rdtscl(t1); /* time stamp counter, 32 bits */
    f = sin(0.0);
    rdtscl(t2);
    printf("sin(0) takes %5li cycles\n", t2 - t1 - tsccost);

}
/* per compilare: "make trig LDFLAGS=-lm" */

Una semplice misura: operazioni in virgola mobile

Come prima misura pratica, vediamo il tempo di eseguzione di tre funzioni trigonometriche su un normale PC: sin(1.0), tan(1.0) e sin(0.0). Il riquadro 2 spiega brevemente l'uso del TSC su processori x86, mentre il listato 1 riporta il sorgente di trig.c, programma che effettua le misure. Questo è il risultato ottenuto sulla mia macchina:

   rudo% ./trig
   sin(1) takes  5716 cycles
   tan(1) takes  1202 cycles
   sin(0) takes    62 cycles

Una conclusione che si potrebbe trarre da questi numeri è che il terzo caso sia più ottimizzato dei precedenti, a livello software o a livello hardware (nel coprocessore matematico).

In realtà, l'effetto che si vede è sicuramente dovuto alla memoria virtuale e alla cache: la prima chiamata a funzione provoca un page-fault (si veda l'articolo sulla memoria virtuale nel numero 60 di Linux&C) e un cache-miss, la seconda provoca un cache-miss e la terza nessuno dei due.

La prima chiamata a sin non viene cioè eseguita finchè il kernel non ha abilitato la corrispondente pagina di codice per il processo corrente. Potrebbe anche essere richiesto il caricamento della pagina da disco, ma molto probabilmente la pagina è già usata da altri processi (con fuser si può verificare chi stia usando libm, nel mio caso è in uso da parte di altri 21 processi).

La seconda chiamata (tan) non genera un page-fault perché le due funzioni si trovano nella stessa pagina (la verifica è lasciata come esercizio al lettore), ma si tratta di codice non presente in memoria cache: le istruzioni di programma vanno quindi caricate dalla RAM, e questo provoca una latenza rispetto al tempo di calcolo effettivo.

Ma quanto è allora il tempo di calcolo? Per saperlo basta ripetere le prove varie volte, e considerare il tempo minimo tra quelli riportati. Il programma trig-rep effettua la prova 10 volte, e un semplice uso di sort e uniq ci permette di verificare che i valori convergono verso il basso a valori che poi si ripetono.

    rudo% ./trig-rep | sort | uniq -c | sort | tail -3
          5 sin(0) takes    55 cycles
          6 sin(1) takes    38 cycles
          8 tan(1) takes   124 cycles

Riquadro 2 -Uso del TSC

Tutti i processori di famiglia x86 a partire dal Pentium contengono un registro macchina a 64 bit chiamato «Time Stamp Counter». Si tratta di un contatore di cicli macchina, pilotato dalla frequenza di clock interna al processore. Il registro può essere letto anche da un programma non privilegiato, quindi qualunque processo può usarlo per i suoi scopi, ricordando però che si tratta di codice non portabile.

Gli header del kernel dichiarano la funzione get_clocks, che cerca di dare portabilità tra le piattaforme al codice sorgente; poiché però il significato del varore ritornato da get_clocks varia enormemente tra le varie piattaforme, il suo uso in spazio utente non è da consigliarsi.

Negli esempi qui riportati, verrà usata la macro rdtscl («read TSC long») che assegna i 32 bit meno significativi del TSC alla variabile passata come argomento (è una macro, non una funzione). Finchè si usa il valore come unsigned long si possono fare differenze tra istanti di tempo vicini senza preoccuparsi dell'overflow del valore. In un processore a 2GHz, però, il valore si riazzera ogni due secondi, quindi per misure di tempi più lunghi occorre usare tutti i 64 bit del registro, chiamando rdtscll o rdtsc. Tutte le macro sono definite in <asm/msr.h> («Machine-Specific Registers»).

Fonti di errore e parziali soluzioni

Naturalmente nella misurazione di parti di programma più sostanziose l'effetto della cache non può essere scavalcato, in quanto tale effetto è sempre presente durante l'esecuzione del programma e le variazioni nel tempo di calcolo saranno fisiologiche anche in un contesto di produzione (si pensi ai servizi di rete o ancora di più alle applicazioni industriali, di cui vanno valutate le prestazioni in maniera realistica prima della messa in opera). Si può quindi dire che la cache non sia una fonte di errore nelle misure effettuate, anche se bisogna ricordarsi che la prima esecuzione ha sempre prestazioni pessime e conviene misurare solo esecuzioni successive. I page-fault, invece, sono sempre da evitarsi in un contesto di misura e se possibile anche in produzione.

Un altro problema da tenere in considerazione quando si misura è la presenza di altri processi sulla macchina dove si fanno le prove: alcuni tempi potrebbero risultare gonfiati semplicemente perché il sistema operativo ha effettuato un cambio di contesto per eseguire un altro processo prima che il processo sotto esame abbia finito. Per il programma trig mostrato qui la misura è stata fatta su una macchina scarica, anche se non sono state prese garanzie particolari in proposito (come avviare un modalità single-user o spegnere le interfaccie di rete).

Infine, tutte le attività pilotate dall'hardware influsicono sui tempi di esecuzione dei programmi attivi: le interruzioni vengono servite togliendo temporaneamente la CPU al processo corrente e il DMA effettuato dalle periferiche interferisce con il trasferimento dati da e verso la RAM da parte del processore.

È possibile per un processo richiedere al sistema operativo di impedire i page-fault e i cambi di contesto, mentre non è possibile impedire che interruzioni e DMA continuino ad avvenire. mlockall è la chiamata di sistema che chiede al kernel di bloccare in RAM tutta la memoria del processo impedendo eventi di page-fault in momenti inaspettati; ogni processo ha un limite massimo nella quantità di memoria bloccabile (si veda man getrlimit), ma per l'amministratore non ci sono limiti imposti. sched_setscheduler, invece, è la chiamata di sistema per richiedere al sistema di trattare il processo corrente come processo soft real-time ed è una possibilità riservata all'amministratore. La schedulazione tra processi real-time è rigorosamente vincolata dalla priorità di ciascuno di essi e nessun processo convenzionale può girare se un processo real-time è attivo; poiché normalmente in un sistema non ci sono processi real-time, richiedere una schedulazione real-time per un processo vuol dire in pratica bloccare l'esecuzione di tutti gli altri processi finchè il primo processo non va a dormire.

Listato 2 - Alzare la priorità

#include <stdlib.h>
#include <sched.h>
#include <sys/mman.h>

{
    struct sched_param param;

    if (mlockall(MCL_CURRENT | MCL_FUTURE)) {
        fprintf(stderr, "%s: mlockall: %s\n",
                 argv[0], strerror(errno));
        /* continue anyway */
    }
    if (!getenv("BENCH_NOTRT")) {
        param.sched_priority = 1;
        if (sched_setscheduler(0, SCHED_RR, ¶m) < 0) {
            fprintf(stderr,"%s: setscheduler: %s\n",
                    argv[0], strerror(errno));
            /* continue anyway */
        }
    }
}

La sequenza che solitamente uso per alzare la priorità del processo e impedire la paginazione è riportata nel listato 2. Normalmente conviene eseguire le misure come utente non privilegiato (così sched_setscheduler fallisce) e rifarlo come amministratore solo in un secondo tempo, dopo essersi assicurati che il programma funzioni correttamente e non richieda il processore troppo a lungo. Occorre prestare attenzione a non abusare di sched_setscheduler perché durante l'esecuzione di un processo real-time il sistema appare completamente bloccato (compresi mouse e tastiera), in quanto nessuno degli altri processi potrà usufruire dei cicli macchina. Per questo motivo, il codice del listato 2 permette di evitare l'attivazione della schedulazione real-time assegnando un valore alla variabile di ambiente BENCH_NORT, così anche lavorando da superutente si può evitare il blocco temporaneo della macchina.

Misurazione di un cambio di contesto

Il programma cswitch, distribuito con i sorgenti relativi a questo articolo, è un semplice strumento per misurare la durata del cambio di contesto tra due processi. Nonostante la durata di un cambio di contesto dipenda da vari fattori relativi ai processi in gioco, per esempio se siano stati usati o no i registri del coprocessore matematico, il risultato di cswitch è comunque significativo, se pure non sempre esattissimo. La misura è fatta usando gettimeofday per la massima portabilità.

Il programma crea due pipe e misura il tempo richiesto per scrivere e trasmettere un byte, dopo di che crea un processo figlio e mosura il tempo necessario a scambiarsi il byte. Ogni processo viene bloccato sulla read finchè l'altro processo non legge e scrive a sua volta.

Questo è quello che succede invocando il processo su una delle mie macchine (in questo caso, Linux-2.4):

    ostro%  ./cswitch 20000
    ./cswitch: mlockall: Operation not permitted
    ./cswitch: setscheduler: Operation not permitted
    20000 writes and reads take 58280 usecs (2.914 usec each)
    20000 wr/rd and cswitches take 89292 usecs (4.465 usec each)
    20000 cswitches take 31012 usecs (1.551 usec each)

    ostro% sudo ./cswitch 20000
    20000 writes and reads take 53344 usecs (2.667 usec each)
    20000 wr/rd and cswitches take 108978 usecs (5.449 usec each)
    20000 cswitches take 55634 usecs (2.782 usec each)

È interessante notare come il tempo misurato raddoppi nel caso di esecuzione come amministratore. In questo caso abbiamo due processi real-time che si contendono il processore, con il risultato che avvengono il doppio di cambi di contesto, come si può verificare usando strace nei due casi. Oltre a fornire un risultato sbagliato, perché vengono violate le assunzioni del programmatore, l'uso di sched_setscheduler in questa situazione peggiora decisamente le prestazioni dell'applicativo multi-processo. In ogni caso, altre versioni del sistema operativo presentano risultati diversi.

L'effetto negativo dell'uso delle priorità real-time è una cosa abbastanza normale: lo scheduler di Linux è ottimizzato per tutte le normali tipologie di uso della macchina e l'intervento manuale sulle priorità dei processi può peggiorare inaspettatamente le prestazioni di un sistema multi-processo. Come al solito, è sempre meglio misurare gli effetti di un intervento di presunta ottimizzazione. La schedulazione real-time, in particolare, è utile quasi esclusivamente per la lettura di sensori critici in contesti industriali.

Listato 3 - moremem.c

/*
 * Facciamo 32 passi ogni ottava: cioè
 * passi da 1kB tra 32k to 64k e di 2kB
 * tra 64k e 128k. Non ottimizzato
 */
int incr(int n)
{
    int step;
    if (n < 64) return n + 1;
    for (step = 1; step <= n; step <<= 1)
	;
    step = step >> 6;
    return n + step;
}

int main(int argc, char **argv)
{
    unsigned char *b1, *b2;
    int maxmegs, i, j;

    /* .... */

    maxmegs = atoi(argv[1]);

    b1 = malloc(maxmegs << 20);
    b2 = malloc(maxmegs << 20);

    for (i = 1; i <= maxmegs<<20; i = incr(i)) {
	min = LONG_MAX, max = 0, tot = 0;
	for (j = 0; j < NTRIALS; j++) {
	    gettimeofday(&tv1, NULL);
	    memcpy(b1, b2, i);
	    gettimeofday(&tv2, NULL);
	    l = TDIFF(tv1, tv2) - gtod - mc;
	    if (l < 0 ) l = 0;
	    if (l < min) min = l;
	    if (l > max) max = l; /* max currently not used */
	    tot = tot + l; /* tot (avg) currently not used */
	}
        printf("%9i    %9li %9f\n", i, min, (double)min/(double)i);
    }
	    
}

Misurazione di memcpy()

Una misura che trovo particolarmente interesssante è la velocità di copia della memoria. Il programma moremem.c, la cui parte principale è rappresentata nel listato 3, misura il tempo impiegato a copiare una zona di memoria tra due buffer. La copia viene fatta 10 volte e viene riportato il tempo migliore tra quelli ottenuti.

In figura 1 sono rappresentati su scala logaritmica i risultati ottenuti su un PC con processore AMD, indicando sull'asse X il numero di byte copiati. In rosso è indicato il numero di cicli macchina per ogni copia, in blu il numero di cicli macchine per ogni byte e in verde la derivata del segnale rosso. In figura 2 sono rappresentati i risultati ottenuti su un processore Intel.



Da questi grafici risulta abbastanza chiaro l'effetto della cache del processore, in quanto appena l'ammontare dei dati copiati sfora la dimensione della cache, i tempi aumentano. Dalla figura 1 per esempio si vede come le cache di primo e di secondo livello siano rispettivamente 64kB e 512kB (poiché la copia di 32kB convolge 64kB di memoria). Questo è confermato dai messaggi di avvio:

    burla% dmesg | grep 'CPU.*Cache'
    CPU: L1 I Cache: 64K (64 bytes/line), D cache 64K (64 bytes/line)
    CPU: L2 Cache: 512K (64 bytes/line)

  8   13    1.625000
  9   19    2.111111
 10   24    2.400000
 11   25    2.272727
 12   15    1.250000
 13   21    1.615385
 14   26    1.857143
 15   27    1.800000
 16   17    1.062500
 17   23    1.352941
 18   28    1.555556
 19   29    1.526316
 20   19    0.950000
 21   25    1.190476
 22   30    1.363636
 23   31    1.347826

Dai valori misurati appaiono anche alcuni dettagli implementativi, per esempio le oscillazioni iniziali dei numeri. Tali oscillazioni sono riportate nel riquadro3, dove la seconda colonna indica il numero di cicli (grafico rosso) e la terza colonna la media (grafico blu). Si può notare come copiare un numero di byte che è multiplo di 4 richieda meno tempo che copiare un numero dispari di byte: questo avviene perché in glibc (sysdeps/i386/i586/memcpy.S) l'accesso in memoria è effettuato 4 byte alla volta, copiando separatamente, uno alla volta, i byte rimanenti.

Ancora una volta, i risultati dipendono significativamente dalla versione del codice (in questo caso della libreria C) e dal processore ospite.

In figura 3 si trova un grafico corrispondente all'esecuzione su un processore PowerPC, misurando i tempi con il contatore di cicli del processore, che in questo caso si chiama «Time Base Low». Il sorgente di moremem contiene le istruzioni per leggere tale contatore. Anche qui è evidente la presenza di una cache (da 32kB in questo caso) e la presenza di copie parziali byte-per-byte per raggiungere l'allineamento.

In tutte questo figure, la dispersione della derivata punto-per-punto (grafico verde) è dovuta all'interferenza di altri eventi (per esempio le interruzioni del timer e delle periferiche), la cui presenza è inevitabile all'allungarsi dell'evento misurato, cioè al crescere della dimensione copiata.


Misurazione di sistemi più complessi

Con i meccanismi qui introdotti si possono misurare abbastanza efficacemente i tempi di esecuzione di azioni individuali o piccole sezioni di codice. Si tratta di meccanismi sicuramente sufficienti per ottimizzare memcpy o funzioni equivalenti, ma difficilmente applicabili alla scelta tra diversi metodi di allocazione all'interno di un kernel (come slab e slub) e ancora meno alla scelta tra diversi algoritmi di ordinamento degli accessi al disco, che deve evitare di essere il collo di bottiglia quando il sistema è estremamente carico.

Il confronto delle prestazioni tra diverse soluzioni in questi casi può basarsi più su una misura del throughput (richieste elaborate con successo nell'unità di tempo) unitamente ad un'analisi (profiling) di dove il processore spende il suo tempo, in situazioni di carico simulato o reale. Per l'analisi di sistemi complessi occorrono però strumenti di misura complessi, come può essere oprofile in ambiente GNU/Linux; i numeri raccolti poi diventano più aleatori e le semplici fonti di errore qui descritte si moltiplicano e si complicano. Non a caso i confronti di prestazioni tra vari sistemi o processori danno risultati diversi a seconda di chi svolge la misura.

Riquadro 4 - Approfondimenti e strumenti

I sorgenti mostrati in questo articolo sono scaricabili da qui (src.tar.gz). Oltre al codice e alle istruzioni su come usarlo contengono la documentazione completa su come sono stati generati i grafici con gnuplot in modo da riprodurre risultati confrontabili su altre macchine.

Una mia descrizione della misurazione dei tempi e della generazione di attese in spazio kernel è disponibile come http://www.linux.it/kerneldocs/time/.

libstamp, in http://ftp.linux.it/pub/People/rubini/samplecode/ è un semplice strumento per la generazione di timestamp usando le varie primitive elencate qui. È uno strumento didattico che ha come obiettivi la semplicità implementativa e la portabilità.

L'implementazione di get_cycles per le varie piattaforme si trova in <asm-arch/timex.h>.

I sorgenti del kernel hanno recentemente iniziato ad usare il tipo a 64 bit ktime_t; il file <linux/ktime.h> spiega perché è stato introdotto e come si usa, è una lettura interessante.

In spazio utente possono essere utili le chiamate di sistema getitimer e setitimer (si veda la pagina del manuale).

Per la profilazione (analisi dell'uso delle varie parti) di un applicativo si possono usare gprof e gcov, inclusi in tutte le distribuzioni, facendo attenzione al carico computazione aggiuntivo richiesto dalla raccolta dei dati.

Per la profilazione del kernel e di un intero sistema, si veda oprofile, presente in tutte le distribuzioni. Il pacchetto usa molte risorse di diagnostica interne ai vari tipi di processori (non solo x86) e offre una certa portabilità d'uso.

Chi è interessato può cercare dei riferimenti alle varie suite di benchmark, anche se servono solo per confrontare i processori e i sistemi operativi e vanno trattate con molta attenzione.

Alessandro Rubini

La copia letterale e la redistribuzione su qualsiasi supporto di questo articolo nella sua integrità è permessa, purchè questa nota sia conservata.