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 sono state notevolmente velocizzate. Molte applicazioni ora funzionano abbastanza velocemente, tanto che ho sentito alcuni sviluppatori chiedersi ad alta voce: "Il web è abbastanza veloce?". Per alcune applicazioni potrebbe esserlo, ma sappiamo che non è abbastanza veloce per gli sviluppatori che lavorano su applicazioni ad alte prestazioni. Nonostante gli straordinari progressi della tecnologia delle macchine virtuali JavaScript, un recente studio ha dimostrato che le applicazioni Google trascorrono tra il 50% e il 70% del loro tempo all'interno di V8. La tua applicazione ha un tempo limitato, quindi ridurre i cicli di un sistema significa che un altro sistema può fare di più. Ricorda che le applicazioni che funzionano a 60 fps hanno solo 16 ms per frame, altrimenti si verificano jank. Continua a leggere per scoprire come ottimizzare JavaScript e profilare le applicazioni JavaScript, in una storia di prima mano dei detective delle prestazioni del team V8 che rintracciano un oscuro problema di prestazioni in Find Your Way to Oz.

Sessione Google I/O 2013

Ho presentato questo materiale al Google I/O 2013. Guarda il video di seguito:

Perché il rendimento è importante?

I cicli della CPU sono un gioco a somma zero. Se riduci l'utilizzo di una parte del sistema, puoi utilizzarne di più in un'altra o migliorare il funzionamento complessivo. Spesso, l'esecuzione più rapida e la possibilità di fare di più sono obiettivi in competizione. Gli utenti richiedono nuove funzionalità, ma si aspettano anche che la tua applicazione funzioni in modo più fluido. Le macchine virtuali JavaScript continuano ad aumentare di velocità, ma questo non è un motivo per ignorare i problemi di prestazioni che puoi risolvere oggi, come già sanno i molti sviluppatori che si occupano di problemi di prestazioni nelle loro applicazioni web. Nelle applicazioni in tempo reale con una frequenza fotogrammi elevata, la necessità di evitare il jitter è fondamentale. Insomniac Games ha realizzato uno studio che ha dimostrato che una frequenza fotogrammi stabile e sostenuta è importante per il successo di un gioco: "Una frequenza fotogrammi stabile è ancora un segno di un prodotto professionale e ben realizzato". Sviluppatori web, prendete nota.

Risolvere i problemi di prestazioni

Risolvere un problema di prestazioni è come risolvere un crimine. Devi esaminare attentamente le prove, controllare le cause sospette e sperimentare diverse soluzioni. Durante tutto il processo, devi documentare le misurazioni per assicurarti di aver effettivamente risolto il problema. Esiste una differenza minima tra questo metodo e il modo in cui i detective risolvono un caso. I detective esaminano le prove, interrogano i sospetti ed eseguono esperimenti nella speranza di trovare la prova schiacciante.

V8 CSI: Oz

I fantastici maghi che hanno creato Find Your Way to Oz si sono rivolti al team V8 per un problema di prestazioni che non riuscivano a risolvere autonomamente. A volte Oz si bloccava, causando un comportamento discontinuo. Gli sviluppatori di Oz avevano effettuato alcuni accertamenti iniziali utilizzando il riquadro Spostamenti in Chrome DevTools. Esaminando l'utilizzo della memoria, hanno riscontrato il temuto grafico a dente di sega. Una volta al secondo, il garbage collector raccoglieva 10 MB di dati inutili e le interruzioni della raccolta corrispondevano al jitter. Come nello screenshot seguente della cronologia in Chrome DevTools:

Cronologia di DevTools

I detective V8, Jakob e Yang, si sono occupati della questione. Si è trattato di un lungo scambio tra Jakob e Yang del team V8 e del team Oz. Ho riassunto questa conversazione negli eventi importanti che hanno contribuito a individuare il problema.

Prove

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

Di che tipo di applicazione stiamo parlando?

La demo di Oz è un'applicazione 3D interattiva. Per questo motivo, è molto sensibile alle interruzioni causate dalle raccolte dei rifiuti. Ricorda che un'applicazione interattiva a 60 FPS ha 16 ms per eseguire tutte le operazioni JavaScript e deve lasciare un po' di tempo a Chrome per elaborare le chiamate grafiche e disegnare lo schermo.

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

Che tipo di problema di rendimento stiamo riscontrando?

Vediamo delle interruzioni, ovvero cali di frame, ovvero "jerk". Queste interruzioni sono correlate alle esecuzioni della raccolta dei rifiuti.

Gli sviluppatori seguono le best practice?

Sì, gli sviluppatori di Oz sono esperti di tecniche di ottimizzazione e miglioramento delle prestazioni delle VM JavaScript. È interessante notare che gli sviluppatori di Oz utilizzavano CoffeeScript come linguaggio di origine e producevano codice JavaScript tramite il compilatore CoffeeScript. Ciò ha reso alcune indagini più complicate a causa della disconnessione tra il codice scritto dagli sviluppatori di Oz e quello utilizzato da V8. Chrome DevTools ora supporta le mappe di origine, il che avrebbe semplificato la procedura.

Perché viene eseguito il garbage collector?

La memoria in JavaScript viene gestita automaticamente per lo sviluppatore dalla VM. V8 utilizza un sistema di garbage collection comune in cui la memoria è suddivisa in due (o più) generazioni. La generazione giovane contiene gli oggetti allocati di recente. Se un oggetto sopravvive a lungo, viene spostato nella vecchia generazione.

I dati della generazione giovane vengono raccolti con una frequenza molto più elevata rispetto a quelli della generazione precedente. Questo è intenzionale, in quanto la raccolta delle giovani generazioni è molto più economica. Spesso è possibile presumere che le interruzioni frequenti del GC siano causate dalla raccolta della generazione giovane.

In V8, lo spazio di memoria giovane è suddiviso in due blocchi di memoria contigui di dimensioni uguali. In un determinato momento è in uso solo uno di questi due blocchi di memoria, chiamato spazio di destinazione. Se lo spazio to ha ancora memoria, l'allocazione di un nuovo oggetto è economica. Un cursore nello spazio a viene spostato in avanti del numero di byte necessari per il nuovo oggetto. Questo continua fino a quando lo spazio non è esaurito. A questo punto il programma viene interrotto e inizia la raccolta.

Memoria giovane V8

A questo punto, lo spazio da e lo spazio a vengono scambiati. Lo spazio to, che ora è lo spazio from, viene sottoposto a scansione dall'inizio alla fine e tutti gli oggetti ancora attivi vengono copiati nello spazio to o vengono promossi nell'heap della vecchia generazione. Per maggiori dettagli, ti consiglio di leggere l'articolo sull'algoritmo di Cheney.

Intuitivamente dovresti capire che ogni volta che un oggetto viene allocato implicitamente o esplicitamente (tramite una chiamata a new, [], o {}) la tua applicazione si avvicina sempre di più a una raccolta dei rifiuti e alla temuta interruzione dell'applicazione.

È previsto un traffico di dati inutili di 10 MB/sec per questa applicazione?

In breve, no. Lo sviluppatore non fa nulla per aspettarsi 10 MB/sec di dati inutili.

Sospettati

La fase successiva dell'indagine consiste nel determinare i potenziali sospetti e poi ridurli al minimo.

Sospetto 1

Chiamata di un nuovo elemento durante il frame. Ricorda che ogni oggetto allocato ti avvicina sempre di più a una pausa GC. In particolare, le applicazioni che funzionano a frequenze fotogrammi elevate devono cercare di avere zero allocazioni per frame. In genere, questo richiede un sistema di riciclo degli oggetti ben studiato e specifico per l'applicazione. I detective V8 hanno controllato con il team di Oz e non hanno segnalato nulla di nuovo. Infatti, il team di Oz era già a conoscenza di questo requisito e ha detto: "Sarebbe imbarazzante". Cancella questa voce dall'elenco.

Sospetto 2

Modifica della "forma" di un oggetto al di fuori del costruttore. Questo accade ogni volta che una nuova proprietà viene aggiunta a un oggetto al di fuori del costruttore. Viene creata una nuova classe nascosta per l'oggetto. Quando il codice ottimizzato rileva questo nuovo livello nascosto, viene attivata la disattivazione e il codice non ottimizzato viene eseguito finché non viene classificato come hot e ottimizzato di nuovo. Questo abbandono di ottimizzazione e re-ottimizzazione comporterà un calo,ma non è strettamente correlato alla creazione eccessiva di dati inutilizzati. Dopo un'attenta verifica del codice, è stato confermato che le forme degli oggetti erano statiche, pertanto il sospetto 2 è stato escluso.

Sospetto 3

Aritmetica in codice non ottimizzato. In un codice non ottimizzato, tutti i calcoli generano l'allocazione di oggetti effettivi. Ad esempio, questo snippet:

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

Il risultato è la creazione di 5 oggetti HeapNumber. I primi tre sono per le variabili a, b e c. Il quarto è per il valore anonimo (a * b) e il quinto è da #4 * c; il quinto viene infine assegnato a point.x.

Oz esegue migliaia di queste operazioni per frame. Se uno di questi calcoli si verifica in funzioni che non vengono mai ottimizzate, potrebbe essere la causa dei dati inutilizzati. Perché i calcoli non ottimizzati allocano memoria anche per i risultati temporanei.

Sospetto 4

Memorizzazione di un numero a doppia precisione in una proprietà. È necessario creare un oggetto HeapNumber per memorizzare il numero e la proprietà modificata in modo che punti a questo nuovo oggetto. La modifica della proprietà in modo che punti a HeapNumber non produrrà dati inutilizzati. Tuttavia, è possibile che siano presenti molti numeri a doppia precisione archiviati come proprietà degli oggetti. Il codice è pieno di istruzioni come la seguente:

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

Nel codice ottimizzato, ogni volta che a x viene assegnato un valore appena calcolato, un'istruzione apparentemente innocua, viene allocato implicitamente un nuovo oggetto HeapNumber, avvicinandoci a una pausa della raccolta dei rifiuti.

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

Il sospetto numero 4 è una possibilità.

Servizi forensi

A questo punto i detective hanno due possibili sospetti: la memorizzazione di numeri dell'heap come proprietà degli oggetti e il calcolo aritmetico all'interno di funzioni non ottimizzate. Era giunto il momento di andare in laboratorio e stabilire definitivamente quale sospetto era colpevole. NOTA: in questa sezione utilizzerò una riproduzione del problema rilevato nel codice sorgente effettivo di Oz. Questa riproduzione è di ordini di grandezza inferiore rispetto al codice originale, quindi è più facile da analizzare.

Esperimento 1

Controllo del sospetto 3 (calcolo aritmetico all'interno di funzioni non ottimizzate). Il motore JavaScript V8 ha un sistema di logging integrato che può fornire informazioni preziose su cosa succede sotto il cofano.

Se Chrome non è in esecuzione, avvialo con i flag:

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

e poi chiudendo completamente Chrome verrà generato un file v8.log nella directory corrente.

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

Dopo aver compilato correttamente la versione 8, puoi elaborare il log utilizzando il processore di tick:

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

Sostituisci mac o windows con linux a seconda della tua piattaforma. Questo strumento deve essere eseguito dalla directory di origine di primo livello in v8.

Il gestore dei tick mostra una tabella di testo delle funzioni JavaScript che hanno registrato il maggior numero di tick:

[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

Puoi vedere che demo.js aveva tre funzioni: opt, unopt e main. Le funzioni ottimizzate sono precedute da un asterisco (*) accanto al nome. Tieni presente che la funzione opt è ottimizzata e unopt non è ottimizzata.

Un altro strumento importante nella cassetta degli attrezzi di V8 Detective è plot-timer-event. Può essere eseguito nel seguente modo:

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

Dopo l'esecuzione, nella directory corrente è presente un file png denominato timer-events.png. Dopo averlo aperto, dovresti vedere qualcosa di simile al seguente:

Eventi timer

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

Asse Y degli eventi timer

La riga V8.Execute contiene una linea verticale nera disegnata in corrispondenza di ogni tick del profilo in cui V8 stava eseguendo il codice JavaScript. V8.GCScavenger presenta una linea verticale blu disegnata in corrispondenza di ogni segno del profilo in cui V8 stava eseguendo una raccolta di nuova generazione. Analogamente per il resto degli stati V8.

Una delle righe più importanti è "Tipo di codice in esecuzione". Sarà verde quando viene eseguito il codice ottimizzato e di colore rosso e blu quando viene eseguito il codice non ottimizzato. Lo screenshot seguente mostra la transizione da codice ottimizzato a non ottimizzato e poi di nuovo a codice ottimizzato:

Tipo di codice in esecuzione

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

Se hai fatto tutto questo, è bene sapere che puoi lavorare molto più velocemente eseguendo il refactoring dell'applicazione in modo che possa essere eseguita nella shell di debug v8: d8. L'utilizzo di d8 consente di ottenere tempi di iterazione più rapidi con gli strumenti tick-processor e plot-timer-event. Un altro effetto collaterale dell'utilizzo di d8 è che diventa più facile isolare il problema effettivo, riducendo la quantità di rumore presente nei dati.

Osservando il grafico degli eventi timer del codice sorgente di Oz, è stata mostrata una transizione da codice ottimizzato a codice non ottimizzato e, durante l'esecuzione del codice non ottimizzato, sono state attivate molte raccolte di nuova generazione, come nel seguente screenshot (nota che il tempo è stato rimosso al centro):

Grafico degli eventi timer

Se guardi attentamente, puoi vedere che le linee nere che indicano quando V8 sta eseguendo il codice JavaScript mancano esattamente negli stessi istanti dei tick del profilo delle raccolte di nuova generazione (linee blu). Questo dimostra chiaramente che, durante la raccolta dei rifiuti, lo script viene messo in pausa.

Esaminando l'output del processore di tick dal codice sorgente di Oz, la funzione principale (updateSprites) non è stata ottimizzata. In altre parole, anche la funzione in cui il programma ha impiegato più tempo non era ottimizzata. Ciò indica chiaramente che il sospetto 3 è il colpevole. La sorgente di updateSprites conteneva loop simili a questi:

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

Conoscendo V8 così bene, hanno subito riconosciuto che la struttura del ciclo for-i-in a volte non è ottimizzata da V8. In altre parole, se una funzione contiene un costrutto di ciclo for-i-in, potrebbe non essere ottimizzata. Al momento si tratta di un caso speciale e probabilmente cambierà in futuro, ovvero un giorno V8 potrebbe ottimizzare questa struttura di loop. Dato che non siamo esperti di V8 e non conosciamo V8 come le nostre tasche, come possiamo determinare perché updateSprites non è stato ottimizzato?

Esperimento 2

Esegui Chrome con questo flag:

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

viene visualizzato un log dettagliato dei dati di ottimizzazione e deottimizzazione. Cercando gli updateSprite nei dati, troviamo:

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

Proprio come ipotizzato dai detective, il motivo era la struttura del ciclo for-i-in.

Richiesta chiusa

Dopo aver scoperto il motivo per cui updateSprites non era ottimizzato, la correzione è stata semplice: basta spostare il calcolo nella relativa 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, il che comporterà un numero molto inferiore di oggetti HeapNumber e quindi interruzioni GC meno frequenti. Dovresti riuscire a confermarlo facilmente eseguendo gli stessi esperimenti con un nuovo codice. Il lettore attento noterà che i numeri doppi vengono ancora memorizzati come proprietà. Se il profiling indica che ne vale la pena, la modifica di position in modo che sia un array di doppi o un array di dati con tipi ridurrebbe ulteriormente il numero di oggetti creati.

Epilogo

Gli sviluppatori di Oz non si sono fermati qui. Grazie agli strumenti e alle tecniche condivisi con loro dai detective di V8, sono riusciti a trovare altre funzioni bloccate nell'inferno della deottimizzazione e hanno suddiviso il codice di calcolo in funzioni di primo livello ottimizzate, con un conseguente miglioramento delle prestazioni.

Inizia a risolvere alcuni problemi di prestazioni.