Comprensione dell'output del profiler di Firebug

Question

Ho cercato di utilizzare il profiler di Firebug per comprendere meglio l'origine di alcuni problemi di prestazioni JavaScript che stiamo riscontrando, ma sono un po 'confuso dall'output.

Quando profilo un codice, il profiler riporta Profilo (464.323 ms, 26.412 chiamate) . Sospetto che il 464.323 ms sia la somma del tempo di esecuzione per quelle 26.412 chiamate.

Tuttavia, quando analizzo i risultati dettagliati, vedo i singoli risultati con un tempo di esecuzione medio maggiore di 464.323 ms, ad es. il risultato con il tempo medio più alto riporta i seguenti dettagli:

Calls: **1**
Percent: **0%**
Own Time: **0.006 ms**
Time: **783.506 ms**
Avg: **783.506 ms**
Min: **783.506 ms**
Max: **783.506 ms**

Un altro risultato riporta:

Calls: **4**
Percent: **0.01%**
Own Time: **0.032 ms**
Time: **785.279 ms**
Avg: **196.32 ms**
Min: **0.012 ms**
Max: **783.741 ms**

Tra questi due risultati la somma dei risultati Time è molto più di 464.323.

Quindi, cosa significano questi vari numeri? Di quali dovrei fidarmi?

Answer 1

Ogni colonna ha una descrizione di ciò che significa se si imposta il mouse su di esso in Firebug. Presumo che tu possa leggere su come ogni colonna funziona da solo. Tuttavia, ti sei sicuramente imbattuto in alcuni comportamenti strani che devono essere spiegati.

Il tempo proprio è il tempo impiegato dalla funzione per eseguire il codice al suo interno. Se la funzione non chiama altre funzioni, ora propria dovrebbe essere uguale a ora . Tuttavia, se sono presenti chiamate di funzione nidificate, anche tempo conta anche il tempo impiegato per eseguirle. Pertanto, tempo sarà quasi sempre maggiore del tempo proprio e nella maggior parte dei casi si sommerà a più del tempo totale riportato dal profiler.

Tuttavia, il tempo di nessuna singola funzione dovrebbe essere maggiore del tempo totale registrato dal profiler per le chiamate JavaScript. Questo problema è sicuramente un bug e posso capire perché hai problemi a fidarti di Firebug quando ti dà un risultato così paradossale. Credo di aver rintracciato il motivo per cui si verifica questo errore: AJAX.

Sembra che le chiamate AJAX stiano facendo sì che le colonne che contano le chiamate di funzioni nidificate riportino informazioni errate. Finiscono per contare sia il tempo di esecuzione JavaScript che la richiesta al server.

Puoi riprodurre questo bug del profiler procedendo come segue:

1. Vai a qualsiasi sito che utilizza AJAX. (Ero solito http://juicystudio.com/experiments/ajax/index.php )
2. Abilita debug console / script.
3. Attiva il profiler.
4. Effettua una chiamata AJAX. (Quelli multipli potrebbero chiarire di più il problema.)
5. Ferma il profiler, esamina l'output.

In questo esempio, per quanto riguarda il tempo rispetto al tempo proprio , il tempo proprio di ciascuna funzione si somma al tempo totale del profiler ma la colonna tempo include il tempo impiegato dalla chiamata AJAX per comunicare con il server. Ciò significa che la colonna time non è corretta se stai cercando solo la velocità di esecuzione di JavaScript.

Peggiora: poiché tempo , tempo medio , min e max contano tutte le chiamate di funzione nidificate, sono tutti errati se si utilizza AJAX. Inoltre, qualsiasi funzione che alla fine utilizza AJAX (in una chiamata di funzione nidificata) riporterà anche l'ora in modo errato. Ciò significa che molte funzioni potrebbero riportare informazioni errate! Quindi non fidarti di nessuna di quelle colonne per ora fino a quando Firebug non risolverà il problema. (È possibile che intendessero che il comportamento fosse così, anche se nella migliore delle ipotesi è confuso lasciarlo così.)

Se non stai usando AJAX, è in gioco un altro problema; facci sapere se lo sei o meno.

Answer 2

Se capisco le cose correttamente, va qualcosa del genere:

Sulla prima riga vedrai che il Tempo personale è "solo 0,006 ms". Ciò significa che anche se il tempo impiegato in quella funzione era 783.506 ms, la maggior parte di essa è stata spesa all'interno di funzioni chiamate da quella funzione.

Quando utilizzo Firebug per ottimizzare il codice, provo a ridurre il "tempo proprio" di funzioni che si chiamano di più. (ovviamente controllando anche eventuali chiamate di funzioni non necessarie da rimuovere del tutto)

Answer 3

Da Tutorial Firebug - Registrazione , Profiling e CommandLine (Parte II) : (gli esempi ci sono buoni)

  

Colonne e descrizione del profiler

     

Colonna funzione : mostra il nome di ciascuna funzione.
   Colonna di chiamata : mostra il conteggio di quante funzioni particolari sono state invocate.
   Colonna percentuale : mostra il tempo impiegato da ciascuna funzione in percentuale.
   Colonna temporale : mostra la durata dell'esecuzione dal punto iniziale di una funzione al punto finale di una funzione.
   Colonna media : mostra il tempo medio di esecuzione di una particolare funzione. Se stai chiamando una funzione una sola volta, non vedrai le differenze. Se stai chiamando più di una volta, vedrai le differenze.
        La formula per quella colonna è
        Avg = Own Ttime / Call;
   Colonna minima e colonna massima : mostra il tempo minimo di esecuzione di una particolare funzione.
   Colonna file : il nome del file del file in cui si trova la funzione.

Answer 4

Da quello che ho capito questo è come funziona ... il tempo totale del profiler è la somma della colonna "Proprio tempo". Tuttavia, potresti notare che alcuni valori singoli di tempo potrebbero essere superiori al tempo totale del profiler. Questi straordinari sono stati spesi al di fuori di JavaScript, ad es. in una chiamata plug-in. Se la tua funzione JS effettua una chiamata del plug-in, ad esempio, e attende che la funzione del plug-in torni a JS, i tempi di attesa NON verranno segnalati dal tempo totale del profiler, ma saranno inclusi nella colonna Tempo.