Go言語のプロファイリングツール、pprofのWeb UIがめちゃくちゃ便利なので紹介する

eureka, Inc.

Published in

Pairs Engineering

10 min readDec 9, 2017

エウレカのPairsグローバル事業部エンジニアの山下です。
この記事は、eureka Advent Calendar 2017 9日目の記事です。

昨日は天才Boxpさんの「GKE+CircleCI 2.0で継続的デプロイ可能なアプリケーションをシュッと作る」の話でした。
読み応え抜群なのでこちらも是非読んでみてください。

以下本題

pprofのWeb UIがすごい

pprofにWeb UIがあるのはご存知でしょうか？
最近Uber社が公開していた go-torch が本家のpprof側にビルトインされたりと盛り上がりを見せております。

下の画像が実際にWebUIを使っている時のイメージ画像です

いかがでしょうか？
インタラクティブでいい感じです。

それでは、pprofのWebUIの使い方を説明していきたいと思います。
後半部分ではpprofの設定方法も説明します。

1. WebUIの使い方（データの見方）

Seach regexp

まず目につくのが一番上の検索窓。
どの画面でも正規表現で絞り込みができるのでとても便利です。

Top

ViewからTopを選択すると下記のカラムのリストが表示されます。

Flat：関数の処理時間
Flat%：各Flatの全体に対する割合
Sum%：スタック履歴からの累計Flat%
Cum：待ち時間も含めた処理時間
Cum%：各Cumの全体に対する割合
Name：関数名

各カラムをクリックすることで並び順を簡単に変更することができます。

Graph

各ボックスはそれぞれ単一の関数に紐づいています。
ボックスのサイズが待ち時間も含めた処理時間の割合を表しています。
矢印の起点が呼び出し元関数で矢印の先が呼び出し関数です。

見方を詳しく説明したいのですが、このGraphをより読みやすくしたものが、
次に紹介するFlame Graphなので、そちらを見ていきましょう。

Flame Graph

・各ボックスはそれぞれ単一の関数に紐づいています。
・積み上げがそのままスタックトレースとなっています。
・ボックスの幅は、CPU上またはCPU上にあった親ボックスの一部（サンプル数に基づく）の合計処理時間を示します。広い幅のボックスは、狭い幅のボックスよりも実行ごとに多くのCPUを消費するか、単により頻繁に呼び出されることがあります。

見方

カーソルをあてると関数名と処理時間が表示されます。
複雑なプログラムであっても、処理時間の長い関数（ボックスの幅が広い関数）の実際にどこの処理（上に乗っている関数、もしくはその関数そのもの）に時間がかかっているかなどがインタラクティブにすぐ分かることができます。
一つのボックスをクリックするとその関数にフォーカスしたグラフとなります。

source

後ほど説明しますが、プロファイリングする時にソースコードのパス（もしくはバイナリ）を指定していた場合、
コードのどの部分でどれだけ時間がかかっていたかすぐ見ることができます。

2. pprofのセットアップ方法

インストール

# Goがインストール済みなことを確認
$ go version
go version go1.9.2 darwin/amd64# pprofをインストール（すでに入っていればアップデート）
$ go get -u github.com/google/pprof# graphvizが必要なのでインストール
$ brew install graphvizプロファイリングするアプリケーションを用意する今回は試しにisucon2017の予選問題でやってみます。# アプリケーションをクローン
$ git clone https://github.com/isucon/isucon7-qualifyプロファイルできるようにアプリにpprofを仕込むmain関数に仕込むだけなのでとても簡単です。
isucon7-qualify/webapp/go/src/isubata/app.goを編集します。
差分は下記だけです。diff --git a/webapp/go/src/isubata/app.go b/webapp/go/src/isubata/app.go
index 06f864a..f45a367 100644
--- a/webapp/go/src/isubata/app.go
+++ b/webapp/go/src/isubata/app.go
@@ -12,6 +12,7 @@ import (
        "log"
        "math/rand"
        "net/http"
+       _ "net/http/pprof"
        "os"
        "strconv"
        "strings"
@@ -721,6 +722,10 @@ func tRange(a, b int64) []int64 {
 }func main() {
+       go func() {
+               log.Println(http.ListenAndServe("localhost:6060", nil))
+       }()
+
        e := echo.New()
        funcs := template.FuncMap{
                "add":    tAdd,
(END)[注意]
今回は常時起動のWebアプリケーションなので、 net/http/pprof を使用したプロファイリング用のWebServerを立てる手法で行います。簡単なCLIのアプリケーション等であれば、 pkg/profile を使ってシンプルにプロファイリングすることもできるので参考にしてみてください。ベンチマーカーのセットアップ# 各環境に合わせてMySQLを立ち上げておいてください
$ mysql.server start# databese初期化
$ ~/isucon7-qualify/db/init.sh# buildする
$ cd ~/isucon7-qualify/bench
$ make# 初期データセットアップ
$ ~/isucon7-qualify/bench/bin/gen-initial-dataset
$ zcat ~/isucon7q-initial-dataset.sql.gz | mysql -uroot -h127.0.0.1 -P3306 --default-character-set=utf8 isubata
（※ macOSの場合、zcatではなくgzcat）# webappビルド
$ cd ~/isucon7-qualify/webapp/go/
$ make詳しくは
下記参考に
<a href="https://github.com/isucon/isucon7-qualify#ベンチマーカーの準備">https://github.com/isucon/isucon7-qualify#ベンチマーカーの準備</a>
<a href="https://github.com/isucon/isucon7-qualify#データベース初期化">https://github.com/isucon/isucon7-qualify#データベース初期化</a>実際にプロファイリングしてみる# アプリケーション起動
$ ~/isucon7-qualify/webapp/go/isubata# ベンチマーク開始
$ ~/isucon7-qualifybench/bin/bench -remotes=127.0.0.1:5000アプリケーションが起動していて、ベンチマークが動いている状態で下記を実行する# プロファイリング開始（30秒後に自動でブラウザが開きます）
$ pprof -http=localhost:8080 ~/isucon7-qualify/webapp/go/src/isubata/  http://localhost:6060/debug/pprof/profile[POINT]
上記はpprof/profileのエンドポイントは、CPUに関してのプロファイルとなりますが、エンドポイントを変えればメモリやブロック待ち時間など色々なプロファイリングが可能です。
http://localhost:6060/debug/pprof/heap
http://localhost:6060/debug/pprof/block
http://localhost:6060/debug/pprof/goroutine
http://localhost:6060/debug/pprof/threadcreate
http://localhost:6060/debug/pprof/mutexさいごに今回はCPUの処理時間に関してプロファイリングしてみましたが、
もちろんメモリ使用量やgoroutineごとのスタックトレースなども同じ手順でプロファイリングすることができます。
また、プロファイリングをすると必ず結果ファイルが生成されます。下記のように生成されたファイルを指定して再度結果を開くこともできます。（もちろんCLIでも）$ pprof -http=localhost:8080 /path/to/binary_or_code /path/to/pprof.samples.cpu.001.pb.gzWebアプリケーションやWorkerなどの常時起動型のアプリケーションであれば、上の手順で紹介したプロファイリング用のポートをあけておいて、気になった時にすぐ取れるようにしておいても良いと思います。謎なメモリリークに頭を悩ませている方、はたまた上司からむちゃなパフォーマンス改善を迫られている方、もちろん今までpprof使ったことがない方でも簡単に気持ち良いインタラクティブなUIでプロファイリングできてしまうので一度お試しあれ。参考にしたサイト
https://github.com/google/pprof/blob/master/doc/pprof.md
https://jvns.ca/blog/2017/09/24/profiling-go-with-pprof/
http://queue.acm.org/detail.cfm?id=2927301
http://www.brendangregg.com/FlameGraphs/cpuflamegraphs.html明日はエウレカのスーパースター二川にこさんが「社内Tinder風Webアプリ「Maybee」を会社忘年会のイベント用に作った話」を書いてくれます。楽しみです！