クライアント アプリとフロントエンド ウェブのデベロッパーは、Android Studio CPU Profiler や Chrome に含まれるプロファイリング ツールなどのツールを使用してコードのパフォーマンスを改善するのが一般的ですが、バックエンド サービスに取り組むデベロッパーは、同等の手法をあまり利用していません。Stackdriver Profiler は、コードが Google Cloud Platform で実行されているかどうかにかかわらず、サービス デベロッパーに同じ機能を提供します。
このツールは、本番環境のアプリケーションから CPU 使用率とメモリ割り当てに関する情報を収集します。収集した情報からアプリケーションのソースコードが特定されるため、最もリソースを消費しているコード部分を容易に識別できます。コードの特定が難しい場合でも、パフォーマンスの特性を把握できます。このツールで使用されている収集手法はオーバーヘッドが少ないため、本番環境での継続的な使用に適しています。
この Codelab では、Go プログラム用に Stackdriver Profiler を設定する方法を学び、このツールでアプリケーションのパフォーマンスに関するどのような分析情報を得られるかについて理解します。
学習内容
- Stackdriver Profiler でプロファイリングを行うように Go プログラムを構成する方法。
- Stackdriver Profiler を使用してパフォーマンス データを収集、表示、分析する方法。
必要なもの
- Google Cloud Platform プロジェクト
- Chrome や Firefox などのブラウザ
- Linux の標準的なテキスト エディタ（vim、emacs、nano など）を使い慣れていること
このチュートリアルをどのように使用されますか？
Google Cloud Platform のご利用経験について、いずれに該当されますか？
セルフペース型の環境設定
Google アカウント（Gmail または Google Apps）をお持ちでない場合は、1 つ作成する必要があります。Google Cloud Platform のコンソール（console.cloud.google.com）にログインし、新しいプロジェクトを作成します。
プロジェクト ID を忘れないようにしてください。プロジェクト ID はすべての Google Cloud プロジェクトを通じて一意の名前にする必要があります（上記の名前はすでに使用されているので使用できません）。以降、このコードラボでは PROJECT_ID と呼びます。
次に、Google Cloud リソースを使用するために、Cloud Console で課金を有効にする必要があります。
この Codelab の操作をすべて行っても、費用は数ドル程度です。ただし、その他のリソースを使いたい場合や、実行したままにしておきたいステップがある場合は、追加コストがかかる可能性があります（このドキュメントの最後にある「クリーンアップ」セクションをご覧ください）。
Google Cloud Platform の新規ユーザーは、300 ドル分の無料トライアルをご利用いただけます。
Google Cloud Shell
Google Cloud はノートパソコンからリモートで操作できますが、この Codelab では、設定を簡単にするために、Google Cloud Shell（Cloud 上で動作するコマンドライン環境）を使用します。
Google Cloud Shell の有効化
GCP Console で右上のツールバーにある Cloud Shell アイコンをクリックします。
[Cloud Shell の起動] をクリックします。
プロビジョニングと環境への接続にはそれほど時間はかかりません。
この仮想マシンには、必要な開発ツールがすべて準備されています。5 GB の永続ホーム ディレクトリが用意されており、Google Cloud で稼働するため、ネットワーク パフォーマンスが充実しており認証もスムーズです。このラボでの作業のほとんどは、ブラウザまたは Google Chromebook から実行できます。
Cloud Shell に接続すると、すでに認証は完了しており、プロジェクトに各自の PROJECT_ID が設定されています。
Cloud Shell で次のコマンドを実行して、認証されたことを確認します。
gcloud auth list
コマンド出力
Credentialed accounts: - <myaccount>@<mydomain>.com (active)
gcloud config list project
コマンド出力
[core] project = <PROJECT_ID>
上記のようになっていない場合は、次のコマンドで設定できます。
gcloud config set project <PROJECT_ID>
コマンド出力
Updated property [core/project].
Cloud コンソールで、左側のナビゲーション バーの [Profiler] をクリックして、Profiler UI に移動します。
また、Cloud Console の検索バーを使用して Profiler UI に移動することもできます。検索バーに「Stackdriver Profiler」と入力して、検索結果を選択します。いずれの場合も、次のように「表示するデータがありません」というメッセージが表示された Profiler UI が表示されます。プロジェクトは新しいため、プロファイリング データはまだ収集されていません。
プロファイリングを行う時間です。
ここでは、GitHub で入手できるシンプルな合成 Go アプリケーションを使用します。まだ開いている Cloud Shell ターミナルで（Profiler UI に「表示するデータがありません」というメッセージが表示されている間に）、次のコマンドを実行します。
$ go get -u github.com/GoogleCloudPlatform/golang-samples/profiler/...
次に、アプリケーション ディレクトリに切り替えます。
$ cd ~/gopath/src/github.com/GoogleCloudPlatform/golang-samples/profiler/hotapp
このディレクトリには、プロファイリング エージェントが有効になっている合成アプリである「main.go」ファイルが含まれています。
main.go
...
import (
...
"cloud.google.com/go/profiler"
)
...
func main() {
err := profiler.Start(profiler.Config{
Service: "hotapp-service",
DebugLogging: true,
MutexProfiling: true,
})
if err != nil {
log.Fatalf("failed to start the profiler: %v", err)
}
...
}プロファイリング エージェントは、デフォルトで CPU、ヒープ、スレッドのプロファイルを収集します。このコードは、ミューテックス（競合とも呼ばれます）プロファイルの収集を有効にします。
プログラムを実行します。
$ go run main.go
プログラムの実行中に、プロファイリング エージェントは構成された 5 つのタイプのプロファイルを定期的に収集します。収集は時間とともにランダム化されます（各タイプの平均レートは 1 分あたり 1 つのプロファイル）。そのため、各タイプの収集に最大 3 分かかることがあります。プロファイルが作成されると、プログラムから通知されます。上記の構成の DebugLogging フラグによってメッセージが有効になります。それ以外の場合、エージェントはサイレント モードで実行されます。
$ go run main.go 2018/03/28 15:10:24 profiler has started 2018/03/28 15:10:57 successfully created profile THREADS 2018/03/28 15:10:57 start uploading profile 2018/03/28 15:11:19 successfully created profile CONTENTION 2018/03/28 15:11:30 start uploading profile 2018/03/28 15:11:40 successfully created profile CPU 2018/03/28 15:11:51 start uploading profile 2018/03/28 15:11:53 successfully created profile CONTENTION 2018/03/28 15:12:03 start uploading profile 2018/03/28 15:12:04 successfully created profile HEAP 2018/03/28 15:12:04 start uploading profile 2018/03/28 15:12:04 successfully created profile THREADS 2018/03/28 15:12:04 start uploading profile 2018/03/28 15:12:25 successfully created profile HEAP 2018/03/28 15:12:25 start uploading profile 2018/03/28 15:12:37 successfully created profile CPU ...
最初のプロファイルが収集されると、UI はすぐに自動更新されます。その後は自動更新されないため、新しいデータを表示するには、Profiler UI を手動で更新する必要があります。これを行うには、時間間隔選択ツールで [現在] ボタンを 2 回クリックします。
UI が更新されると、次のような画面が表示されます。
プロファイル タイプ セレクタには、次の 5 つのプロファイル タイプが表示されます。
それでは、各プロファイル タイプと重要な UI 機能を確認し、いくつかのテストを実施してみましょう。この段階では Cloud Shell ターミナルは不要になったため、Ctrl+C キーを押して「exit」と入力して終了します。
データを収集したので、詳しく見てみましょう。ここでは、本番環境でさまざまな種類のパフォーマンスの問題の典型的な動作をシミュレートする合成アプリ（ソースは Github で入手可能）を使用します。
CPU 使用率の高いコード
CPU プロファイル タイプを選択します。UI に読み込まれると、フレーム グラフに load 関数の 4 つのリーフブロックが表示されます。これらのブロックは、CPU 使用率の合計を表します。
この関数は、タイトなループを実行して CPU サイクルを大量に消費するように特別に記述されています。
main.go
func load() {
for i := 0; i < (1 << 20); i++ {
}
}この関数は、busyloop → {foo1, foo2} → {bar, baz} → load の 4 つの呼び出しパスを介して busyloop() から間接的に呼び出されます。関数ボックスの幅は、特定の呼び出しパスの相対的なコストを表します。この場合、4 つのパスの費用はほぼ同じです。実際のプログラムでは、パフォーマンスの面で最も重要な呼び出しパスの最適化に注力する必要があります。フレームグラフでは、コストの高いパスが大きなボックスで視覚的に強調表示されるため、これらのパスを簡単に特定できます。
プロファイル データフィルタを使用すると、表示をさらに絞り込むことができます。たとえば、「baz」をフィルタ文字列として指定する「スタックを表示」フィルタを追加してみます。次のスクリーンショットのように、load() への 4 つの呼び出しパスのうち 2 つのみが表示されます。この 2 つのパスだけが、名前に文字列「baz」を含む関数を通過します。このようなフィルタリングは、大きなプログラムの一部に焦点を当てたい場合に便利です（たとえば、プログラムの一部のみを所有している場合など）。
メモリ使用量の多いコード
[Heap] プロファイル タイプに切り替えます。以前のテストで作成したフィルタは必ず削除してください。これで、alloc によって呼び出された allocImpl がアプリのメモリの主なコンシューマーとして表示されるフレームグラフが表示されます。
フレームグラフの上にある概要表は、アプリで使用されているメモリの合計量が平均で約 57.4 MiB であり、そのほとんどが allocImpl 関数によって割り当てられていることを示しています。この関数の実装を考えると、これは驚くことではありません。
main.go
func allocImpl() {
// Allocate 64 MiB in 64 KiB chunks
for i := 0; i < 64*16; i++ {
mem = append(mem, make([]byte, 64*1024))
}
}この関数は 1 回実行され、64 MiB が小さなチャンクに割り当てられ、これらのチャンクへのポインタがグローバル変数に保存されて、ガベージ コレクションから保護されます。プロファイラで使用されているメモリの量は 64 MiB と若干異なります。Go ヒープ プロファイラは統計ツールであるため、測定のオーバーヘッドは小さいですが、バイト単位で正確ではありません。このような 10% 程度の差が生じても、驚かないでください。
IO 集中型コード
プロファイル タイプ セレクタで [Threads] を選択すると、表示がフレームグラフに切り替わります。このグラフでは、幅の大部分が wait 関数と waitImpl 関数で占められています。
上のフレームグラフの概要を見ると、wait 関数からコールスタックを拡張する goroutine が 100 個あることがわかります。これらの待機を開始するコードは次のようになっているため、これはまさに正しい動作です。
main.go
func main() {
...
// Simulate some waiting goroutines.
for i := 0; i < 100; i++ {
go wait()
}このプロファイル タイプは、プログラムが予期しない時間（I/O など）を待機に費やしているかどうかを把握するのに役立ちます。このようなコールスタックは、CPU 時間の大部分を消費しないため、通常は CPU プロファイラによってサンプリングされません。スレッド プロファイルで「スタックを非表示」フィルタを使用することがよくあります。たとえば、gopark, の呼び出しで終わるすべてのスタックを非表示にします。これは、これらのスタックがアイドル状態の goroutine であることが多く、I/O を待機しているスタックよりも重要度が低いことが多いためです。
スレッド プロファイル タイプは、プログラム内のスレッドがプログラムの別の部分が所有するミューテックスを長時間待機しているポイントを特定するのにも役立ちますが、次のプロファイル タイプの方がより有用です。
競合の多いコード
競合プロファイル タイプは、プログラムで最も「必要」なロックを特定します。このプロファイル タイプは Go プログラムで使用できますが、エージェント構成コードで「MutexProfiling: true」を指定して明示的に有効にする必要があります。このコレクションは、特定のロックが goroutine A によってロック解除されたときに、別の goroutine B がロックのロック解除を待機していた回数を「Contentions」指標に記録することで機能します。また、ブロックされた goroutine がロックを待機した時間も記録します（「遅延」指標）。この例では、競合スタックが 1 つあり、ロックの合計待ち時間は 11.03 秒です。
このプロファイルを生成するコードは、ミューテックスを奪い合う 4 つの goroutine で構成されています。
main.go
func contention(d time.Duration) {
contentionImpl(d)
}
func contentionImpl(d time.Duration) {
for {
mu.Lock()
time.Sleep(d)
mu.Unlock()
}
}
...
func main() {
...
for i := 0; i < 4; i++ {
go contention(time.Duration(i) * 50 * time.Millisecond)
}
}このラボでは、Stackdriver Profiler で使用するように Go プログラムを構成する方法について学習しました。また、このツールを使用してパフォーマンス データを収集、表示、分析する方法も学習しました。これで、新しいスキルを Google Cloud Platform で実行する実際のサービスに適用できるようになりました。
Stackdriver Profiler の構成方法と使用方法を学びました。
詳細
- Stackdriver Profiler: https://cloud.google.com/profiler/
- Stackdriver Profiler が使用する Go runtime/pprof パッケージ: https://golang.org/pkg/runtime/pprof/
ライセンス
この作業はクリエイティブ・コモンズの表示 2.0 汎用ライセンスにより使用許諾されています。