pprofでGoアプリのプロファイル情報を取得する

はじめに

Javaでプロファイル情報を取得して分析するための方法は、いくつか思い当たるものはあるのですがGoだとやり方全くわからなかったので少しまとめておこうかと思いました。
Go言語は標準ライブラリとして、runtime/pprofパッケージやnet/http/pprofパッケージが用意されており、これらをちょっと使ってみようと思います。
また、プロファイル情報を分析するためのツールは公式のpprofを使うのが一般的なようなのでほんの少しだけ使い方をみてみようと思います。

pprofを用いたプロファイリング

Go言でプロファイル情報を取得するには以下の2つのやり方があるみたいです。

  • runtime/pprofパッケージを用いてプロファイル情報をファイルに出力する
  • net/http/pprofパッケージを用いてHTTP経由でプロファイル情報を取得する

上記の2つはprofile.proto形式で情報を出力するようです。
profile.protoは記号化されたコールスタックの情報がProtocol Buffersの書式で記述されているようです。
pprofで取得可能な項目には以下のようなものがあるようです。

  • CPU: CPUの使用時間に関するプロファイル
  • Heep: メモリアロケーションのプロファイル、メモリリークのチェック情報
  • Threadcreate: OSのスレッド生成に関するプロファイル
  • Goroutine: すべてのGoroutineのスタックトレース
  • Block: Goroutineのブロッキングに関するプロファイル。デフォルトで無効なのでruntime.SetBlockProfileRateを使って有効化する必要がある。
  • Mutex: Mutexのロックに関するプロファイル。デフォルトで無効なのでruntime.SetMutexProfileFractionを使って有効化する必要がある。

これらの詳細はこちらをご確認ください。

また軽く前述していますが、取得したprofile.protoの分析はpprofの可視化ツールを使って行なうのが一般的なようです。 このツールはのデータを読み込んで可視化を行ってくれます。

やってみる

フィボナッチ数列を計算する簡単なのアプリケーションを作成して、runtime/pprofパッケージやnet/http/pprofパッケージで情報を取得してみるのと、その情報を可視化するとことまでやってみようかと思います。

環境

動作環境は以下のような感じ。

$ uname -srvmpio
Linux 5.4.0-84-generic #94-Ubuntu SMP Thu Aug 26 20:27:37 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux


$ go version
go version go1.17.1 linux/amd64

$ lsb_release -a
LSB Version:    core-11.1.0ubuntu2-noarch:security-11.1.0ubuntu2-noarch
Distributor ID: Ubuntu
Description:    Ubuntu 20.04.3 LTS
Release:    20.04
Codename:   focal

サンプルアプリの作成

アプリは引数で正数nを受け取ってフィボナッチ数列を計算してn番目のフィボナッチ数を返すアプリを作ろうと思います。
まずはプロジェクト作成から。

$ mkdir echo-fibo && cd echo-fibo


$ go mod init echo-fibo

次にfiboパッケージを作り、よくある定義のフィボナッチ数列を計算する関数を定義します。
また、その関数に対するテストも記述しておきます。

fibo.go

package fibo

func Fibo(n int) int {
    if n < 2 {
        return n
    }
    return Fibo(n-2) + Fibo(n-1)
}

fibo_test.go

package fibo

import "testing"

func TestFibo(t *testing.T) {
    tests := []struct {
        name string
        input int
        want int
    }{
        {
            "input 10",
            10,
            55,
        },
        {
            "input 11",
            11,
            89,
        },
        {
            "input 20",
            20,
            6765,
        },
        {
            "input 30",
            30,
            832040,
        },
        {
            "input 44",
            44,
            701408733,
        },
    }
    for _, tt := range tests {
        t.Run(tt.name, func(t *testing.T) {
            if got := Fibo(tt.input); got != tt.want {
                t.Errorf("Fibo() = %v, want %v", got, tt.want)
            }
        })
    }
}

ここでは、効率は度外視で直感的なフィボナッチ数列の計算アルゴリズムものを記述しました。

最後にこの関数を呼び出すmain関数を書きます。

package main

import (
    "echo-fibo/fibo"
    "fmt"
    "log"
    "os"
    "strconv"
)

func main() {


    number, err := strconv.Atoi(os.Args[1])
    if err != nil {
        log.Fatal(err)
    }

    fmt.Println(fibo.Fibo(number))
}

バリデージョンもなにもしてないほんとに最低限のものですが、pprofを動かすことが目的なだけなのでこのまま行きます。

runtime/pprofパッケージを用いてプロファイル情報を取得する

runtime/pprofパッケージを用いてプロファイル情報を取得する方法は以下の2通りの方法があります。

  • Goのtestingパッケージにビルドインされているプロファイラを使う
  • pprof.StartCPUProfile(filename)pprof.WriteHeapProfile(filename)等を使ってスタンドアローンアプリでプロファイルを有効化する

testingパッケージにビルドインされているプロファイラを使う

前者のやり方は簡単で、testingパッケージにはプロファイルのサポートがビルドインされているので、以下のコマンドを実行するだけでプロファイル情報を取得することが可能です。

$ cd fibo
$ go test -cpuprofile cpu.prof -memprofile mem.prof -benchtime 1ms -bench .

$ ls
cpu.prof  fibo.go  fibo.test  fibo_test.go  mem.prof

上記のコマンドでは、-bench .ですべてのベンチマークが実行され、-cpuprofile cpu.prof-memprofile mem.profで実行結果を出力する項目とファイル名を決定しているようです。

上記の例ではCPUとMemoryに対するプロファイル情報を取得しましたが、以下のオプションでそれぞれのプロファイル情報が取得可能なようです。

Option 説明
-blockprofile [outputFileName] goroutineのブロッキングプロファイル
-coverprofile [outputFileName] すべてのテストが実行された時のカバレッジプロファイル
-cpuprofile [outputFileName] CPUプロファイル
-memprofile [outputFileName] Memoryプロファイル
-mutexprofile mutexの競合プロファイル

また、プロファイルとは少し毛色が違いますが-trace [outputFileName]実行のトレースを出力することも可能なようです。

スタンドアローンアプリでプロファイルを有効化する

testingパッケージは利用せずスタンドアローンのアプリに対してプロファイルを実行したい場合は少し工夫が必要です。
pprof.StartCPUProfile(filename)やpprof.WriteHeapProfile(filename)などの関数をmain関数で呼び出しプロファイルを有効にできるようにする必要があるからです。 ' main.go`を以下のように書き換えます。

package main

import (
    "echo-fibo/fibo"
    "flag"
    "fmt"
    "log"
    "os"
    "runtime"
    "runtime/pprof"
    "strconv"
)

var cpuprofile = flag.String("cpuprofile", "", "write cpu profile to `file`")
var memprofile = flag.String("memprofile", "", "write memory profile to `file`")
var number = flag.String("number", "", "fibo number")

func main() {

    flag.Parse()
    if *cpuprofile != "" {
        f, err := os.Create(*cpuprofile)
        if err != nil {
            log.Fatal("could not create CPU profile: ", err)
        }
        defer f.Close() // error handling omitted for example
        if err := pprof.StartCPUProfile(f); err != nil {
            log.Fatal("could not start CPU profile: ", err)
        }
        defer pprof.StopCPUProfile()
    }

    fmt.Println(os.Args)
    num, err := strconv.Atoi(*number)
    if err != nil {
        log.Fatal(err)
    }
    fmt.Println(fibo.Fibo(num))


    if *memprofile != "" {
        f, err := os.Create(*memprofile)
        if err != nil {
            log.Fatal("could not create memory profile: ", err)
        }
        defer f.Close() // error handling omitted for example
        runtime.GC()    // get up-to-date statistics
        if err := pprof.WriteHeapProfile(f); err != nil {
            log.Fatal("could not write memory profile: ", err)
        }
    }
}

この状態でアプリをビルドし以下のように起動するとプロファイル情報が取得できます。

$ go build echo-fibo

$  ./echo-fibo -number 44 -memprofile mem.prof

1つ1つプロファイルごとに設定していくのは流石に面倒に感じますが、ラップしてくれているライブラリがあるみたいなのでこれを使えばもう少し楽にできるのかも知れません。また、別で試してみようと思います。

net/http/pprofパッケージ

net/http/pprofを用いればプロファイル情報をHTTP経由で公開することも可能です。
基本的な使い方は簡単で、以下のインポートを自分のプログラムに追加するだけです。

import _ "net/http/pprof"

ここで、注意が必要で、もしアプリケーションがhttp serverを起動していない場合に以下のようなコードを記述して自分で起動してやる必要があります。

go func() {
    log.Println(http.ListenAndServe("localhost:6060", nil))
}()

net/http/pprofを使えばデフォルトでハンドラーが実装され以下のようなURLでプロファイル情報を取得できるようになります。

また、すべてのプロファイル情報を取得する場合はhttp://localhost:6060/debug/pprof/で行けるみたいです。

main関数を以下のように書き換えてHTTPのパスパラメータで受け取った値のフィボナッチ数列の答えを返すアプリに変更します。

package main

import (
    "echo-fibo/fibo"
    "flag"
    "fmt"
    "log"
    "net/http"
    _ "net/http/pprof"
    "strconv"
    "strings"
)

func main() {

    flag.Parse()

    http.HandleFunc("/fibo/", func(writer http.ResponseWriter, request *http.Request) {

        number := strings.TrimPrefix(request.URL.Path, "/fibo/")
        writer.WriteHeader(http.StatusOK)

        num, err := strconv.Atoi(number)
        if err != nil {
            log.Fatal(err)
        }

        fiboNum := fibo.Fibo(num)
        log.Println(fiboNum)

        fmt.Fprintf(writer, "The Answer is %d", fiboNum)
    })

    log.Println(http.ListenAndServe("localhost:6060", nil))
}

普通のHTTPハンドラーの実装とサーバの起動を行っているだけですが、Importに_ "net/http/pprof"を追加しています。
wgetでプロファイル情報を取得してみます。

$ wget -O heep.prof http://localhost:6060/debug/pprof/heap
--2021-09-23 18:47:58--  http://localhost:6060/debug/pprof/heap
localhost (localhost) をDNSに問いあわせています... 127.0.0.1
localhost (localhost)|127.0.0.1|:6060 に接続しています... 接続しました。
HTTP による接続要求を送信しました、応答を待っています... 200 OK
長さ: 特定できません [application/octet-stream]
`heep.prof' に保存中

heep.prof                                              [ <=>                                                                                                            ]   2.79K  --.-KB/s    in 0s      

2021-09-23 18:47:58 (8.25 MB/s) - `heep.prof' へ保存終了 [2858]

$ ls
echo-fibo  fibo  go.mod  go.sum  heep.prof  main.go

pprof 可視化ツールを使ってみる

pprofの可視化ではいくつかのやり方があるようです。
今回はWeb UIを通した可視化を行ってみたいと思います。
Web UIを用いる場合はgraphvizがインストールされている必要があるみたいなので、以下のコマンドでインストールしておきます。

sudo apt install graphviz

可視化ツールの使い方自体はさほど難しくなく以下のコマンドでWebのUIが立ち上がります。

$ go tool pprof -http=localhost:8081 pprof heep.prof 
pprof: open pprof: no such file or directory
Fetched 1 source profiles out of 2
Serving web UI on http://localhost:8081

f:id:yuya_hirooka:20210923184946p:plain

HTTP経由でプロファイルを取得する場合は以下のようにします。

$ go tool pprof -http=localhost:8082 http://localhost:6060/debug/pprof/heap
Fetching profile over HTTP from http://localhost:6060/debug/pprof/heap
Saved profile in /home/someone/pprof/pprof.___go_build_echo_fibo.alloc_objects.alloc_space.inuse_objects.inuse_space.005.pb.gz
Serving web UI on http://localhost:8082

力尽きたのでUIの詳細な見かたは別の機会に。