2016-02-02 14 views
8

Pracuję nad optymalizacją kodu, który analizuje dane z wykresów społecznych (z dużą pomocą od https://blog.golang.org/profiling-go-programs) i udało mi się przerobić wiele powolny kod.Jak zoptymalizować program golang, który spędza najwięcej czasu w runtime.osyield i runtime.usleep

Wszystkie dane są ładowane do pamięci z db pierwszy, a analiza danych z pojawia CPU związany (max zużycie pamięci < 10MB, CPU1 @ 100%)

Ale teraz większość czasu mój program wydaje się być w runtime.osyield i runtime.usleep. W jaki sposób temu zapobiec?

Ustawiłem GOMAXPROCS = 1, a kod nie odradza żadnych goroutines (innych niż te, które mogą wywoływać biblioteki golang).

To moje wyjście top10 z 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) 

W _/C_/code/sc_proto/* funkcje mojego kodu.

a wyjście z sieci: output from web

(lepsza wersja SVG wykresu tutaj: https://goo.gl/Tyc6X4)

+1

Twoje wykresy są nieczytelne. Nie mów nam, co robi twój program. [Jak utworzyć przykład minimalny, pełny i sprawdzalny.] (Http://stackoverflow.com/help/mcve). – peterSO

+0

Czy używasz cgo? – JimB

+0

@ JimB nie używa cgo; wszystko czysto Go – Aaron

Odpowiedz

5

znaleźć odpowiedź sam, więc jestem delegowania to tutaj dla każdego, kto jest posiadanie podobny problem. Specjalne podziękowania dla @ Jimb za wysłanie mnie właściwą drogą.

Jak widać na wykresie, ścieżki prowadzące do osyield i usleep są procedurami czyszczenia pamięci. Ten program korzystał z połączonej listy, która generowała dużo wskaźników, co spowodowało wiele pracy dla gc, co czasami blokowało wykonywanie mojego kodu, podczas gdy ja sprzątał mój bałagan.

Ostatecznie rozwiązanie tego problemu pochodzi z https://software.intel.com/en-us/blogs/2014/05/10/debugging-performance-issues-in-go-programs (co było niesamowitym źródłem Btw). Postępowałem zgodnie z instrukcjami dotyczącymi profilera pamięci; a zalecenie zastąpienia kolekcji wskaźników za pomocą plasterków wyjaśniło moje problemy ze zbieraniem śmieci, a mój kod jest teraz znacznie szybszy!

+0

Który sterownik SQL? (Przy okazji stwierdzam również, że skumulowany wynik jest pomocny, ponieważ pokazuje czas w wywołaniach funkcji bardziej przypominający stos wywołań) – JimB

+0

Sterownik to sterownik Go-SQL na: https://github.com/go-sql -driver/mysql Doszedłem do wniosku, że mój sterownik bazy danych był wątkiem, który ustępował, ponieważ pod wyjściem pod adresem http: // localhost: 6060/debug/pprof/goroutine? debug = 1 widzę '1 @ 0x43079c 0x43086b 0x40487d 0x4043bb 0x5451ec 0x45f0e1 # \t 0x5451ec \t bazy danych/sql. (* DB) .connectionOpener + 0x4c \t C:/Go/src/database/sql/sql.przejść: 727' wraz z moim goroutine (obok komentarza) – 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_// kod sc_proto.main.func3 + 0x7a \t \t \t C: /code/sc_proto/main.go: # 887 \t 0x48dc02 \t _/C_// kod 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