2016-05-21 19 views
4

Ich profile eine Go-Anwendung mit pprof.pprof CPU-Profil einer Go-Anwendung zeigt keine Beispiele

Die Anwendung verwendet etwa 4-10% CPU und lässt es für eine kurze Zeit läuft ein Profil von etwa 6-11kb. Dies deutet darauf hin, dass es in der Lage sein sollte, einige Aktivitäten zu probieren.

Wenn ich das Ergebnis zu sehen, aber ich sehe die folgende:

$ go tool pprof --text bigproc 
1.77s of 1.77s total ( 100%) 
     flat flat% sum%  cum cum% 
    1.77s 100% 100%  1.77s 100% 
$ 

Die interessanten Informationen erscheinen zu fehlen. Was könnte falsch sein?

Dies ist auf Linux, mit go Version 1.6.1 und pprof Version 2.2.1 von google-perftools (wenn das wichtig ist).

+1

Sie werden für eine Menge zu haben, probieren länger als 1,7 Sekunden, besonders bei nur 4-10% CPU. Probieren Sie einige Minuten lang. – JimB

+0

Ich lief den Prozess für so etwas wie eine Minute Wanduhrzeit. Ich nehme an, dass die 1.77 Sekunden, die in der Ausgabe erwähnt werden, CPU-Zeit sind, also die Zeit ausgenommen, in der die CPU im Leerlauf war (Programm wird blockiert oder schläft). Ich werde versuchen, länger zu laufen! –

+1

Wenn Sie ein Profil erstellen, betonen Sie normalerweise den Codepfad, den Sie erstellen, um so viele Beispiele wie möglich von dort zu erhalten, als eine Leerlauflaufzeit. Wenn Sie nur 4-10% CPU verwenden, werden 90-96% Ihrer Proben nicht gut sein. – JimB

Antwort

3

Sie verwenden die go tool pprof falsch, weil Sie die mit dem generierten Profil verknüpfte ausführbare Datei angeben müssen.

Vergleichen Sie dies

$ go tool pprof --text cpuprofile.prof 
680ms of 680ms total ( 100%) 
     flat flat% sum%  cum cum% 
    680ms 100% 100%  680ms 100% 

mit diesem (beachten Sie main, das ist die ausführbare Datei, die die cpuprofile.prof produziert)

$ go tool pprof --text main cpuprofile.prof 
680ms of 680ms total ( 100%) 
     flat flat% sum%  cum cum% 
    350ms 51.47% 51.47%  610ms 89.71% main.renderMandelbrotUnified 
    130ms 19.12% 70.59%  130ms 19.12% math.Log 
     40ms 5.88% 76.47%  60ms 8.82% image.(*RGBA).Set 
[cut] 

Es ist nicht eine Frage der falschen Probenahme: bedenkt, dass rund 100 Proben entnommen werden jede Sekunde der Ausführung, also sogar von 1.7s sollten Sie trotzdem einige Proben bekommen (from here):

Wenn die CPU Profilerstellung aktiviert ist, stoppt das Go-Programm über 100 Mal pro Sekunde und zeichnet eine Probe auf der Programmzähler aus der zur Zeit goroutine Stack

Ausführung
+0

Danke, ich fühle mich so dumm! Ich tröste mich mit der Tatsache, dass ich nicht alleine bin: https://github.com/golang/go/issues/10863 :) –

+0

Ja, mach dir keine Sorgen, passierte mir auch und ich hatte das Glück, es zu bemerken es vor dem Posten auf SO! : D – AkiRoss

+1

Ich hoffe, https: //go-review.googlesource.com#/c/23323/ wird es in irgendeiner Form schaffen, so dass wir zukünftigen Generationen diese Verwirrung ersparen –