2016-02-02 8 views
8

Ho lavorato sull'ottimizzazione del codice che analizza i dati dei social graph (con molto aiuto da https://blog.golang.org/profiling-go-programs) e ho rielaborato con successo molte codice lento.Come ottimizzare il programma golang che passa la maggior parte del tempo in runtime.osyield e runtime.usleep

Tutti i dati vengono caricati in memoria dal primo db, e l'analisi dei dati da lì appare CPU bound (il consumo di memoria max < 10MB, CPU1 @ 100%)

Ma ora la maggior parte del tempo del mio programma sembra essere in runtime.osyield e runtime.usleep. Qual è il modo per impedirlo?

Ho impostato GOMAXPROCS = 1 e il codice non genera alcuna goroutine (diversa da quella che le librerie golang possono chiamare).

Questa è la mia uscita dalla top10 pprof

(pprof) top10 
62550ms of 72360ms total (86.44%) 
Dropped 208 nodes (cum <= 361.80ms) 
Showing top 10 nodes out of 77 (cum >= 1040ms) 
     flat flat% sum%  cum cum% 
    20760ms 28.69% 28.69% 20850ms 28.81% runtime.osyield 
    14070ms 19.44% 48.13% 14080ms 19.46% runtime.usleep 
    11740ms 16.22% 64.36% 23100ms 31.92% _/C_/code/sc_proto/cloudgraph.(*Graph).LeafProb 
    6170ms 8.53% 72.89%  6170ms 8.53% runtime.memmove 
    4740ms 6.55% 79.44% 10660ms 14.73% runtime.typedslicecopy 
    2040ms 2.82% 82.26%  2040ms 2.82% _/C_/code/sc_proto.mAvg 
    890ms 1.23% 83.49%  1590ms 2.20% runtime.scanobject 
    770ms 1.06% 84.55%  1420ms 1.96% runtime.mallocgc 
    760ms 1.05% 85.60%  760ms 1.05% runtime.heapBitsForObject 
    610ms 0.84% 86.44%  1040ms 1.44% _/C_/code/sc_proto/cloudgraph.(*Node).DeepestChildren 
(pprof) 

I _/C_/codice/sc_proto/* funzioni sono il mio codice.

E l'uscita dal web: output from web

(meglio, la versione SVG di grafico qui: https://goo.gl/Tyc6X4)

+1

I tuoi grafici sono illeggibili. Non ci dici cosa sta facendo il tuo programma. [Come creare un esempio minimo, completo e verificabile.] (Http://stackoverflow.com/help/mcve). – peterSO

+0

Stai usando cgo? – JimB

+0

@JimB che non usa cgo; tutto puro Go – Aaron

risposta

5

trovato la risposta me, quindi sto postando questo qui per chiunque altro che sta avendo un problema simile E grazie speciale a @JimB per avermi inviato sulla strada giusta.

Come si può vedere dal grafico, i percorsi che portano a osyield e usleep sono routine di garbage collection. Questo programma utilizzava una lista collegata che generava molti puntatori, che creavano molto lavoro per il gc, che occasionalmente bloccava l'esecuzione del mio codice mentre puliva il mio casino.

In definitiva la soluzione a questo problema proveniva da https://software.intel.com/en-us/blogs/2014/05/10/debugging-performance-issues-in-go-programs (che era una risorsa eccezionale btw). Ho seguito le istruzioni sul profiler di memoria lì; e la raccomandazione di sostituire gli insiemi di puntatori con le porzioni risolve i problemi relativi alla raccolta dei rifiuti e il mio codice è molto più veloce ora!

+0

Quale driver SQL? (A proposito, trovo anche che l'output cumulativo sia utile, dal momento che mostra l'ora in funzione chiama più lo stack chiamate) – JimB

+0

Il driver è il driver Go-SQL all'indirizzo: https://github.com/go-sql -driver/mysql sono arrivato alla conclusione che il mio driver di database è stato il filo che stava cedendo perché sotto l'output all'indirizzo http: // localhost: 6060/debug/pprof/goroutine debug = 1 vedo '1 @ 0x43079c 0x43086b 0x40487d 0x4043bb 0x5451ec 0x45f0e1 # \t 0x5451ec \t database/sql. (* DB) .connectionOpener + 0x4c \t C:/Vai/src/database/sql/sql.andare: 727' insieme con la mia goroutine (commento successivo) – Aaron

+0

'1 @ 0x441d10 0x53447a 0x48ba79 0x48d7f7 0x48cfe5 0x49b7da 0x48dc02 0x49a8db 0x480e9f 0x45f0e1 # \t 0x53447a \t _/C_/code/sc_proto/cloudgraph (* Node) .AddChild + 0x8A. \t C: /code/sc_proto/cloudgraph/cloudgraph.go: 92 # \t 0x49b7da \t _/C_/code/sc_proto.main.func3 + 0x7A \t \t \t C: /code/sc_proto/main.go: 887 # \t 0x48dc02 \t _/C_/code/sc_proto.main + 0x1d2 \t \t \t \t C: /code/sc_proto/main.go: 908 # \t 0x49a8db \t _/C_/code/sc_proto.Test_main + 0x1b \t \t \t C: /code/sc_proto/main_test.go: 1002 # \t 0x480e9f \t testing.tRunner + 0x9F \t \t \t \t \t C:/go/src /testing/testing.go: 473' – Aaron

Problemi correlati