Utilizzare l'analisi forense e l'investigazione per risolvere i misteri delle prestazioni di JavaScript

John McCutchan
John McCutchan

Introduzione

Negli ultimi anni, le applicazioni web hanno subito una notevole accelerazione. Molte applicazioni ora funzionano così velocemente che alcuni sviluppatori mi chiedevano "il web è abbastanza veloce?". Per alcune applicazioni può esserlo, ma gli sviluppatori che lavorano su applicazioni ad alte prestazioni sappiamo che non è abbastanza veloce. Nonostante gli incredibili progressi nella tecnologia delle macchine virtuali JavaScript, uno studio recente ha dimostrato che le applicazioni Google trascorrono tra il 50% e il 70% del proprio tempo all'interno di V8. La tua applicazione ha un tempo limitato, eliminando i cicli da un sistema significa che un altro sistema può fare di più. Ricorda che le applicazioni in esecuzione a 60 fps hanno solo 16 ms per frame oppure jank. Continua a leggere per scoprire come ottimizzare le applicazioni JavaScript e di creare il profilo di JavaScript, in una storia di successo dei detective del rendimento del team V8 che hanno individuato un problema di prestazioni poco chiaro in Find Your Way to Oz.

Sessione Google I/O 2013

Ho presentato questo materiale alla conferenza Google I/O 2013. Guarda il seguente video:

Perché il rendimento è importante?

I cicli della CPU sono un gioco a somma zero. Se riduci il consumo di una parte del tuo sistema, puoi utilizzarne di più in un'altra o lavorare in modo più fluido in generale. Eseguire più velocemente e fare di più sono spesso obiettivi concorrenti. Gli utenti chiedono nuove funzionalità e si aspettano anche che la tua applicazione funzioni in modo più fluido. Le macchine virtuali JavaScript diventano sempre più veloci, ma questo non è un motivo per ignorare i problemi di prestazioni che è possibile risolvere oggi, come già conoscono i molti sviluppatori che hanno a che fare con i problemi di prestazioni delle applicazioni web. Nelle applicazioni in tempo reale con una frequenza fotogrammi elevata, la pressione per essere priva di jank è fondamentale. Insomniac Games ha prodotto uno studio che ha dimostrato che una frequenza fotogrammi stabile e duratura è importante per il successo di un gioco: "Una frequenza fotogrammi stabile è comunque un segno di prodotto professionale e ben realizzato". Gli sviluppatori web ne prendono nota.

Risoluzione dei problemi di rendimento

Risolvere un problema di performance è come risolvere un crimine. Devi esaminare attentamente le prove, verificare le cause sospette e sperimentare diverse soluzioni. Devi sempre documentare le misurazioni, in modo da avere la certezza di aver effettivamente risolto il problema. C'è pochissima differenza tra questo metodo e il modo in cui i criminali investigano su un caso. I investigatori esaminano le prove, interrogano i sospetti ed eseguono esperimenti nella speranza di trovare la pistola fumatori.

CSI V8: Oz

Gli incredibili maghi che creano Trova la tua strada per Oz si sono rivolti al team V8 con un problema di prestazioni che non sono riusciti a risolvere da soli. A volte Oz si bloccava, causando jank. Gli sviluppatori di Oz avevano eseguito un'indagine iniziale utilizzando il riquadro della cronologia in Chrome DevTools. Esaminando l'utilizzo della memoria, hanno trovato il grafico a dente sega. Una volta al secondo, il garbage collection stava raccogliendo 10 MB di spazzatura e le pause nella garbage collection corrispondevano al jank. Simile al seguente screenshot di Spostamenti in Chrome DevTools:

Cronologia degli strumenti per sviluppatori

I detective V8, Jakob e Yang, hanno preso in carico il caso. Quello che è accaduto è stato un lungo avanti e indietro tra Jakob e Yang del team V8 e del team Oz. Ho sintetizzato questa conversazione con gli eventi importanti che ci hanno aiutato a capire il problema.

Prove

Il primo passo consiste nel raccogliere e studiare le prove iniziali.

Che tipo di applicazione stiamo esaminando?

La demo di Oz è un'applicazione 3D interattiva. Per questo motivo, è molto sensibile alle pause causate da garbage collection. Ricorda che un'applicazione interattiva in esecuzione a 60 FPS ha 16 ms per svolgere tutte le operazioni di JavaScript e deve trascorrere un po' di tempo affinché Chrome possa elaborare le chiamate grafiche e disegnare lo schermo.

Oz esegue molti calcoli aritmetici su valori doppi ed effettua frequenti chiamate a WebAudio e WebGL.

Che tipo di problema di rendimento stiamo riscontrando?

Stiamo notando delle pause, note anche come calo dei frame, note anche come jank. Queste pause sono correlate alle esecuzioni di garbage collection.

Gli sviluppatori seguono le best practice?

Sì, gli sviluppatori di Oz sono esperti nelle prestazioni e nelle tecniche di ottimizzazione delle VM JavaScript. Vale la pena notare che gli sviluppatori Oz utilizzavano CoffeeScript come linguaggio di origine e producevano codice JavaScript tramite il compilatore CoffeeScript. Questo ha reso più complicate le indagini a causa della disconnessione tra il codice scritto dagli sviluppatori di Oz e il codice utilizzato dalla V8. Chrome DevTools ora supporta le mappe di origine, il che renderebbe più semplice.

Perché viene eseguito il garbage collector?

La memoria in JavaScript viene gestita automaticamente per lo sviluppatore dalla VM. La versione 8 utilizza un sistema di garbage collection comune in cui la memoria viene divisa in due (o più) generations. La giovane generazione detiene oggetti che sono stati allocati di recente. Se un oggetto sopravvive abbastanza a lungo, viene spostato alla vecchia generazione.

La giovane generazione viene raccolta con una frequenza molto più elevata rispetto a quella della vecchia generazione. Questo è stato progettato, poiché la collezione di giovani generazione è molto più economica. Spesso si può supporre che pause frequenti di GC siano causate da raccolte di giovani generazioni.

Nella versione V8 lo spazio di memoria giovane è diviso in due blocchi contigui di dimensioni uguali. Solo uno di questi due blocchi di memoria è in uso in un dato momento ed è chiamato spazio. Mentre la memoria rimanente è presente nello spazio, l'allocazione di un nuovo oggetto è economica. Un cursore nello spazio viene spostato in avanti del numero di byte necessari per il nuovo oggetto. Questo continua fino all'esaurimento dello spazio. A questo punto il programma viene interrotto e inizia la raccolta.

Memoria giovane V8

A questo punto, gli elementi dallo spazio e dallo spazio sono scambiati. Ciò che era lo spazio, ed è ora lo dallo spazio, viene scansionato dall'inizio alla fine e tutti gli oggetti che sono ancora vivi vengono copiati nello spazio o promossi allo spazio di generazione precedente. Se vuoi dei dettagli, ti consiglio di leggere l'articolo sull'algoritmo di Cheney.

Intuitivamente dovresti capire che ogni volta che un oggetto viene allocato in modo implicito o esplicito (tramite una chiamata a nuovo, [] o {}), la tua applicazione si avvicina sempre di più a una garbage collection e la temuta pausa dell'applicazione.

Sono previsti 10 MB/sec di spazzatura per questa applicazione?

In breve, no. Lo sviluppatore non sta facendo nulla per aspettarsi 10 MB/sec di spazzatura.

Sospetti

La fase successiva dell’indagine consiste nell’individuare i potenziali sospetti e quindi ridurli.

Sospetto n. 1

Chiamata nuova durante il frame. Ricorda che ogni oggetto allocato ti avvicina sempre di più a una pausa di GC. Le applicazioni che vengono eseguite con frequenze fotogrammi elevate, in particolare, dovrebbero cercare di non avere allocazioni per frame. Generalmente, questa procedura richiede un sistema di riciclo degli oggetti ben ponderato e specifico per ciascuna applicazione. I detective V8 hanno contattato il team di Oz e non hanno chiamato nuovi. In effetti il team di Oz era già ben consapevole di questo requisito e ha detto "Sarebbe imbarazzante". Cancellalo dall'elenco.

Sospetto n. 2

Modifica della "forma" di un oggetto all'esterno del costruttore. Questo accade ogni volta che viene aggiunta una nuova proprietà a un oggetto esterno al costruttore. Viene creata una nuova classe nascosta per l'oggetto. Quando il codice ottimizzato rileva questa nuova classe nascosta, viene attivato un deopt, il codice non ottimizzato viene eseguito finché non viene classificato di nuovo come attivo e ottimizzato. Questo tasso di abbandono delle operazioni di de-ottimizzazione e ri-ottimizzazione si tradurrà in jank,ma non è strettamente correlato a un'eccessiva creazione di rifiuti. Dopo un attento controllo del codice, è stato confermato che le forme degli oggetti erano statiche, quindi il sospetto n. 2 sia stato escluso.

Sospetto n. 3

Aritmetica nel codice non ottimizzato. Nel codice non ottimizzato, tutto il calcolo determina l'allocazione degli oggetti effettivi. Ad esempio, questo snippet:

var a = p * d;
var b = c + 3;
var c = 3.3 * dt;
point.x = a * b * c;

Risultati nella creazione di 5 oggetti HeapNumber. Le prime tre riguardano le variabili a, b e c. Il 4° è per il valore anonimo (a * b) e il 5° è da n. 4 * c; Il 5° è infine assegnato al punto.x.

Oz esegue migliaia di queste operazioni per frame. Se uno qualsiasi di questi calcoli avviene in funzioni che non vengono mai ottimizzate, potrebbero essere la causa della garbage. Perché i calcoli non ottimizzati allocano la memoria anche per risultati temporanei.

Sospetto n. 4

Memorizzazione di un numero a precisione doppia in una proprietà. Per archiviare il numero, è necessario creare un oggetto HeapNumber e la proprietà venga modificata in modo che punti al nuovo oggetto. Modificare la proprietà in modo che punti all'HeapNumber non generi rifiuti. Tuttavia, è possibile che ci siano molti numeri a precisione doppia archiviati come proprietà dell'oggetto. Il codice è ricco di istruzioni come le seguenti:

sprite.position.x += 0.5 * (dt);

Nel codice ottimizzato, ogni volta che a x viene assegnato un valore calcolato di recente, un'istruzione apparentemente innocua, un nuovo oggetto HeapNumber viene implicitamente allocato, avvicinandoci a una pausa della garbage collection.

Tieni presente che utilizzando un array digitato (o un array normale che contiene solo valori doppi), puoi evitare del tutto questo problema specifico, poiché lo spazio di archiviazione per il numero a precisione doppia viene allocato una sola volta e la modifica ripetuta del valore non richiede nuovo spazio di archiviazione da allocare.

Il sospetto n. 4 è una possibilità.

Servizi forensi

A questo punto i detective hanno due possibili sospetti: memorizzare i numeri heap come proprietà degli oggetti e i calcoli aritmetici che avvengono all'interno di funzioni non ottimizzate. Era giunto il momento di andare in laboratorio per stabilire con certezza quale sospettato fosse colpevole. NOTA: in questa sezione userò una riproduzione del problema rilevato nel codice sorgente di Oz. Questa riproduzione presenta ordini di grandezza minori rispetto al codice originale, per cui è più facile ragionare.

Esperimento 1

Verifica della sospetta n. 3 (calcolo aritmetico all'interno di funzioni non ottimizzate). Il motore JavaScript V8 ha un sistema di registrazione integrato che può fornire informazioni dettagliate su ciò che accade dietro le quinte.

Chrome non è in esecuzione e viene avviato con i flag:

--no-sandbox --js-flags="--prof --noprof-lazy --log-timer-events"

Se esci completamente da Chrome, nella directory corrente verrà visualizzato un file v8.log.

Per poter interpretare i contenuti di v8.log, devi scaricare la stessa versione v8 utilizzata da Chrome (check about:version) e crearla.

Dopo aver creato la versione 8, puoi elaborare il log utilizzando il processore dei segni di graduazione:

$ tools/linux-tick-processor /path/to/v8.log

Sostituisci Linux con Mac o Windows, a seconda della piattaforma. Questo strumento deve essere eseguito dalla directory di origine di primo livello nella versione 8.

Il processore di graduazione visualizza una tabella basata su testo delle funzioni JavaScript con il maggior numero di segni di graduazione:

[JavaScript]:
ticks  total  nonlib   name
167   61.2%   61.2%  LazyCompile: *opt demo.js:12
 40   14.7%   14.7%  LazyCompile: unopt demo.js:20
 15    5.5%    5.5%  Stub: KeyedLoadElementStub
 13    4.8%    4.8%  Stub: BinaryOpStub_MUL_Alloc_Number+Smi
  6    2.2%    2.2%  Stub: BinaryOpStub_ADD_OverwriteRight_Number+Number
  4    1.5%    1.5%  Stub: KeyedStoreElementStub
  4    1.5%    1.5%  KeyedLoadIC:  {12}
  2    0.7%    0.7%  KeyedStoreIC:  {13}
  1    0.4%    0.4%  LazyCompile: ~main demo.js:30

Come puoi vedere, demo.js aveva tre funzioni: opt, unopt e main. Accanto ai nomi delle funzioni ottimizzate è presente un asterisco (*). Tieni presente che l'opzione di attivazione della funzione è ottimizzata, mentre l'opzione di disattivazione non è ottimizzata.

Un altro strumento importante nella borsa degli attrezzi del detective V8 è il timer della trama. Può essere eseguito in questo modo:

$ tools/plot-timer-event /path/to/v8.log

Dopo l'esecuzione, nella directory corrente si trova un file png chiamato timer-events.png. Quando lo apri, dovresti vedere qualcosa di simile a questo:

Eventi timer

Oltre al grafico in basso, i dati sono visualizzati in righe. L'asse X indica il tempo (ms). Sul lato sinistro sono presenti le etichette per ogni riga:

Eventi timer asse Y

La riga V8.Execute ha disegnato una linea verticale nera su ogni segno di spunta del profilo in cui V8 stava eseguendo il codice JavaScript. V8.GCScavenger ha una linea verticale blu disegnata su ogni segno di spunta del profilo in cui V8 stava eseguendo una collezione di nuova generazione. Allo stesso modo per gli altri stati V8.

Una delle righe più importanti è il tipo di codice in fase di esecuzione. L'icona è verde quando viene eseguito codice ottimizzato, mentre viene eseguito un mix di rosso e blu quando viene eseguito codice non ottimizzato. Il seguente screenshot mostra la transizione da ottimizzato a non ottimizzato e poi di nuovo a codice ottimizzato:

Tipo di codice in esecuzione

Idealmente, ma mai immediatamente, questa linea sarà verde fissa. Il che significa che il tuo programma è passato a uno stato stabile ottimizzato. Il codice non ottimizzato verrà sempre eseguito più lentamente del codice ottimizzato.

Se sei arrivato a questa lunghezza, vale la pena notare che puoi lavorare molto più velocemente con il refactoring della tua applicazione in modo che possa essere eseguita nella shell di debug v8: d8. L'uso di d8 offre tempi di iterazione più rapidi con gli strumenti processore di selezione e timer di tracciamento. Un altro effetto collaterale dell'uso di d8 è che diventa più facile isolare il problema reale, riducendo la quantità di rumore presente nei dati.

Il grafico degli eventi timer dal codice sorgente di Oz ha mostrato una transizione da un codice ottimizzato a quello non ottimizzato e, durante l'esecuzione di codice non ottimizzato, sono state attivate molte raccolte di nuova generazione, come nello screenshot seguente (nota che il tempo è stato rimosso nella parte centrale):

Grafico degli eventi timer

Osservando attentamente puoi vedere che le linee nere che indicano quando V8 è in esecuzione il codice JavaScript mancano esattamente negli stessi momenti di spunta del profilo delle raccolte di nuova generazione (linee blu). Questo dimostra chiaramente che durante la raccolta dei rifiuti, lo script viene messo in pausa.

Osservando l'output del processore dei segni di graduazione dal codice sorgente di Oz, la funzione superiore (updateSprites) non è stata ottimizzata. In altre parole, anche la funzione in cui il programma ha trascorso più tempo non era ottimizzata. Questo indica fortemente che il colpevole è il sospetto n. 3. L'origine di updateSprites conteneva loop simili ai seguenti:

function updateSprites(dt) {
    for (var sprite in sprites) {
        sprite.position.x += 0.5 * dt;
        // 20 more lines of arithmetic computation.
    }
}

Sapendo V8 come fanno, hanno immediatamente riconosciuto che il costrutto for-i-in loop talvolta non è ottimizzato da V8. In altre parole, se una funzione contiene un costrutto del ciclo for-i-in, potrebbe non essere ottimizzata. Questo è un caso speciale oggi e probabilmente cambierà in futuro, ossia la V8 potrebbe un giorno ottimizzare questo costrutto del loop. Dal momento che non siamo detective del V8 e non conosciamo il V8 come il dorso delle nostre mani, come possiamo determinare perché updateSprites non è stato ottimizzato?

Esperimento 2

Chrome viene eseguito con questo flag:

--js-flags="--trace-deopt --trace-opt-verbose"

visualizza un log dettagliato dei dati di ottimizzazione e disattivazione. Cercando nei dati relativi a updateSprites troviamo:

[Ottimizzazione disattivata per updateSprites, motivo: ForInStatement non è veloce caso]

Proprio come i detective ipotizzarono, il motivo era il costrutto del ciclo for-i-in.

Caso chiuso

Dopo aver scoperto il motivo per cui updateSprites non era ottimizzato, la soluzione è stata semplice. È sufficiente spostare il calcolo nella propria funzione, ovvero:

function updateSprite(sprite, dt) {
    sprite.position.x += 0.5 * dt;
    // 20 more lines of arithmetic computation.
}

function updateSprites(dt) {
    for (var sprite in sprites) {
        updateSprite(sprite, dt);
    }
}

updateSprite verrà ottimizzato, con un conseguente calo degli oggetti HeapNumber e interruzioni di GC meno frequenti. Dovresti verificarlo facilmente eseguendo gli stessi esperimenti con il nuovo codice. Il lettore attento noterà che i numeri doppi vengono ancora memorizzati come proprietà. Se la profilazione indica che ne vale la pena, la modifica della posizione in un array di dati doppi o in un array di dati digitati ridurrà ulteriormente il numero di oggetti creati.

Epilogo

Gli sviluppatori di Oz non si sono fermati qui. Armati degli strumenti e delle tecniche condivisi con loro dai detective V8, sono stati in grado di trovare alcune altre funzioni bloccate nell'inferno della disottimizzazione e fattore di calcolo del codice di calcolo in funzioni foglia che sono state ottimizzate, ottenendo prestazioni ancora migliori.

Esci e inizia a risolvere alcuni crimini legati alla performance.