読者です 読者をやめる 読者になる 読者になる

Go言語のpprofとFlameGraph

CODEVS Go

Go pprof 入門編 (CPU Profile とコマンドラインツール) : KLabGames Tech Blog

Go で利用できるプロファイリングツール pprof の読み方 - Qiita

GolangでFlame Graphを描く | SOTA

GitHub - pkg/profile: Simple profiling for Go

GitHub - uber/go-torch: Stochastic flame graph profiler for Go programs

GitHub - brendangregg/FlameGraph: stack trace visualizer

上記のリンクを参考に先日行われたCODEVSforSTUDENTのプログラムのFlameGraphをだします

予選落ち(全体25位学生18位)しましたが、決勝進出者のプログラム提出日はまだ先なので、細かいことは書きません。

CODE VS for STUDENT 予選7位! - ぴろずメモ

www.youtube.com

pkg/profile

Go言語には標準にプロファイル用のruntime/pprofnet/http/pprofがありますが、runtime/pprofを使いやすくした、Dave Cheney氏のpkg/profileを使います。(元runtime/pprof)

go get github.com/pkg/profile

インストールしてmain関数に1行加えるだけです。

import "github.com/pkg/profile"

func main() {
    defer profile.Start().Stop()
    ...
}

テストには実際の試合の入力ログを使いますが、試合終了のフラグがないのでログの最後にENDを加えて、ソースコードも正常終了させるように変更しておきます。

実際にビルドして、実行します。

[fmhr@Sarah] ~/Dropbox/projects/CODEVS/CODEVSforSTUDENT/go
% go build -o tmp/outprofile src/*.go                                       
[fmhr@Sarah] ~/Dropbox/projects/CODEVS/CODEVSforSTUDENT/go
% tmp/outprofile < sampleInput/1P_20161111_135322_00000000000000000000_00003_stdin.txt
2016/11/21 14:30:43 profile: cpu profiling enabled, /tmp/profile918389017/cpu.pprof
fmhr
W: 4000 H: 5 s: 2000
[1 1 8 8 11]
0(0)0 / 0(0)0
0 0
0 turn: -180 / 180
[1 6 7 11 20]
3(0)0 / 3(0)0
5 0
1 turn: 1.64 / 178.36
[4 4 8 20 16]
6(0)0 / 6(0)0
6 1
()
40 turn: 0.014 / 102.107
GAMEOVER
0 0
41 turn: 0.006 / 102.101
SetTurnSet失敗
2016/11/21 14:32:16 profile: cpu profiling disabled, /tmp/profile918389017/cpu.pprof

デバッグ用のエラー出力と試合用の出力も入ってます(この試合は40ターン目で負けたみたいです)SetTurnSet失敗が追加したENDを読み込んでループから抜けています。

とりあえず、/tmp/profile918389017/cpu.pprofができてることが1行目でわかる。 これを見てみます。

% go tool pprof /tmp/profile918389017/cpu.pprof    
Entering interactive mode (type "help" for commands)
(pprof) top5
79.84s of 98.22s total (81.29%)
Dropped 130 nodes (cum <= 0.49s)
Showing top 5 nodes out of 58 (cum >= 2.62s)
      flat  flat%   sum%        cum   cum%
    56.09s 57.11% 57.11%     66.24s 67.44%  main.deleteLoop
     9.67s  9.85% 66.95%      9.67s  9.85%  runtime.duffcopy
     7.25s  7.38% 74.33%      7.45s  7.59%  main.moveBlock
     4.21s  4.29% 78.62%      6.93s  7.06%  runtime.scanobject
     2.62s  2.67% 81.29%      2.62s  2.67%  math/rand.(*rngSource).Seed
(pprof) 

main.deleteLoop関数が実行時間の6割を占めてるのがわかります。 この関数はゲーム内のフィールドを縦横斜め(2回)を走査して、消えるブロックがなくなるまでループする、ゲームのシミュレータの主要部分です。 (pprof) web をするとグラフにしてくれるのですが見え過ぎるで今回はお預けします。

この結果を使って、FlameGraphをみてみます。

Go言語のpprofからflame graphを見るためには、uber/go-torchを使います。

GitHub - uber/go-torch: Stochastic flame graph profiler for Go programs

go get github.com/uber/go-torch
[fmhr@Sarah] ~/Dropbox/projects/CODEVS/CODEVSforSTUDENT/go
% cd /tmp/profile918389017        
[fmhr@Sarah] /tmp/profile918389017
% ls
cpu.pprof
[fmhr@Sarah] /tmp/profile918389017
% go-torch cpu.pprof 
INFO[15:09:41] Run pprof command: go tool pprof -raw -seconds 30 cpu.pprof
FATA[15:09:41] Failed: could not generate flame graph: Cannot find flamegraph scripts in the PATH or current directory. You can download the script at https://github.com/brendangregg/FlameGraph. These scripts should be added to your PATH or in the directory where go-torch is executed. Alternatively, you can run go-torch with the --raw flag.

肝心のflame graphがはいってませんでした。 PATHかディレクトリにスクリプトを入れろと言われてます。今回は必要なスクリプトだけつっこんでおきます。

[fmhr@Sarah] /tmp/profile918389017
% wget https://raw.githubusercontent.com/brendangregg/FlameGraph/master/stackcollapse-perf.pl
% wget https://raw.githubusercontent.com/brendangregg/FlameGraph/master/flamegraph.pl

パーミションを変更して実行可能にします

% chmod 777 flamegraph.pl stackcollapse-perf.pl 

これで準備完了です。

flame graph

[fmhr@Sarah] /tmp/profile918389017
% go-torch cpu.pprof                           
INFO[15:18:02] Run pprof command: go tool pprof -raw -seconds 30 cpu.pprof
INFO[15:18:02] Writing svg to torch.svg

目的のtorch.svgがでてきました。 (hatenablogにsvgファイルが出せないようなので、jpegに変換してます) f:id:fmhr29:20161121153128j:plain おしまい