継続的プロファイリングを導入して Grafana で観測してみた
こんにちは。
ご機嫌いかがでしょうか。
"No human labor is no human error" が大好きな吉井 亮です。
継続的プロファイリングを本番環境に計装してみました。理解が及ぼないところがあるので整理のために記事にしました。
継続的プロファイリングとは
プロファイリングとは、プログラムの実行時にどの部分がどれだけの時間を消費しているかを調査する手法です。
CPU 使用時間、メモリの割当、Mutex など内部動作を詳細に観測できます。
継続的ではないプロファイリングはコンピューティングの初期時代から存在するそうです。当時の使用場面は、限られたコンピュートリソースをどのように活用するか理解することでした。
- サンプルベースのプロファイリング: プロファイラーが定期的にプログラムを中断し、そのたびにプログラムの状態をキャプチャ
- インストルメンテーションベースのプロファイリング: 開発者が情報を記録する追加コードをプログラムに埋め込む
これら従来のプロファイリングでは、コードの特定部分にフォーカス可能、ボトルネック被疑対象を開発者が決められるなどのメリットがある一方、オーバーヘッドが高い、その時点の情報しか得られないなどのデメリットがありました。
ソフトウェアの規模と複雑さが増すにつれ、従来のプロファイリングでは対応しきれなくなりました。そこで登場したのが継続的プロファイリングです。
プロファイリング取得にかかるオーバーヘッドを最小限に抑え、プロファイリングデータを継続的に収集するようになりました。これにより、時間経過によるプログラムの動作を把握しやすくなりました。
継続的プロファイリングの主な利点です。
- ある瞬間のパフォーマンスと長期的なパフォーマンスの両方を観測できる
- パフォーマンスのボトルネックを特定するのに役立つ
- パフォーマンスの比較が容易になる (本番環境と開発環境、短時間と長時間など)
- 継続的プロファイリングはバックグラウンドかつ低オーバーヘッドで動作するよう設計されているため、実働環境のパフォーマンスへの影響を最小限に抑えることができる
オブザーバビリティとプロファイリング
下の図を見てください。これは私が大好きな図です。
オブザーバビリティの主要なシグナルの関係性をよく表していると思ってます。
プロファイリングも他のシグナルと同じで、単体よりも組み合わせて観測することでより効果を発揮します。
メトリクスを観測していたところ、メモリ使用量が急激に増加していることを発見したとします。メトリクスだけではプログラムのどの処理がメモリを消費しているかはわかりません。
継続的プロファイリングを確認することで、メモリ使用量が増加している原因を特定できる可能性が高くなります。
トレースと継続的プロファイリングをダッシュボード上でリンクさせることで、時間を要しているトレースを特定し、その処理がメモリを消費しているかどうかを確認できます。
導入
今回は Grafana Pyroscope を使用しました。元々 Grafana を導入していたので、親和性を期待しての選択です。
Pyroscope の導入方法は2通りあります。
-
Grafana Alloy による自動計装
- コードの変更が最小限で済む
- SDK と比べると取得できるデータ種類が少ない
- 別途 Alloy コンテナが必要
- SDK を使用した計装
- 対応している言語が豊富
- Alloy と比べると種類できるデータ種類が多い
- コードの変更が発生
Alloy を使用した Pull Mode を実装してみた構成図です。(簡略化してます)
Pull Mode にすると /debug/pprof/
で始まる複数のエンドポイントが生成されます。そこに対して、Alloy が定期的にデータを取りに行きます。
取得したデータは Pyroscope に送られ蓄積され、Grafana で観測できるようになります。
セットアップ
基本的に上記ドキュメントに記載の通り進めるだけです。
担当しているアプリケーションは Golang なので、以下の手順を行いました。
まずはパッケージの追加。
go get github.com/grafana/pyroscope-go/godeltaprof@latest
コードには2行追加です。
import _ "net/http/pprof"
import _ "github.com/grafana/pyroscope-go/godeltaprof/http/pprof"
上記ドキュメントに記載がありますが、http.DefaultServeMux
を使っていない場合は自身で Handler を登録する必要があります。
以下が参考になりました。これを参考に実装しましょう。
Pyroscope
Pyroscope を起動します。
今回はバックエンドストレージに S3 を使いました。 Your_Bucket_Name
は適宜変更してください。
コンテナの IAM ロールに S3 の書き込み権限が必要です。
storage:
backend: s3
s3:
region: ap-northeast-1
endpoint: s3.ap-northeast-1.amazonaws.com
bucket_name: Your_Bucket_Name
sse:
type: SSE-S3
Pyroscope の全設定は以下を参照ください。
Alloy
アプリケーションのセットアップが終わったら、次は Alloy です。
Prometheus によく似た設定ファイルです。
Alloy からアプリケーションにプロファイルデータを取得するための設定を行います。
Apps_ip_address
はアプリケーションの IP アドレス、Apps_Port
はアプリケーションのポート番号です。
Your_Apps_Name
はアプリケーションを識別する名称です。Grafana で表示した際に使いますので、識別しやすい名前をつけましょう。
pyroscope.scrape "scrape_job_name" {
targets = [{"__address__" = "Apps_ip_address:Apps_Port", "service_name" = "Your_Apps_Name"}]
forward_to = [pyroscope.write.write_job_name.receiver]
profiling_config {
profile.process_cpu {
enabled = true
}
profile.godeltaprof_memory {
enabled = true
}
profile.memory {
enabled = false
}
profile.godeltaprof_mutex {
enabled = false
}
profile.mutex { // disable mutex, use godeltaprof_mutex instead
enabled = false
}
profile.godeltaprof_block {
enabled = true
}
profile.block { // disable block, use godeltaprof_block instead
enabled = false
}
profile.goroutine {
enabled = true
}
}
}
取得したデータを Pyroscope に送る設定を行います。
Your_Pyroscope_ip_address
は Pyroscope の IP アドレス、Your_Pyroscope_Port
は Pyroscope のポート番号です。
pyroscope.write "write_job_name" {
endpoint {
url = "http://Your_Pyroscope_ip_address:Your_Pyroscope_Port"
}
}
Alloy の全設定は以下を参照ください。
Grafana
Grafana のデータソースに Pyroscope を追加します。YAML で設定する場合は以下のようになります。
Your_Pyroscope_ip_address
は Pyroscope の IP アドレス、Your_Pyroscope_Port
は Pyroscope のポート番号です。
- name: Pyroscope
uid: Pyroscope
type: grafana-pyroscope-datasource
url: http://Your_Pyroscope_ip_address:Your_Pyroscope_Port
editable: true
isDefault: false
Grafana 起動時に以下の環境変数を追加します。
GF_INSTALL_PLUGINS=grafana-pyroscope-app
Grafana で表示してみよう
一通りのセットアップが終わったので、Grafana で表示してみましょう。
本番環境の実データを公開することはできないので、サンプルを使います。
intro-to-mltp をローカルにクローンし、docker compose up -d
します。
http://localhost:3000/
で Grafana にアクセスします。
左側ペインから Explore
→ Profiles
をクリックします。
グラフが表示されると思います。Flame graph
を選択すると、以下のようなグラフが表示されます。
見慣れないグラフが表示されました。フレームグラフです。(例の右側に表示されているカラフルなもの)
アプリケーションのリソース割り当てとボトルネックを直感的に把握できます。
グラフを構成している一本一本のバーを「ノード」と呼ぶそうです。
水平方向がアプリケーションの実行時間の100%を表しています。水平に幅が大きいほど、その関数が多くの時間を消費していることを示しています。
垂直方向は関数の階層を表しています。上位のノードから下位ノードが呼び出されている関係を示しています。
フレームグラフの右側にはテーブル形式のデータが表示されています。列には Self
と Total
があります。
Self
はそのノード単体の実行時間、Total
はそのノードを含む全ての子ノードの実行時間を表しています。
比較ビュー
このままの表示でもボトルネックを特定するのには十分ですが、比較ビューを使うとさらに効果的です。
同じグラフ画面の上部にある Diff flame graph
をクリックします。画面が2分割されるはずです。
一方のグラフは Last 30 minutes
、もう一方は Last 1 hour
に設定しそれぞれ検索します。そのうえで、Last 30 minutes
の方はある5分間をマウスで選択肢、Last 1 hour
の方は同じ5分間を含む35分間をマウスで選択します。それが下図です。
これで何が分かるかというと、時間経過によるリソース使用量の変化を観測できます。下図だとメモリリークを起こしている関数の特定に役に立ちます。
時間帯の比較以外にも、実行環境(本番と開発)、クラウドリージョン、リリースバージョンなどの比較が可能です。
まとめ
初めて継続的プロファイリングを導入してみました。
まだまだ理解していない部分が多いですが、初歩的な解析をすることができました。経験と勘に頼らない解析ができそうな感触です。
トレースとの紐付けやダッシュボード化など、さらなる深堀りを計画しています。
参考
What is continuous profiling?
継続的プロファイルによる大規模アプリケーションの性能改善
Continuous Profiler
Traces and telemetry
Introduction to Metrics, Logs, Traces and Profiles in Grafana
Discussion