Goのプロファイラ fgprof #Go

Go2 Advent Calendar 2020 12日目のエントリです。

fgprofというGoのプロファイラがあります。fgprofはサンプリング型のプロファイラで、On-CPUとOff-CPUのプロファイルを統合的に収集して分析できるという特徴を持ちます。
これにより、fgprofではCPUリソースを消費するワークロードとI/O（Didk, Networkなど）のワークロードが混在するアプリケーションで、両方の観点からボトルネックを分析するのに役立てることができます。

fgprofは次のようにプロファイリング対象のアプリケーションにHTTPハンドラを追加する形で組み込み、go tool pprofでプロファイリングの実行と解析ができます。

GitHub - felixge/fgprof - Quick Start

package main

import(
    _ "net/http/pprof"
    "github.com/felixge/fgprof"
)

func main() {
    http.DefaultServeMux.Handle("/debug/fgprof", fgprof.Handler())
    go func() {
       log.Println(http.ListenAndServe(":6060", nil))
    }()

    // <code to profile>
}

go tool pprof --http=:6061 http://localhost:6060/debug/fgprof?seconds=10

Goのnet/http/pprofパッケージでも同様の方法でプロファイリングを行えますが、/debug/pprof/profilerエンドポイントを利用するCPU ProfilerではOn-CPUの分析しか行なえません。Off-CPUの分析をする場合には別途/debug/pprof/traceを利用することができますが、fgprofのように統合的に扱うことはできません。
READMEのThe Problem に詳しく書かれていますが、fgprofはこの点についての課題感から生まれたツールのようです。

fgprofの実装

fgprofが具体的にどのようにプロファイリングを行っているのか、またnet/http/pprofとどのような点が異なるのか興味があったので実装を調べてみました。

fgprofではプロファイリング実行中に、バックグラウンドのGoroutineでruntime.GoroutineProfile() を呼び出して全Goroutineのスタックトレースを取得する、ということを99/secの頻度で行っています。
runtime.GoroutineProfile()で取得できる情報には、CPU時間を利用して処理を行っているGoroutineのものも、I/O待ちで待機中のGoroutineのものも含まれるので、これを利用してOn-CPUとOff-CPUを統合的に収集し、分析可能にしています。

なお、net/http/pprofのCPU Profile(/debug/pprof/profile)では、内部的にruntime/pprofのStartCPUProfile でプロファイルを収集していますが、ここでは実行中のGoroutineのスタックトレースしか収集されません。
このあたりはほぼREADMEのGo's builtin CPU Profiler の受け売りですが、GoではIOが内部的にnon-blockingで処理されるため、IOを待機しているGoroutineはOSスレッドに割り当てられず実行中とならないため、StartCPUProfile()で収集できるプロファイルにOff-CPUの情報が載ってこないということのようです。

Goのプロファイラ fgprof

fgprofの実装

参考