2015-01-08 23 views
6

Provo a fare un po 'di profiling nodejs utilizzando Linux perf_events come descritto da Brendan Gregg here.Eventi sconosciuti in nodejs/v8 flamegraph usando perf_events

flusso di lavoro è la seguente:

  1. nodo run> 0.11.13 con --perf-basic-prof, che crea /tmp/perf-(PID).map file in cui vengono scritti mappatura simbolo JavaScript.
  2. pile acquisire utilizzando perf record -F 99 -p `pgrep -n node` -g -- sleep 30
  3. pile Fold utilizzando stackcollapse-perf.pl script da this repository
  4. Genera grafico fiamma svg utilizzando flamegraph.pl di script

ottengo risultato seguente (che sembrano davvero bello all'inizio): enter image description here

Il problema è che ci sono molti elementi [unknown], che suppongo dovrebbero essere il mio nodejs funct chiamate di ioni. Presumo che l'intero processo fallisca nel punto 3, dove i dati perf dovrebbero essere piegati usando le mappature generate da node/v8 eseguite con --perf-basic-prof. Il file /tmp/perf-PID.map viene creato e alcuni mapping vengono scritti durante l'esecuzione del nodo.

Come risolvere questo problema?

Sto usando CentOS 6.5 x64 e ho già provato questo con il nodo 0.11.13, 0.11.14 (sia pre-compilato che compilato) senza successo.

risposta

13

In primo luogo, cosa significa "[sconosciuto]" significa che il campionatore non è in grado di capire il nome della funzione, poiché è una funzione di sistema o libreria. Se è così, va bene - non ti interessa, perché stai cercando cose responsabili per il tempo in il tuo codice, non il codice di sistema.

In realtà, sto suggerendo che questo è uno di quelli XY questions. Anche se ottieni una risposta diretta a ciò che hai chiesto, è probabile che sia poco utile. Qui ci sono le ragioni per le quali:

1. Profiling CPU è di scarsa utilità in un programma di I bound/O

Le due torri a sinistra nel grafico fiamme stanno facendo I/O, in modo che probabilmente impiegheresti molto più tempo al muro rispetto alla grande pila sulla destra. Se questo grafico fiamma sono stati ricavati da campioni di parete a tempo, piuttosto che campioni di CPU in tempo, potrebbe sembrare più simile al secondo grafico qui sotto, che ti dice dove il tempo va in realtà:

enter image description here

Quello che era un il grande mucchio dall'aspetto succoso sulla destra si è ristretto, quindi non è neanche lontanamente significativo. D'altra parte, le torri I/O sono molto larghe. Qualsiasi di quelle strisce arancioni larghe, se è nel codice, rappresenta una possibilità di risparmiare molto tempo, se alcuni degli I/O potrebbero essere evitati.

2.Se il programma è del CPU o I/O-bound, opportunità SpeedUp possono facilmente nascondersi da grafici di fiamma

Supponiamo che ci sia qualche funzione Foo che in realtà sta facendo qualcosa di spreco, che se si sapeva su di esso, si potrebbe risolvere il problema. Supponiamo nel grafico della fiamma, è un colore rosso scuro. Supponiamo che sia chiamato da numerosi punti nel codice, quindi non è tutto raccolto in un punto nel grafico della fiamma. Piuttosto appare in più piccoli luoghi indicati qui da contorni neri:

enter image description here

Avviso, se sono stati raccolti tutti quei rettangoli, si vedeva che rappresenta il 11% del tempo, il che significa che vale la pena guardare . Se riuscissi a dimezzare il tempo, potresti risparmiare complessivamente il 5,5%. Se quello che sta facendo potrebbe essere evitato del tutto, si potrebbe risparmiare l'11% complessivo. Ciascuno di quei piccoli rettangoli si ridurrebbe a zero e trascinerebbe il resto del grafico alla sua destra, con esso.

Ora ti mostrerò the method I use. Prendo un numero moderato di campioni di stack casuali ed esamino ciascuno per le routine che potrebbero essere velocizzate. corrispondente al prelievo di campioni nel grafico fiamma in questo modo:

enter image description here

Le linee verticali sottili rappresentano venti campioni pila casuale tempo. Come puoi vedere, tre di questi sono contrassegnati con un X. Questi sono quelli che passano attraverso Foo. Questo è il numero giusto, perché l'11% delle volte 20 è 2.2.

(Confuso? OK, ecco un po 'di probabilità per te. Se lanci una moneta 20 volte, e ha una probabilità dell'11% di venire in testa, quante teste potresti ottenere? Tecnicamente è una distribuzione binomiale. più probabile numero che si ottiene è 2, i prossimi numeri più probabili sono 1 e 3. (Se si ottiene solo 1 si andare avanti fino ad arrivare 2.) Ecco la distribuzione :)

enter image description here

(The il numero medio di campioni da prendere per vedere Foo due volte è 2/0,11 = 18,2 campioni.)

Guardare quei 20 campioni potrebbe sembrare un po 'scoraggiante, perché corrono tra i 20 ei 50 livelli di profondità. Tuttavia, puoi fondamentalmente ignorare tutto il codice che non è il tuo. Basta esaminarli per il codice. Vedrai esattamente come passi il tempo, e avrai una misurazione molto approssimativa di quanto. Gli stack profondi sono sia cattive notizie che buone notizie - significano che il codice potrebbe avere un sacco di spazio per gli speedups, e che ti mostrano cosa sono.

Qualsiasi cosa si vede che si potrebbe accelerare, se si vede su più di un campione, vi darà una sana accelerazione, garantita. Il motivo per cui è necessario vederlo su più di un campione è, se lo vedi solo su un campione, sai solo che il suo tempo non è zero. Se la vedi su più di un campione, non sai ancora quanto tempo ci vuole, ma sai che non è piccolo. Here are the statistics.

+0

Kamil Z può provare profiling off-cpu, se il il compito è legato all'I/O, Gregg ha appena pubblicato gli script - http://stackoverflow.com/a/28784580/196561 Inoltre, prendendo "campioni di casuali" (ad esempio con gdb, o anche con 'perf record -g', quindi 'perf script' per afferrare campioni di pila grezza, quindi prendere diversi stack casuali per l'esame manuale) potrebbe non essere d'aiuto qui perché 1) potrebbe essere difficile collegarli a programmi di breve durata (Tracing with LTTng può aiutare lì ...) 2) gdb (o perf record) continua a non riportare i nomi dei simboli, ancora il problema Y chiesto da Kamil. Il debugger interno node.js/v8 può aiutare a risolverli. – osgx

+0

@osgx: con il campionamento manuale, non devi preoccuparti se il suo I/O è legato o meno, funziona allo stesso modo. Non devi preoccuparti se una routine è di breve durata - se viene chiamata un numero di volte sufficiente per utilizzare una frazione significativa di tempo, i campioni la colpiscono. (Se l'intero programma termina troppo velocemente per campionare, quello che faccio è aggiungere un ciclo esterno temporaneo.) Sto assumendo che si trovi nella posizione di un programmatore, con codice sorgente e un debugger. Per altre situazioni non sto offrendo consigli. –

+0

@MikeDunlavey Il primo punto non mi è chiaro. Questo problema non si verifica solo quando il thread che viene profilato è lo stesso thread che genera gli esempi? In altre parole, la ragione per cui il primo grafico non mostra il tempo di attesa I/O è che è in attesa e non è stato possibile registrare alcun campione. D'altra parte, se un altro thread sta generando i campioni, avrebbe catturato tutto il tempo di attesa e di elaborazione del thread di destinazione e il secondo grafico sarebbe stato generato. –

8

In generale è una cattiva idea non essere d'accordo con un esperto in materia ma (con il massimo rispetto) eccoci qui!

sollecita quindi la risposta di fare quanto segue: "! Si prega di essere sicuri di rispondere alla domanda Fornire informazioni e condividere la vostra ricerca"

Quindi la domanda era, almeno la mia interpretazione, perché ci sono [incognite] fotogrammi nell'output di script perf (e come posso trasformare questi frame [sconosciuti] in nomi significativi? Questa domanda potrebbe essere essere su "come migliorare le prestazioni del mio sistema?" ma non lo vedo in questo caso particolare. C'è un vero problema qui su come i dati perf record sono stati postati.

La risposta alla domanda è che, sebbene il presupposto impostato è corretto: la versione nodo corretta, l'argomento corretta era presente per generare i nomi delle funzioni (--perf-base-prof), generato perf mappa il file deve essere di proprietà di root affinché lo script perf produca l'output previsto.

Questo è tutto!

Scrivere alcuni nuovi script oggi ho colpito apon questo indirizzandomi a questa domanda SO.

Ecco un paio di riferimenti aggiuntivi:

https://yunong.io/2015/11/23/generating-node-js-flame-graphs/

https://github.com/jrudolph/perf-map-agent/blob/d8bb58676d3d15eeaaf3ab3f201067e321c77560/bin/create-java-perf-map.sh#L22

[file non-root possono a volte essere costretti] http://www.spinics.net/lists/linux-perf-users/msg02588.html