Cloud Profiler で本番環境のパフォーマンスを分析する

1. 概要

クライアント アプリとフロントエンド ウェブのデベロッパーは、Android Studio CPU ProfilerChrome に含まれるプロファイリング ツールなどのツールを使用してコードのパフォーマンスを改善するのが一般的ですが、バックエンド サービスに取り組むデベロッパーは、同等の手法をあまり利用していません。Cloud Profiler は、コードが Google Cloud Platform で実行されているかどうかにかかわらず、サービス デベロッパーに同じ機能を提供します。

95c034c70c9cac22.png

このツールは、本番環境のアプリケーションから CPU 使用率とメモリ割り当てに関する情報を収集します。収集した情報からアプリケーションのソースコードが特定されるため、最もリソースを消費しているコード部分を容易に識別できます。コードの特定が難しい場合でも、パフォーマンスの特性を把握できます。このツールで使用されている収集手法はオーバーヘッドが少ないため、本番環境での継続的な使用に適しています。

この Codelab では、Go プログラム用に Cloud Profiler を設定する方法を学び、このツールでどのようなアプリケーション パフォーマンスに関する分析情報を取得できるかについて理解を深めます。

学習内容

  • Cloud Profiler でプロファイリングを行うように Go プログラムを構成する方法。
  • Cloud Profiler を使用してパフォーマンス データを収集、表示、分析する方法。

必要なもの

  • Google Cloud Platform プロジェクト
  • ChromeFirefox などのブラウザ
  • Linux の標準的なテキスト エディタ(vim、emacs、nano など)を使い慣れていること

このチュートリアルをどのように使用されますか?

通読するのみ 通読し、演習を行う

Google Cloud Platform のご利用経験について、いずれに該当されますか?

初心者 中級者 上級者

2. 設定と要件

セルフペース型の環境設定

  1. Cloud コンソールにログインして、新しいプロジェクトを作成するか、既存のプロジェクトを再利用しますGmail アカウントも Google Workspace アカウントもまだお持ちでない場合は、アカウントを作成してください。

96a9c957bc475304.pngb9a10ebdf5b5a448.pnga1e3c01a38fa61c2.png

プロジェクト ID を忘れないようにしてください。プロジェクト ID はすべての Google Cloud プロジェクトを通じて一意の名前にする必要があります(上記の名前はすでに使用されているので使用できません)。以降、このコードラボでは PROJECT_ID と呼びます。

  1. 次に、Google Cloud リソースを使用するために、Cloud Console で課金を有効にする必要があります。

このコードラボを実行しても、費用はほとんどかからないはずです。このチュートリアル以外で請求が発生しないように、リソースのシャットダウン方法を説明する「クリーンアップ」セクションの手順に従うようにしてください。Google Cloud の新規ユーザーは、300 米ドル分の無料トライアル プログラムをご利用いただけます。

Google Cloud Shell

Google Cloud はノートパソコンからリモートで操作できますが、この Codelab では、設定を簡単にするために、Google Cloud Shell(Cloud 上で動作するコマンドライン環境)を使用します。

Cloud Shell をアクティブにする

  1. Cloud Console で、[Cloud Shell をアクティブにする] 4292cbf4971c9786.png をクリックします。

bce75f34b2c53987.png

Cloud Shell を初めて起動した場合は、その内容を説明する画面が(スクロールしなければ見えない位置に)表示されます。その場合は、[続行] をクリックしてください(以後表示されなくなります)。この中間画面は次のようになります。

70f315d7b402b476.png

すぐにプロビジョニングが実行され、Cloud Shell に接続されます。

fbe3a0674c982259.png

この仮想マシンには、必要な開発ツールがすべて用意されています。仮想マシンは Google Cloud で稼働し、永続的なホーム ディレクトリが 5 GB 用意されているため、ネットワークのパフォーマンスと認証が大幅に向上しています。このコードラボでの作業のほとんどは、ブラウザまたは Chromebook から実行できます。

Cloud Shell に接続すると、すでに認証は完了しており、プロジェクトに各自のプロジェクト ID が設定されていることがわかります。

  1. Cloud Shell で次のコマンドを実行して、認証されたことを確認します。
gcloud auth list

コマンド出力

 Credentialed Accounts
ACTIVE  ACCOUNT
*       <my_account>@<my_domain.com>

To set the active account, run:
    $ gcloud config set account `ACCOUNT`
  1. Cloud Shell で次のコマンドを実行して、gcloud コマンドがプロジェクトを認識していることを確認します。
gcloud config list project

コマンド出力

[core]
project = <PROJECT_ID>

上記のようになっていない場合は、次のコマンドで設定できます。

gcloud config set project <PROJECT_ID>

コマンド出力

Updated property [core/project].

3. Cloud Profiler に移動します。

Cloud コンソールで、左側のナビゲーション バーの [Profiler] をクリックして、Profiler UI に移動します。

37ad0df7ddb2ad17.png

または、Cloud コンソールの検索バーを使用して Profiler UI に移動することもできます。検索バーに「Cloud Profiler」と入力して、検索結果を選択します。いずれの場合も、次のように「表示するデータがありません」というメッセージが表示された Profiler UI が表示されます。プロジェクトは新しいため、プロファイリング データはまだ収集されていません。

d275a5f61ed31fb2.png

プロファイリングを行う時間です。

4. ベンチマークをプロファイリングする

ここでは、GitHub で入手できるシンプルな合成 Go アプリケーションを使用します。まだ開いている Cloud Shell ターミナルで(Profiler UI に「No data to display」というメッセージが表示されている間に)、次のコマンドを実行します。

$ 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 回クリックします。

650051097b651b91.png

UI が更新されると、次のような画面が表示されます。

47a763d4dc78b6e8.png

プロファイル タイプ セレクタには、次の 5 つのプロファイル タイプが表示されます。

b5d7b4b5051687c9.png

それでは、各プロファイル タイプと重要な UI 機能を確認し、いくつかのテストを実施してみましょう。この段階では Cloud Shell ターミナルは不要になったため、Ctrl+C キーを押して「exit」と入力して終了します。

5. Profiler データを分析する

データを収集したので、詳しく見てみましょう。ここでは、本番環境でさまざまな種類のパフォーマンスの問題の典型的な動作をシミュレートする合成アプリ(ソースは Github で入手可能)を使用します。

CPU 使用率の高いコード

CPU プロファイル タイプを選択します。UI に読み込まれると、フレーム グラフに load 関数の 4 つのリーフブロックが表示されます。これらのブロックは、CPU 使用率の合計を表します。

fae661c9fe6c58df.png

この関数は、タイトなループを実行して 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」を含む関数を通過する唯一のパスです。このようなフィルタリングは、大きなプログラムの一部に焦点を当てたい場合に便利です(たとえば、プログラムの一部のみを所有している場合など)。

eb1d97491782b03f.png

メモリ使用量の多いコード

[Heap] プロファイル タイプに切り替えます。以前のテストで作成したフィルタは必ず削除してください。これで、alloc によって呼び出された allocImpl がアプリのメモリの主な使用元として表示されるフレームグラフが表示されます。

f6311c8c841d04c4.png

フレームグラフの上にある概要表は、アプリで使用されているメモリの合計量が平均で約 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 集中型コード

プロファイル タイプ セレクタで [スレッド] を選択すると、表示がフレームグラフに切り替わり、幅の大部分が wait 関数と waitImpl 関数で占められます。

ebd57fdff01dede9.png

上のフレームグラフの概要を見ると、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 つで、ロックの合計待機時間は 10.5 秒です。

83f00dca4a0f768e.png

このプロファイルを生成するコードは、ミューテックスを奪い合う 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)
        }
}

6. まとめ

このラボでは、Cloud Profiler で使用するように Go プログラムを構成する方法を学習しました。また、このツールを使用してパフォーマンス データを収集、表示、分析する方法も学びました。これで、新しいスキルを Google Cloud Platform で実行する実際のサービスに適用できるようになりました。

7. 完了

Cloud Profiler の構成と使用方法を学習しました。

詳細

ライセンス

この作業はクリエイティブ・コモンズの表示 2.0 汎用ライセンスにより使用許諾されています。