OpenCensus を用いた Cloud Spanner 上のアプリケーション パフォーマンスのトラブルシューティング

※この投稿は米国時間 2022 年 2 月 8 日に、Google Cloud blog に投稿されたものの抄訳です。

このチュートリアルでは、OpenCensus を使用して、Cloud Spanner のワークロードでクライアントサイドの指標記録を構成する方法を紹介します。Cloud Spanner は、サーバーサイドの多くの有用な指標を表示しますが、アプリケーションは、Cloud Spanner のクライアント ライブラリが発する指標を収集することで、さらなるメリットを得ることができます。たとえば、セッションやトランザクションに関連する情報はクライアントサイドの指標にのみ含まれます。これらの OpenCensus の指標は、通常の動作からの異常な逸脱を発見し、その原因を調査するのに十分なデータを提供します。

詳細を紹介する前に、OpenCensus について簡単に紹介します。

OpenCensus は、C++、Java、Go、Python、JavaScript、.Net、Ruby、PHP 用のライブラリを提供しています。これらのライブラリは、アプリケーションから分散型のトレースや指標を取得し、このテレメトリを Cloud Monitoring、Cloud Trace、Prometheus、Jaeger、Datadog などのバックエンドに送信します。詳細情報およびユーザー マニュアルは、opencensus.io でご覧いただけます。このブログでは、例題を挙げて Java でのクライアントサイドの指標について説明します。

始める前に

• Java 8 以上と Apache Maven を使用していることを確認してください。

• この例は Google Cloud 上で実行され、指標を Cloud Monitoring に、Trace を Cloud Trace に出力しますが、コードはどこでも実行でき、OpenCensus でサポートされているものであれば任意のエクスポータを利用できます。

セッション プールの使用と不正使用を調査するためのクライアントサイドの指標

これらのシンプルな指標により、セッションの最小設定と最大設定を変更した場合の影響や、セッション リークの検出など、さまざまな問題を診断できます。Cloud Spanner の Java および Go のクライアント ライブラリには、以下の指標が含まれています。

セッションは、Cloud Spanner API の中心的なコンセプトです。すべての Spanner の読み取りと書き込みは、セッションを通じて行われます。1 つのセッションには、常に 1 つのアクティブなトランザクションしか存在しません。

1. ユーザーが構成可能な最大許容セッション数の追跡

cloud.google.com/java/spanner/max_allowed_sessions: 許可される最大セッション数が表示されます。プール内の現在のセッション数がこれより少なく、すべて使用されている場合は、新しい操作に対して新しいセッションが作成されます。現在の使用中のセッションがこの数と同じで、新しいリクエストが来た場合、プールはブロックするか失敗するかのどちらかになります。この指標は、データベース名、インスタンス名、ライブラリのバージョンによって表示されます。

2. 最大使用セッション数の追跡

cloud.google.com/java/spanner/max_in_use_sessions: この値は、直近のメンテナンスの時間枠の間隔で使用されたセッションの最大数を示しており、データベース内のアクティビティの量を示すものです。これは実行されるデータベースとインスタンス名に固有のものです。メンテナンスの時間枠は、10 分間の間隔で設定されます。メンテナンスの時間枠が完了すると、値はゼロにリセットされます（その後、再び増加に転じます）。この値は、セッションがプールからチェックアウトされるたびに更新されます。

3. プールでのセッション数の追跡

cloud.google.com/java/spanner/num_sessions_in_pool: この指標では、現時点でプールに存在するセッションの総数について、インスタンス レベルおよびデータベース レベルのデータを確認できます。この指標は、num_in_use_sessions、num_sessions_being_prepared、num_read_sessions および num_write_prepared_sessions の数を示しています。num_sessions_being_prepared という指標は現在サポートされておらず、デフォルトでは 0 に設定されています。num_read_sessions と num_write_prepared_sessions を合わせて、プール内のセッション数を示します。num_in_use_sessions は、現在使用されているセッションの数を示します。

4. セッション タイムアウトを取得するためのリクエスト数の追跡（累積）

cloud.google.com/java/spanner/get_session_timeouts: これは、サーバー プロセスが開始されてから、プールが枯渇したために許可されないままタイムアウトした（セッションを要求したスレッドが待機キューに入れられたまま、他のスレッドによってプールに解放された）get セッションの総数を示します。この値を、現在の in_use_sessions の値と合わせて考えることで、データベースの負荷を把握できます。この指標は、データベース名、インスタンス名、ライブラリのバージョンで表示されます。このような状況では、現在の in_use_sessions の値が max_allowed_sessions と等しい（またはほぼ等しい）状態を常にモニタリングする必要があります。これは、何かがうまくいっていないことを示していますが、アプリケーションとセッション プールが上限値に達していても、実際には枯渇していないという可能性もあります。

以下は、この問題を解決するための手順です。

1. Spanner のインスタンスを閉じたときに発生する LeakedSessionExceptions について、アプリケーション ログを確認します。（Spanner インスタンスを閉じるとセッション プールが閉じられ、セッション プールを閉じると、プールを閉じる前にセッション プールにチェックバックされていないすべてのセッションに対して LeakedSessionExceptions が発生します。）

2. LeakedSessionExceptions が発生している場合、これらのスタック トレースを調査し、セッションをチェックアウトしているにもかかわらず、再チェックインしていないコードを修正します。たとえば、すべての ResultSets を閉じなかった場合や、読み取り専用のトランザクションを閉じなかった場合です。

3. LeakedSessionExceptions が発生していない場合、SessionPool.maxSessions が増加します。

5. 獲得したセッション数と解放されたセッション数の追跡

cloud.google.com/java/spanner/num_acquired_sessions: この指標では、獲得したセッションの総数を確認できます。

cloud.google.com/java/spanner/num_released_sessions: この指標では、リリースされた（破棄された）セッションの総数を確認できます。

理想的な状態では、獲得したセッション数はリリースしたセッション数と同じ（またはほぼ同じ）になるはずです。この 2 つの差が着実に大きくなっている場合は、確実にセッション リークが発生していることを示しています。この指標はシステムの負荷を示すものでもあるので、タイムラインで表示すれば、負荷の高いときと低いときを認識できます。

6. 往復レイテンシと GFE レイテンシの追跡

OpenCensus/grpc.io/client/roundtrip_latency: この指標は、API リクエストの最初のバイトが送信されてから、レスポンスの最後のバイトが受信されるまでの時間を示します。

cloud.google.com/java/spanner/gfe_latency: この指標は、Google のネットワークが RPC を受信してから、レスポンスの最初のバイトを読み返すまでのレイテンシを示すものです。

cloud.google.com/java/spanner/gfe_header_missing_count: この指標は、server-timing ヘッダーなしで受信した RPC レスポンスの数を示します。これは、多くの場合、RPC が Google のネットワークに到達しなかったことを意味します。

現在、gfe_latency および gfe_header_missing_count 指標は、Cloud Spanner の Java クライアント ライブラリでのみ利用可能です。現在、Go クライアント ライブラリでの対応を進めています。

クライアント、GFE、Spanner のクエリ実行の間のレイテンシを比較することで、ユーザーやサポート エンジニアは、Spanner の動作が遅い原因を絞り込むことができるはずです。例えば、次のようになります。

1. 往復レイテンシが高く、GFE レイテンシが高く、Cloud Spanner クエリのレイテンシが高い場合: クエリ実行時のレイテンシが高い場合、ユーザーはスキーマ、インデックス、クエリの最適化に注力することでパフォーマンスを向上できます。

2. 往復レイテンシが高く、GFE レイテンシが高く、Cloud Spanner クエリレイテンシが低い場合: アプリケーションのエンドツーエンドのレイテンシと Google Front End のレイテンシが予想よりも高く、Cloud Spanner クエリ実行のレイテンシ指標と GFE レイテンシがエンドツーエンドの合計レイテンシよりも大幅に低い場合は、GFE に問題がある可能性があります。ユーザーはこの情報をサポート チケットに記載することで、サポート エンジニアは GFE のトラブルシューティングに集中できます。

3. 往復レイテンシが高く、GFE レイテンシが低く、Cloud Spanner のクエリのレイテンシが低い場合: アプリケーションのレイテンシが予想以上に高くても、Cloud Spanner のクエリ実行のレイテンシと GFE レイテンシの指標がエンドツーエンドの合計レイテンシよりも大幅に低い場合、アプリケーション コードに問題がある可能性があります。アプリケーションのパフォーマンスが低下し、一部のコードパスの処理速度が遅くなると、各リクエストの全体のレイテンシが増加する可能性があります。この問題を確認するには、アプリケーションのベンチマークを取り、想定以上に遅いコードパスを特定します。また、Cloud Spanner と通信を行うコードをコメントにし、全体のレイテンシを再度測定することもできます。全体のレイテンシに大きな変化が見られない場合は、Cloud Spanner が高レイテンシの原因とは考えられません。これは、クライアントと GFE の間のネットワークの問題を示している可能性があり、ネットワーク ルーティングの修正が必要です。

指標を設定して有効にするには、以下の手順を実行します。

ステップ 1 - 強化された指標の設定と有効化

Cloud Spanner クライアントからクライアントサイドの指標や分散トレースを取得するためには、OpenCensus Observability Ready Util for Java を使用する必要があります。本パッケージは、デベロッパーが簡単に OpenCensus を利用できるように、便利なラッパーを提供します。

OpenCensus Observability Ready Util は、デフォルトで以下のことを行います。

• 基本的な RPC（gRPC サービスに対する単一の呼び出しで、ストリーミングまたは 1 つの呼び出し）ビューで、以下のようなサーバーサイドの指標を表示可能。GFE のレイテンシの指標を利用するには、ビューを登録する必要がある。

• 確率的なサンプリング レートを 0.0001（10,000 分の 1）に設定する

• トレースを収集するために OCAgent Trace Exporter を作成し登録する

• OCAgent Metrics Exporter を作成して登録し、指標を収集する

Maven を使用している場合は、pom.xml ファイルに以下の内容を追加します。

Gradle を使用している場合は、依存関係に以下を追加します。

OpenCensus を構成し、ビューを登録します。

Cloud Spanner クライアントは、OpenCensus Metrics をサポートしており、クライアントの内部を知ることができ、本番環境の問題をデバッグ / トラブルシューティングするのに役立ちます。cloud.google.com/java/spanner/ の接頭辞が付いた指標は、運用レベルの指標に焦点を当てています。RPC レベルの指標は、grpc.io/client/ を接頭辞とする gRPC の指標から得ることができます。

ステップ 2 - OpenCensus エージェントのデプロイと実行

ocagent は、ソース、バイナリ、または Docker イメージから直接実行できます。エージェントのインストールとビルドは、こちらの指示に従ってください。

ステップ 3 - Stackdriver Metrics Explorer でキャプチャした指標の確認

Spanner クライアントで指標を有効にした後、Stackdriver Metrics Exporter を使って指標を表示できます。

1. Metrics Explorer に移動します。

2. 検索のために [Resource type] と [Metrics] の項目に、cloud.google.com/java/spanner/in_use_sessions と入力します。

3. リストからこの指標を選択します。

4. 右側のペインには、使用中のセッション数が表示されます。

ステップ 4 - クリーンアップ

このチュートリアルでは、複数の GCP コンポーネントを使用しているため、作業終了後は必ず関連するリソースを削除してください。

Java アプリケーションのサンプル: 

デモを実行して指標を取得するには、以下のアプリケーションのクローンを作成して Cloud Spanner 上にサンプルロードを生成し、Opencensus の指標収集を有効にする必要があります。詳細なガイドは以下をご覧ください。

1. 次のコマンドを使用して、チュートリアルのソース リポジトリのクローンを作成します。$ git clone
   https://github.com/cloudspannerecosystem/spanner-oc-java.git

2. プロジェクト固有の設定で Java アプリケーションを更新します。次のコマンドを使用して、Java のソースが入っているフォルダに移動します。
   $ cd src/main/java/com/example/spanner

3. Cloud Spanner のインスタンスとデータベースを使用するために、アプリケーション コードで環境変数を設定します。

4. 次のコマンドを使用して、例をビルドします。$ mvn clean package

5. 次の Maven コマンドを実行してプログラムをビルドし、実行します。$ mvn exec:java -Dexec.mainClass=com.example.spanner.App

6. http://localhost:8080/spanner/ にアクセスして、読み取りリクエストを送信します。

OpenCensus と Cloud Spanner のインテグレーションは、1 つまたは複数の指標における通常とは異なる偏差を検出できることが重要です。最近使用されたセッション数は、測定値が妥当か問題の兆候であるかを知るためにベースラインが必要な指標の良い例です。指標のベースラインを設定すると、通常の動作からの予期しない逸脱の原因を検出して調査できます。

このシンプルなスタートガイドが、お客様のスタートアップに役立つことを願っています。提案や質問がありましたら、下記のコメント セクションでお知らせください。