生涯未熟

生涯未熟

プログラミングをちょこちょこと。

go1.9で追加されるpprofのLabel機能を見てみる

Golang Weekly #167 - 生涯未熟

でも紹介しましたが、go1.9からプロファイリングツールのpprofでLabel機能が使えるらしいのでサラッと見てみます。

前置き

このlabel機能は以下のissueでのproposalが採択され、

github.com

提案者のmatloob氏がPRを投げ、go1.9beta1から組み込まれることになりました。

github.com

使い方

// labelの生成
labels := pprof.Labels("key", "value")

// プロファイリングの実行
pprof.Do(ctx, labels, func(ctx context.Context) {
    // 何らかの処理
})

基本的には上記コードを使い、Label付きでプロファイルしていきます。

では、実際に簡単なWebサーバのHandler毎にCPUプロファイリングしていきます。

簡単なWebサーバをプロファイリング

今回は極々シンプルな //user をハンドリングするWebサーバを作成しました。

package main

import (
    "context"
    "fmt"
    "log"
    "math/rand"
    "net/http"
    _ "net/http/pprof"
    "time"
)

func main() {
    http.HandleFunc("/", rootHandler)
    http.HandleFunc("/user", userHandler)
    log.Fatal(http.ListenAndServe(":8080", nil))
}

func rootHandler(w http.ResponseWriter, r *http.Request) {
    rootProcessing()
}

func userHandler(w http.ResponseWriter, r *http.Request) {
    userProcessing()
}

func rootProcessing(ctx context.Context) {
    fmt.Println("Start root processing")

    rand.Seed(time.Now().UnixNano())

    for true {
        fib(rand.Intn(100))
        time.Sleep(5 * time.Second)
    }
}

func userProcessing(ctx context.Context) {
    fmt.Println("Start user processing")

    rand.Seed(time.Now().UnixNano())

    for true {
        fib(rand.Intn(100))
        time.Sleep(5 * time.Second)
    }
}

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

//user にアクセスすると、CPUがしっかり動くように計算処理が無限ループに入ります。

それでは、これにCPUプロファイリングのコードを差し込んでいきましょう。

package main

import (
    "context"
    "fmt"
    "log"
    "math/rand"
    "net/http"
    _ "net/http/pprof"
    "runtime/pprof"
    "time"
)

func main() {
    http.HandleFunc("/", rootHandler)
    http.HandleFunc("/user", userHandler)
    log.Fatal(http.ListenAndServe(":8080", nil))
}

func rootHandler(w http.ResponseWriter, r *http.Request) {
    ctx := context.Background()
    rootProcessing(ctx)
}

func userHandler(w http.ResponseWriter, r *http.Request) {
    ctx := context.Background()
    userProcessing(ctx)
}

func rootProcessing(ctx context.Context) {
    fmt.Println("Start root processing")

    labels := pprof.Labels("http-path", "/root")
    pprof.Do(ctx, labels, func(ctx context.Context) {
        rand.Seed(time.Now().UnixNano())

        for true {
            fib(rand.Intn(100))
            time.Sleep(5 * time.Second)
        }
    })
}

func userProcessing(ctx context.Context) {
    fmt.Println("Start user processing")

    labels := pprof.Labels("http-path", "/user")
    pprof.Do(ctx, labels, func(ctx context.Context) {
        rand.Seed(time.Now().UnixNano())

        for true {
            fib(rand.Intn(100))
            time.Sleep(5 * time.Second)
        }
    })
}

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

rootProcessinguserProcessing にCPUプロファイリングのコードが追加されているのが分かりますね。

これを go run main.go で実行し、 http://localhost:8080http://localhost:8080/user にアクセスしてみてください。
CPUが唸りを上げるはずです。

これで最後にCPUプロファイリング結果を見るだけです。
ターミナルで以下を実行してみてください。

go tool pprof http://localhost:8080/debug/pprof/profile
(pprof)

すると、対話状態に入りますのでおもむろに tags と入力してください。

(pprof) tags
http-path: Total 4675
      2345 (50.16%): /root
      2330 (49.84%): /user

こんな感じでCPUの状態がそれぞれのLabelごとに表示されます。
keyで設定された値にグルーピングされ、valueに対応するCPUの状態が表示されているのが分かりますね。

このような形で、各々のURLパスごとにCPUの状態を見たい場合に使ったりするのも一つの使い方です。
他にもgoroutineで並列処理を行なうような場合にも、それぞれのgoroutineに対してLabelを貼りCPUプロファイリングするのもありですね。

というわけで簡単にですが、pprofのLabel機能を紹介しました。