2009-06-16 8 views
8

Sto cercando di iniziare con Google Perf Tools per profilare alcune applicazioni a uso intensivo della CPU. È un calcolo statistico che scarica ogni passaggio in un file usando `ofstream '. Non sono un esperto in C++ quindi mi sto preoccupando di trovare il collo di bottiglia. Il mio primo passaggio dà risultati:Che cosa misura esattamente il profilo C++ (strumenti di google cpu perf)?

 
Total: 857 samples 
    357 41.7% 41.7%  357 41.7% _write$UNIX2003 
    134 15.6% 57.3%  134 15.6% _exp$fenv_access_off 
    109 12.7% 70.0%  276 32.2% scythe::dnorm 
    103 12.0% 82.0%  103 12.0% _log$fenv_access_off 
     58 6.8% 88.8%  58 6.8% scythe::const_matrix_forward_iterator::operator* 
     37 4.3% 93.1%  37 4.3% scythe::matrix_forward_iterator::operator* 
     15 1.8% 94.9%  47 5.5% std::transform 
     13 1.5% 96.4%  486 56.7% SliceStep::DoStep 
     10 1.2% 97.5%  10 1.2% 0x0002726c 
     5 0.6% 98.1%  5 0.6% 0x000271c7 
     5 0.6% 98.7%  5 0.6% _write$NOCANCEL$UNIX2003 

Ciò è sorprendente, dal momento che tutti i calcoli reali avviene in SliceStep :: Dostęp. Il "_write $ UNIX2003" (dove posso scoprire di cosa si tratta?) Sembra provenire dalla scrittura del file di output. Ora, quello che mi confonde è che se commento tutte le dichiarazioni outfile << "text" ed eseguo pprof, il 95% è in SliceStep::DoStep e `_write $ UNIX2003 'se ne va. Tuttavia la mia applicazione non si velocizza, come misurato dal tempo totale. Il tutto si accelera meno dell'1 percento.

Cosa mi manca?

Aggiunto: L'uscita pprof senza i outfile << affermazioni è:

 
Total: 790 samples 
    205 25.9% 25.9%  205 25.9% _exp$fenv_access_off 
    170 21.5% 47.5%  170 21.5% _log$fenv_access_off 
    162 20.5% 68.0%  437 55.3% scythe::dnorm 
     83 10.5% 78.5%  83 10.5% scythe::const_matrix_forward_iterator::operator* 
     70 8.9% 87.3%  70 8.9% scythe::matrix_forward_iterator::operator* 
     28 3.5% 90.9%  78 9.9% std::transform 
     26 3.3% 94.2%  26 3.3% 0x00027262 
     12 1.5% 95.7%  12 1.5% _write$NOCANCEL$UNIX2003 
     11 1.4% 97.1%  764 96.7% SliceStep::DoStep 
     9 1.1% 98.2%  9 1.1% 0x00027253 
     6 0.8% 99.0%  6 0.8% 0x000274a6 

Questo appare come ciò che mi aspettavo, tranne che non vedo alcun aumento visibile in termini di prestazioni (0,1 secondi in un secondo calcolo 10) . Il codice è essenzialmente:

ofstream outfile("out.txt"); 
for loop: 
    SliceStep::DoStep() 
    outfile << 'result' 
outfile.close() 

Aggiornamento: I tempi utilizzando boost :: timer, a partire da dove il profiler inizia e finisce dove finisce. Non uso discussioni o niente di speciale.

+0

Come si misura il runtime? Esegui un "orario ./programma tuo" per entrambe le configurazioni. Usi il multithreading? – ebo

+0

Eseguire una corsa con il tempo e misurare il tempo di sistema/ora. I numeri del profiler indicano che si dovrebbe avere il 40% in meno di runtime senza output. La spiegazione più semplice sarebbe che la misurazione del profiler è distorta. – ebo

+0

È tutto in utente. Quello che sto facendo è piuttosto semplice, penso ... Il fatto che il file sia aperto tutto il tempo significa qualcosa? – Tristan

risposta

3

Dalle mie osservazioni:

I numeri si ottiene dal vostro profiler dire che il programma dovrebbe essere circa il 40% più veloce senza le istruzioni di stampa.

Il runtime, tuttavia, rimane pressoché la stessa.

Ovviamente una delle misurazioni deve essere errata. Ciò significa che devi fare misurazioni maggiori e migliori.

Prima Suggerisco a partire da un altro strumento facile: il comando di tempo. Questo dovrebbe farti un'idea approssimativa su dove trascorri il tuo tempo.

Se i risultati non sono ancora conclusivi avete bisogno di un TestCase meglio:

  • Utilizzare un problema più grande
  • fare un riscaldamento prima di misurare. Fai alcuni loop e inizia qualsiasi misura dopo (nello stesso processo).

Tiristan: E 'tutto nella utente. Quello che sto facendo è piuttosto semplice, penso ...Il fatto che il file sia aperto per tutto il tempo significa qualcosa?

Ciò significa che il profiler è errato.

stampa 100000 linee alla console utilizzando i risultati di pitone in qualcosa di simile:

for i in xrange(100000): 
    print i 

di consolarlo:

time python print.py 
[...] 
real 0m2.370s 
user 0m0.156s 
sys  0m0.232s 

Versus:

time python test.py > /dev/null 

real 0m0.133s 
user 0m0.116s 
sys  0m0.008s 

Il mio punto è: Il tuo misuratore interno ents e time show non si ottiene nulla dalla disattivazione dell'output. Google Perf Tools dice che dovresti. Chi ha torto?

+0

L'operazione impiega sicuramente 10 secondi, il tutto praticamente vicino alla funzione Slice :: DoStep. Non capisco come la _write possa andare via, dopo essere stata del 40%, e non avere alcun impatto ... – Tristan

+0

Questo è il punto. Un numero deve essere sbagliato. Scopri quale. I numeri generati dal profiler potrebbero non essere statisticamente significativi o errati. – ebo

1

_write $ UNIX2003 si riferisce probabilmente alla chiamata di sistema POSIX write, che viene inviata al terminale. I/O è molto lento rispetto a qualsiasi altra cosa, quindi ha senso che il tuo programma passi molto tempo se stai scrivendo un bel po 'di output.

Non sono sicuro del motivo per cui il programma non si accelera quando si rimuove l'output, ma non posso davvero fare un'ipotesi solo sulle informazioni che hai fornito. Sarebbe bello vedere parte del codice o anche l'output di perftools quando viene rimossa l'istruzione cout.

1

Google perftools raccoglie campioni dello stack di chiamate, quindi ciò che serve è ottenere una certa visibilità in questi.

In base al documento, è possibile visualizzare il grafico della chiamata in base alla granularità dell'istruzione o dell'indirizzo. Questo dovrebbe dirti quello che devi sapere.

Problemi correlati