The Go Blog

Go プログラムのプロファイリング

Russ Cox、2011年7月; Shenghou Ma による更新、2013年5月
2011年6月24日

Scala Days 2011 で、Robert Hundt は Loop Recognition in C++/Java/Go/Scala という論文を発表しました。この論文では、コンパイラのフロー解析パスで使用するような特定のループ検出アルゴリズムを C++、Go、Java、Scala で実装し、これらのプログラムを使用して、これらの言語における典型的なパフォーマンスの問題について結論を導き出しました。この論文で提示された Go プログラムはかなり遅く実行されるため、Go のプロファイリングツールを使用して遅いプログラムを高速化する方法を示す絶好の機会となりました。

Go のプロファイリングツールを使用して特定のボトルネックを特定し修正することで、Go のループ検出プログラムを1桁高速化し、メモリ使用量を6分の1に削減できます。 (更新: gcclibstdc++ の最近の最適化により、メモリ削減は現在3.7倍です。)

Hundt の論文は、彼が使用した C++、Go、Java、Scala ツールのバージョンを特定していません。このブログ投稿では、6g Go コンパイラの最新の週次スナップショットと、Ubuntu Natty ディストリビューションに付属している g++ のバージョンを使用します。(Java や Scala は使用しません。これらの言語で効率的なプログラムを書くスキルがないため、比較が不公平になるからです。C++ は論文で最速の言語であったため、ここでの C++ との比較で十分でしょう。) (更新: この更新された投稿では、amd64 上の Go コンパイラの最新の開発スナップショットと、2013年3月にリリースされた g++ の最新バージョン (4.8.0) を使用します。)

$ go version
go version devel +08d20469cc20 Tue Mar 26 08:27:18 2013 +0100 linux/amd64
$ g++ --version
g++ (GCC) 4.8.0
Copyright (C) 2013 Free Software Foundation, Inc.
...
$

プログラムは、3.4GHz Core i7-2600 CPU と 16 GB RAM を搭載し、Gentoo Linux の 3.8.4-gentoo カーネルを実行しているコンピュータで実行されます。このマシンは CPU 周波数スケーリングを無効にして実行しています。

$ sudo bash
# for i in /sys/devices/system/cpu/cpu[0-7]
do
    echo performance > $i/cpufreq/scaling_governor
done
#

C++ と Go で記述された Hundt のベンチマークプログラム を取得し、それぞれを単一のソースファイルに結合し、出力の1行を残してすべて削除しました。ユーザー時間、システム時間、実時間、最大メモリ使用量を示す形式で、Linux の time ユーティリティを使用してプログラムの時間を測定します。

$ cat xtime
#!/bin/sh
/usr/bin/time -f '%Uu %Ss %er %MkB %C' "$@"
$

$ make havlak1cc
g++ -O3 -o havlak1cc havlak1.cc
$ ./xtime ./havlak1cc
# of loops: 76002 (total 3800100)
loop-0, nest: 0, depth: 0
17.70u 0.05s 17.80r 715472kB ./havlak1cc
$

$ make havlak1
go build havlak1.go
$ ./xtime ./havlak1
# of loops: 76000 (including 1 artificial root node)
25.05u 0.11s 25.20r 1334032kB ./havlak1
$

C++ プログラムは 17.80 秒で実行され、700 MB のメモリを使用します。Go プログラムは 25.20 秒で実行され、1302 MB のメモリを使用します。(これらの測定値は論文の測定値と一致させるのが困難ですが、この投稿の目的は go tool pprof の使用方法を探ることであり、論文の結果を再現することではありません。)

Go プログラムのチューニングを開始するには、プロファイリングを有効にする必要があります。コードが Go テストパッケージのベンチマークサポートを使用している場合、gotest の標準的な -cpuprofile-memprofile フラグを使用できます。このスタンドアロンプログラムのように、runtime/pprof をインポートし、数行のコードを追加する必要があります。

var cpuprofile = flag.String("cpuprofile", "", "write cpu profile to file")

func main() {
    flag.Parse()
    if *cpuprofile != "" {
        f, err := os.Create(*cpuprofile)
        if err != nil {
            log.Fatal(err)
        }
        pprof.StartCPUProfile(f)
        defer pprof.StopCPUProfile()
    }
    ...

新しいコードは、cpuprofile というフラグを定義し、Go フラグライブラリを呼び出してコマンドラインフラグを解析し、cpuprofile フラグがコマンドラインで設定されている場合、そのファイルにリダイレクトされた CPU プロファイリングを開始します。プロファイラは、プログラムが終了する前にファイルへの保留中の書き込みをすべてフラッシュするために、StopCPUProfile を最後に呼び出す必要があります。defer を使用して、main が戻るときにこれが確実に行われるようにします。

このコードを追加した後、新しい -cpuprofile フラグを指定してプログラムを実行し、go tool pprof を実行してプロファイルを解釈できます。

$ make havlak1.prof
./havlak1 -cpuprofile=havlak1.prof
# of loops: 76000 (including 1 artificial root node)
$ go tool pprof havlak1 havlak1.prof
Welcome to pprof!  For help, type 'help'.
(pprof)

go tool pprof プログラムは、Google の pprof C++ プロファイラ のわずかなバリアントです。最も重要なコマンドは topN で、プロファイル内の上位 N 個のサンプルを表示します。

(pprof) top10
Total: 2525 samples
     298  11.8%  11.8%      345  13.7% runtime.mapaccess1_fast64
     268  10.6%  22.4%     2124  84.1% main.FindLoops
     251   9.9%  32.4%      451  17.9% scanblock
     178   7.0%  39.4%      351  13.9% hash_insert
     131   5.2%  44.6%      158   6.3% sweepspan
     119   4.7%  49.3%      350  13.9% main.DFS
      96   3.8%  53.1%       98   3.9% flushptrbuf
      95   3.8%  56.9%       95   3.8% runtime.aeshash64
      95   3.8%  60.6%      101   4.0% runtime.settype_flush
      88   3.5%  64.1%      988  39.1% runtime.mallocgc

CPU プロファイリングが有効になっている場合、Go プログラムは1秒あたり約100回停止し、現在実行中のゴルーチンのスタックにあるプログラムカウンタからなるサンプルを記録します。プロファイルには2525個のサンプルがあるため、25秒強実行されていました。go tool pprof の出力には、サンプルに表示された関数ごとに1行があります。最初の2つの列は、その関数が実行中であった (呼び出された関数の戻りを待っていたのではなく) サンプルの数を、生の値と全サンプルに対する割合として示します。runtime.mapaccess1_fast64 関数は298個のサンプル、つまり11.8%で実行中でした。top10 の出力は、このサンプル数でソートされます。3番目の列は、リスト中の累積合計を示します。最初の3行でサンプルの32.4%を占めます。4番目と5番目の列は、その関数が表示された (実行中または呼び出された関数の戻りを待っていた) サンプルの数を示します。main.FindLoops 関数はサンプルの10.6%で実行中でしたが、84.1%のサンプルでコールスタック上にありました (その関数またはそれが呼び出した関数が実行中でした)。

4番目と5番目の列でソートするには、-cum (累積用) フラグを使用します。

(pprof) top5 -cum
Total: 2525 samples
       0   0.0%   0.0%     2144  84.9% gosched0
       0   0.0%   0.0%     2144  84.9% main.main
       0   0.0%   0.0%     2144  84.9% runtime.main
       0   0.0%   0.0%     2124  84.1% main.FindHavlakLoops
     268  10.6%  10.6%     2124  84.1% main.FindLoops
(pprof) top5 -cum

実際には、main.FindLoopsmain.main の合計は100%であるべきでしたが、各スタックサンプルには下から100個のスタックフレームしか含まれません。サンプルの約4分の1の間、再帰的な main.DFS 関数は main.main よりも100フレーム以上深く、完全なトレースは切り捨てられました。

スタックトレースサンプルには、テキストリストが示す以上の関数呼び出し関係に関する興味深いデータが含まれています。web コマンドは、プロファイルデータのグラフを SVG 形式で書き込み、ウェブブラウザで開きます。(PostScript を書き込み、Ghostview で開く gv コマンドもあります。どちらのコマンドでも、graphviz がインストールされている必要があります。)

(pprof) web

完全なグラフの小さな断片は次のようになります。

グラフの各ボックスは1つの関数に対応しており、ボックスのサイズは、その関数が実行中であったサンプルの数に応じて決定されます。ボックス X からボックス Y へのエッジは、X が Y を呼び出すことを示します。エッジに沿った数値は、その呼び出しがサンプルに表示される回数です。再帰的な関数呼び出しのように、1つのサンプルに呼び出しが複数回表示される場合、各表示はエッジの重みに数えられます。これは、main.DFS から自身への自己エッジ上の21342を説明しています。

一見して、プログラムの多くの時間がハッシュ操作、つまり Go の map 値の使用に費やされていることがわかります。web に特定の関数、例えば runtime.mapaccess1_fast64 を含むサンプルのみを使用するように指示することで、グラフから一部のノイズをクリアできます。

(pprof) web mapaccess1

目を凝らすと、runtime.mapaccess1_fast64 への呼び出しが main.FindLoopsmain.DFS によって行われていることがわかります。

これで全体像が大まかに把握できたので、特定の関数に焦点を当てる時が来ました。まず main.DFS を見てみましょう。短い関数だからです。

(pprof) list DFS
Total: 2525 samples
ROUTINE ====================== main.DFS in /home/rsc/g/benchgraffiti/havlak/havlak1.go
   119    697 Total samples (flat / cumulative)
     3      3  240: func DFS(currentNode *BasicBlock, nodes []*UnionFindNode, number map[*BasicBlock]int, last []int, current int) int {
     1      1  241:     nodes[current].Init(currentNode, current)
     1     37  242:     number[currentNode] = current
     .      .  243:
     1      1  244:     lastid := current
    89     89  245:     for _, target := range currentNode.OutEdges {
     9    152  246:             if number[target] == unvisited {
     7    354  247:                     lastid = DFS(target, nodes, number, last, lastid+1)
     .      .  248:             }
     .      .  249:     }
     7     59  250:     last[number[currentNode]] = lastid
     1      1  251:     return lastid
(pprof)

このリストは DFS 関数のソースコード (実際には、正規表現 DFS に一致するすべての関数) を示しています。最初の3つの列は、その行を実行中に取得されたサンプル数、その行またはその行から呼び出されたコードで実行中に取得されたサンプル数、およびファイル内の行番号です。関連コマンド disasm は、ソースリストの代わりにその関数の逆アセンブリを表示します。十分なサンプルがある場合、どの命令が高価であるかを理解するのに役立ちます。weblist コマンドは2つのモードを混ぜています。行をクリックすると逆アセンブリが表示される ソースリスト を表示します。

時間がハッシュランタイム関数によって実装されたマップ検索に費やされていることがすでにわかっているので、2番目の列が最も重要です。再帰的なトラバーサルから予想されるように、時間の大部分は DFS への再帰呼び出し (247行目) に費やされます。再帰を除くと、時間は242行目、246行目、250行目の number マップへのアクセスに費やされているようです。その特定の検索の場合、マップは最も効率的な選択ではありません。コンパイラの場合と同様に、基本ブロック構造には一意のシーケンス番号が割り当てられています。map[*BasicBlock]int の代わりに、ブロック番号でインデックス付けされたスライスである []int を使用できます。配列またはスライスで十分な場合にマップを使用する理由はありません。

number をマップからスライスに変更するには、プログラムの7行を編集する必要があり、実行時間はほぼ半分になりました。

$ make havlak2
go build havlak2.go
$ ./xtime ./havlak2
# of loops: 76000 (including 1 artificial root node)
16.55u 0.11s 16.69r 1321008kB ./havlak2
$

(havlak1havlak2 の差分 を参照してください。)

main.DFS が実行時間の重要な部分ではなくなったことを確認するために、プロファイラを再度実行できます。

$ make havlak2.prof
./havlak2 -cpuprofile=havlak2.prof
# of loops: 76000 (including 1 artificial root node)
$ go tool pprof havlak2 havlak2.prof
Welcome to pprof!  For help, type 'help'.
(pprof)
(pprof) top5
Total: 1652 samples
     197  11.9%  11.9%      382  23.1% scanblock
     189  11.4%  23.4%     1549  93.8% main.FindLoops
     130   7.9%  31.2%      152   9.2% sweepspan
     104   6.3%  37.5%      896  54.2% runtime.mallocgc
      98   5.9%  43.5%      100   6.1% flushptrbuf
(pprof)

main.DFS エントリはプロファイルに表示されなくなり、残りのプログラムの実行時間も短縮されました。現在、プログラムはその時間のほとんどをメモリの割り当てとガベージコレクションに費やしています (メモリの割り当てと定期的なガベージコレクションの両方を行う runtime.mallocgc が時間の54.2%を占めます)。ガベージコレクタがこれほど頻繁に実行される理由を見つけるには、何をメモリに割り当てているのかを特定する必要があります。1つの方法は、プログラムにメモリプロファイリングを追加することです。-memprofile フラグが指定された場合、プログラムはループ検出の1回の反復後に停止し、メモリプロファイルを書き込み、終了するように手配します。

var memprofile = flag.String("memprofile", "", "write memory profile to this file")
...

    FindHavlakLoops(cfgraph, lsgraph)
    if *memprofile != "" {
        f, err := os.Create(*memprofile)
        if err != nil {
            log.Fatal(err)
        }
        pprof.WriteHeapProfile(f)
        f.Close()
        return
    }

プロファイルを書き込むために、-memprofile フラグを指定してプログラムを呼び出します。

$ make havlak3.mprof
go build havlak3.go
./havlak3 -memprofile=havlak3.mprof
$

(havlak2 からの差分 を参照してください。)

go tool pprof をまったく同じ方法で使用します。これで、調査しているサンプルはメモリ割り当てであり、クロックティックではありません。

$ go tool pprof havlak3 havlak3.mprof
Adjusting heap profiles for 1-in-524288 sampling rate
Welcome to pprof!  For help, type 'help'.
(pprof) top5
Total: 82.4 MB
    56.3  68.4%  68.4%     56.3  68.4% main.FindLoops
    17.6  21.3%  89.7%     17.6  21.3% main.(*CFG).CreateNode
     8.0   9.7%  99.4%     25.6  31.0% main.NewBasicBlockEdge
     0.5   0.6% 100.0%      0.5   0.6% itab
     0.0   0.0% 100.0%      0.5   0.6% fmt.init
(pprof)

コマンド go tool pprof は、FindLoops が使用中の82.4 MB のうち約56.3 MB を割り当てたこと、CreateNode がさらに17.6 MB を占めることを報告しています。オーバーヘッドを減らすため、メモリプロファイラは割り当てられた500 KB あたり約1ブロックの情報のみを記録します (「1-in-524288 サンプリングレート」)。したがって、これらは実際の数に対する近似値です。

メモリ割り当てを見つけるには、それらの関数をリストアップします。

(pprof) list FindLoops
Total: 82.4 MB
ROUTINE ====================== main.FindLoops in /home/rsc/g/benchgraffiti/havlak/havlak3.go
  56.3   56.3 Total MB (flat / cumulative)
...
   1.9    1.9  268:     nonBackPreds := make([]map[int]bool, size)
   5.8    5.8  269:     backPreds := make([][]int, size)
     .      .  270:
   1.9    1.9  271:     number := make([]int, size)
   1.9    1.9  272:     header := make([]int, size, size)
   1.9    1.9  273:     types := make([]int, size, size)
   1.9    1.9  274:     last := make([]int, size, size)
   1.9    1.9  275:     nodes := make([]*UnionFindNode, size, size)
     .      .  276:
     .      .  277:     for i := 0; i < size; i++ {
   9.5    9.5  278:             nodes[i] = new(UnionFindNode)
     .      .  279:     }
...
     .      .  286:     for i, bb := range cfgraph.Blocks {
     .      .  287:             number[bb.Name] = unvisited
  29.5   29.5  288:             nonBackPreds[i] = make(map[int]bool)
     .      .  289:     }
...

現在のボトルネックは以前と同じようです。より単純なデータ構造で十分な場所でマップを使用していることです。FindLoops は約29.5 MB のマップを割り当てています。

ちなみに、--inuse_objects フラグを指定して go tool pprof を実行すると、サイズではなく割り当て数が報告されます。

$ go tool pprof --inuse_objects havlak3 havlak3.mprof
Adjusting heap profiles for 1-in-524288 sampling rate
Welcome to pprof!  For help, type 'help'.
(pprof) list FindLoops
Total: 1763108 objects
ROUTINE ====================== main.FindLoops in /home/rsc/g/benchgraffiti/havlak/havlak3.go
720903 720903 Total objects (flat / cumulative)
...
     .      .  277:     for i := 0; i < size; i++ {
311296 311296  278:             nodes[i] = new(UnionFindNode)
     .      .  279:     }
     .      .  280:
     .      .  281:     // Step a:
     .      .  282:     //   - initialize all nodes as unvisited.
     .      .  283:     //   - depth-first traversal and numbering.
     .      .  284:     //   - unreached BB's are marked as dead.
     .      .  285:     //
     .      .  286:     for i, bb := range cfgraph.Blocks {
     .      .  287:             number[bb.Name] = unvisited
409600 409600  288:             nonBackPreds[i] = make(map[int]bool)
     .      .  289:     }
...
(pprof)

約20万個のマップが29.5 MBを占めることから、初期マップ割り当てには約150バイトかかるようです。これはマップがキーと値のペアを保持するために使用されている場合には妥当ですが、今回のようにマップが単純なセットの代わりとして使用されている場合にはそうではありません。

マップの代わりに、単純なスライスを使って要素をリストできます。マップが使用されているケースのほとんどすべてにおいて、アルゴリズムが重複する要素を挿入することは不可能です。残りの1つのケースでは、組み込み関数の append の単純なバリアントを記述できます。

func appendUnique(a []int, x int) []int {
    for _, y := range a {
        if x == y {
            return a
        }
    }
    return append(a, x)
}

この関数を記述するだけでなく、Go プログラムをマップの代わりにスライスを使用するように変更するには、わずかなコード行を変更するだけです。

$ make havlak4
go build havlak4.go
$ ./xtime ./havlak4
# of loops: 76000 (including 1 artificial root node)
11.84u 0.08s 11.94r 810416kB ./havlak4
$

(havlak3 からの差分 を参照してください。)

開始時点から2.11倍高速になりました。もう一度 CPU プロファイルを見てみましょう。

$ make havlak4.prof
./havlak4 -cpuprofile=havlak4.prof
# of loops: 76000 (including 1 artificial root node)
$ go tool pprof havlak4 havlak4.prof
Welcome to pprof!  For help, type 'help'.
(pprof) top10
Total: 1173 samples
     205  17.5%  17.5%     1083  92.3% main.FindLoops
     138  11.8%  29.2%      215  18.3% scanblock
      88   7.5%  36.7%       96   8.2% sweepspan
      76   6.5%  43.2%      597  50.9% runtime.mallocgc
      75   6.4%  49.6%       78   6.6% runtime.settype_flush
      74   6.3%  55.9%       75   6.4% flushptrbuf
      64   5.5%  61.4%       64   5.5% runtime.memmove
      63   5.4%  66.8%      524  44.7% runtime.growslice
      51   4.3%  71.1%       51   4.3% main.DFS
      50   4.3%  75.4%      146  12.4% runtime.MCache_Alloc
(pprof)

現在、メモリ割り当てとそれに伴うガベージコレクション (runtime.mallocgc) が実行時間の50.9%を占めています。システムがガベージコレクションを行っている理由を別の観点から見るには、コレクションを引き起こしている割り当て、つまり mallocgc にほとんどの時間を費やしている割り当てを見る方法があります。

(pprof) web mallocgc

このグラフでは、多くのノードが小さなサンプル数で大きなノードを覆い隠しているため、何が起こっているのかを把握するのは困難です。go tool pprof に、サンプルの少なくとも10%を占めないノードを無視するように指示できます。

$ go tool pprof --nodefraction=0.1 havlak4 havlak4.prof
Welcome to pprof!  For help, type 'help'.
(pprof) web mallocgc

太い矢印をたどることで、FindLoops がほとんどのガベージコレクションを引き起こしていることが容易にわかります。FindLoops をリストすると、その大部分が冒頭にあることがわかります。

(pprof) list FindLoops
...
     .      .  270: func FindLoops(cfgraph *CFG, lsgraph *LSG) {
     .      .  271:     if cfgraph.Start == nil {
     .      .  272:             return
     .      .  273:     }
     .      .  274:
     .      .  275:     size := cfgraph.NumNodes()
     .      .  276:
     .    145  277:     nonBackPreds := make([][]int, size)
     .      9  278:     backPreds := make([][]int, size)
     .      .  279:
     .      1  280:     number := make([]int, size)
     .     17  281:     header := make([]int, size, size)
     .      .  282:     types := make([]int, size, size)
     .      .  283:     last := make([]int, size, size)
     .      .  284:     nodes := make([]*UnionFindNode, size, size)
     .      .  285:
     .      .  286:     for i := 0; i < size; i++ {
     2     79  287:             nodes[i] = new(UnionFindNode)
     .      .  288:     }
...
(pprof)

FindLoops が呼び出されるたびに、かなりのサイズの管理構造が割り当てられます。ベンチマークは FindLoops を50回呼び出すため、これらは大量のガベージとなり、ガベージコレクターにとってかなりの量の作業となります。

ガベージコレクトされる言語であっても、メモリ割り当ての問題を無視できるわけではありません。この場合、簡単な解決策は、FindLoops への各呼び出しが可能な限り前の呼び出しのストレージを再利用するようにキャッシュを導入することです。(実際、Hundt の論文では、Java プログラムが合理的なパフォーマンスを得るためにはまさにこの変更が必要だったと説明されていますが、彼は他のガベージコレクトされた実装では同じ変更を行いませんでした。)

グローバルな cache 構造を追加します。

var cache struct {
    size int
    nonBackPreds [][]int
    backPreds [][]int
    number []int
    header []int
    types []int
    last []int
    nodes []*UnionFindNode
}

そして、FindLoops で割り当ての代わりにそれを参照するようにします。

if cache.size < size {
    cache.size = size
    cache.nonBackPreds = make([][]int, size)
    cache.backPreds = make([][]int, size)
    cache.number = make([]int, size)
    cache.header = make([]int, size)
    cache.types = make([]int, size)
    cache.last = make([]int, size)
    cache.nodes = make([]*UnionFindNode, size)
    for i := range cache.nodes {
        cache.nodes[i] = new(UnionFindNode)
    }
}

nonBackPreds := cache.nonBackPreds[:size]
for i := range nonBackPreds {
    nonBackPreds[i] = nonBackPreds[i][:0]
}
backPreds := cache.backPreds[:size]
for i := range nonBackPreds {
    backPreds[i] = backPreds[i][:0]
}
number := cache.number[:size]
header := cache.header[:size]
types := cache.types[:size]
last := cache.last[:size]
nodes := cache.nodes[:size]

このようなグローバル変数は、もちろん、悪いエンジニアリングプラクティスです。つまり、FindLoops への並行呼び出しは安全ではなくなります。今のところ、プログラムのパフォーマンスにとって何が重要であるかを理解するために、最小限の変更を行っています。この変更はシンプルであり、Java 実装のコードを反映しています。Go プログラムの最終バージョンでは、このメモリを追跡するために個別の LoopFinder インスタンスを使用し、並行使用の可能性を回復します。

$ make havlak5
go build havlak5.go
$ ./xtime ./havlak5
# of loops: 76000 (including 1 artificial root node)
8.03u 0.06s 8.11r 770352kB ./havlak5
$

(havlak4 からの差分 を参照してください。)

プログラムをクリーンアップして高速化するためにできることは他にもありますが、私たちがまだ示していないプロファイリング技術を必要とするものはありません。内部ループで使用される作業リストは、反復間および FindLoops への呼び出し間で再利用でき、そのパス中に生成された個別の「ノードプール」と組み合わせることができます。同様に、ループグラフストレージは、再割り当てされるのではなく、各反復で再利用できます。これらのパフォーマンスの変更に加えて、最終バージョンは、イディオム的な Go スタイルで記述されており、データ構造とメソッドを使用しています。スタイルの変更は実行時間にわずかな影響しか与えません。アルゴリズムと制約は変更されていません。

最終バージョンは 2.29 秒で実行され、351 MB のメモリを使用します。

$ make havlak6
go build havlak6.go
$ ./xtime ./havlak6
# of loops: 76000 (including 1 artificial root node)
2.26u 0.02s 2.29r 360224kB ./havlak6
$

これは、私たちが最初に始めたプログラムよりも11倍高速です。生成されたループグラフの再利用を無効にしたとしても、つまりキャッシュされたメモリがループ検出のブックキーピングだけだとしても、プログラムは元のプログラムよりも6.7倍高速に実行され、メモリ使用量は1.5倍少なくなります。

$ ./xtime ./havlak6 -reuseloopgraph=false
# of loops: 76000 (including 1 artificial root node)
3.69u 0.06s 3.76r 797120kB ./havlak6 -reuseloopgraph=false
$

もちろん、この Go プログラムを元の C++ プログラムと比較するのはもはや公平ではありません。C++ プログラムは vector がより適切であるような set のような非効率なデータ構造を使用していました。健全性チェックとして、最終的な Go プログラムを 同等の C++ コード に翻訳しました。その実行時間は Go プログラムと似ています。

$ make havlak6cc
g++ -O3 -o havlak6cc havlak6.cc
$ ./xtime ./havlak6cc
# of loops: 76000 (including 1 artificial root node)
1.99u 0.19s 2.19r 387936kB ./havlak6cc

Go プログラムは C++ プログラムとほぼ同じ速さで実行されます。C++ プログラムは明示的なキャッシュではなく自動削除と割り当てを使用しているため、C++ プログラムは少し短く書きやすいですが、劇的にそうではありません。

$ wc havlak6.cc; wc havlak6.go
 401 1220 9040 havlak6.cc
 461 1441 9467 havlak6.go
$

(havlak6.cchavlak6.go を参照してください。)

ベンチマークは、測定するプログラムと同じくらいしか役に立ちません。私たちは go tool pprof を使用して、非効率的な Go プログラムを調査し、そのパフォーマンスを1桁向上させ、メモリ使用量を3.7分の1に削減しました。その後、同等に最適化された C++ プログラムとの比較により、プログラマが内部ループによって生成されるガベージの量に注意を払えば、Go は C++ と競合できることが示されました。

この投稿の作成に使用されたプログラムのソース、Linux x86-64 バイナリ、およびプロファイルは、GitHub の benchgraffiti プロジェクトで入手できます。

上記で述べたように、go test にはすでにこれらのプロファイリングフラグが含まれています。 ベンチマーク関数を定義すれば、すべて準備完了です。プロファイリングデータへの標準 HTTP インターフェースもあります。HTTP サーバーでは、次のように追加すると、

import _ "net/http/pprof"

/debug/pprof/ のいくつかの URL にハンドラがインストールされます。その後、サーバーのプロファイリングデータへの URL という単一の引数を指定して go tool pprof を実行すると、ライブプロファイルをダウンロードして調べることができます。

go tool pprof https://:6060/debug/pprof/profile   # 30-second CPU profile
go tool pprof https://:6060/debug/pprof/heap      # heap profile
go tool pprof https://:6060/debug/pprof/block     # goroutine blocking profile

ゴルーチンのブロッキングプロファイルは今後の投稿で説明します。ご期待ください。

次の記事: Go のファーストクラス関数
前の記事: 外部 Go ライブラリに焦点を当てる
ブログインデックス