トランザクションの統計情報で Cloud Spanner のパフォーマンスの可視性を高める
Google Cloud Japan Team
※この投稿は米国時間 2020 年 6 月 28 日に、Google Cloud blog に投稿されたものの抄訳です。
Cloud Spanner は Google のスケーラブルなフルマネージド リレーショナル データベース サービスです。先日リリースした、Cloud Spanner の新機能であるトランザクションの統計情報を利用すると、SQL クエリを実行してデータベースのトランザクションの統計情報を複数の期間で取得できます。これらの統計情報により、トランザクションのパフォーマンスを促進している要因をさらに詳細に把握できます。
この投稿では、トランザクションの統計情報を使用して、Cloud Spanner データベースの競合に関係するトランザクションを特定する方法についてご紹介します。
Spanner のトランザクションについて
Spanner 内のトランザクションは、データベース内の列、行、テーブルにまたがる時間内の単一論理ポイントにおいてアトミックに実行される読み取りと書き込みのセットの実行に使用されます。Spanner でのトランザクションの仕組みを把握し、競合を最も適切にトラブルシューティングする場合に有効です。
トランザクションの統計情報
トランザクションの統計情報はアプリケーションによるデータベースの使用状況について分析情報を提供し、パフォーマンスの問題を調査する際に役立ちます。たとえば、競合を引き起こしている可能性がある実行速度の遅いトランザクションの有無を確認したり、特定の列に対する大量の更新など、高負荷の潜在的な原因を特定したりできます。
Spanner にはトランザクションに関する統計情報を保存する組み込みテーブルが用意されています。SQL ステートメントを使用すると、下記の SPANNER_SYS.TXN_STATS* テーブルから統計情報を取得できます。
トランザクションの集計統計情報
Spanner は次のシステム テーブルに集計されたトランザクションの統計情報をキャプチャします。
●SPANNER_SYS.TXN_STATS_TOTAL_MINUTE: 1 分間隔のトランザクション
●SPANNER_SYS.TXN_STATS_TOTAL_10MINUTE: 10 分間隔のトランザクション
●SPANNER_SYS.TXN_STATS_TOTAL_HOUR: 1 時間間隔のトランザクション
上記テーブルの各行には、特定の期間中にデータベースに対して実行されたすべてのトランザクションの集計統計情報が含まれています。そのため、上記のテーブルには、指定した時間間隔に 1 行のみが格納されます。
上位のトランザクションの統計情報
Spanner は次のシステム テーブルに書き込まれたレイテンシ、commit の試行回数、バイト数など、トランザクションの統計情報をキャプチャします。
●SPANNER_SYS.TXN_STATS_TOP_MINUTE: 1 分間隔のトランザクション
●SPANNER_SYS.TXN_STATS_TOP_10MINUTE: 10 分間隔のトランザクション
●SPANNER_SYS.TXN_STATS_TOP_HOUR: 1 時間間隔のトランザクション
期間中にテーブルで実行されたすべてのトランザクションの統計情報を Spanner が保存できない場合、特定の期間中のレイテンシ、commit の試行回数、バイト数が最も高いトランザクションが優先されます。
Spanner でデータベース競合の根本原因を突き止める
トランザクションの統計情報は、データベースで競合を引き起こしているトランザクションをデバッグして特定するのに役立ちます。次に、データベースの競合が原因で書き込みレイテンシが高いデータベースを例にとり、この機能を使用してデバッグする方法について説明します。
ステップ 1: レイテンシが高い期間を特定する
このような期間は、Cloud Spanner を使用しているアプリケーションに見つかることがあります。下記の例では、「2020-05-17T17:20:00」前後に問題が発生し始めています。
ステップ 2: 集計されたトランザクション指標が、指定した期間にどのように変化したかを確認する
TXN_STATS_TOTAL_10MINUTE テーブルに対してクエリを実行し、問題が生じ始めた時刻前後のデータを取得します。このクエリの結果は、その期間中にレイテンシなどのトランザクション統計情報がどのように変化したかについての手がかりになる可能性があります。
たとえば、このクエリは、「2020-05-17T16:40:00」から「2020-05-17T19:40:00」までに集計されたトランザクションの統計情報を取得できます。これにより、10 分間ごとに結果が 1 行ずつ返されます。以下のようになります。
クエリ
出力
結果を見ると、ハイライトされている期間は、集計されたレイテンシと中断回数の数値が高めになっています。集計されたレイテンシや中断回数の数値が高い 10 分の期間（終了時刻が「2020-05-17T18:40:00」の期間など）を選んでみます。次のステップで、レイテンシや中断回数の数値が高い原因となっているトランザクションを確認できます。
ステップ 3: 高レイテンシの原因になっているトランザクションを正確に特定する
TXN_STATS_TOP_10MINUTE テーブルに対してクエリを実行し、前のステップで選んだ期間のデータを取得します。このクエリの結果は、レイテンシや中断回数の数値が高いトランザクションについての手がかりになる可能性があります。
以下のクエリを使用して、終了時刻が「2020-05-17T18:40:00」の期間の合計レイテンシから、特にパフォーマンスに影響するトランザクションを降順で取得します。
クエリ
出力
上記の表でハイライト表示されている行は、commit の中断回数が多いためにレイテンシが高くなっているトランザクションの例です。
ステップ 4: レイテンシが高いトランザクションの間の類似性を確認する
中断回数が多いトランザクションの read_columns、write_constructive_columns、write_delete_tables 列を取得できます（次のステップに役立つ fprint の値にも注目）。これにより、高レイテンシのトランザクションが同じ列のセットで動作しているかどうかを確認することが可能です。
クエリ
出力
出力が示すとおり、合計レイテンシの平均が最も高いトランザクションが同じ列を読み取っています。このトランザクションで同じ列 TestHigherLatency._exists に書き込まれているため、書き込みの競合も見られます。
ステップ 5: 影響を受ける期間についてレイテンシが高いトランザクションの状態を確認する
このトランザクションの状態に関連付けられた統計情報が指定の期間でどのように変化したかを確認できます。次のクエリを使用します。$FPRINT は、前のステップで取得した、レンテンシが高いトランザクションのフィンガープリントです。
クエリ
出力
上記の出力では、ハイライト表示された期間の合計レイテンシが高くなっています。また、commit レイテンシ（commit_latency）はあまり変化していないものの、合計レイテンシが高い場合は常に、commit_attempt_count と commit_abort_count も高くなります。トランザクションの commit がより頻繁に中断されるため、commit の再試行による commit の試行回数も多くなります。
上記のトラブルシューティング手順を使用し、競合に関係しているトランザクションが見つかりました。commit の中断回数が多いと、レイテンシが高くなります。次のステップでは、アプリケーションが受信した commit 中断のエラー メッセージを確認して中断の原因を把握します。アプリケーションのログを調べると、この期間にアプリケーションによってワークロードが実際に変更されたことがわかります。これはおそらく、他のトランザクションの状態が attempts_per_second の高い数値で示され、別のトランザクション（クリーンアップの夜間ジョブかもしれません）が追加のロック競合の原因になった可能性があります。
Cloud Spanner のトランザクションの統計情報では、データベースの動作についてオブザーバビリティが改善され、より詳細に分析できるようになります。トランザクションの統計情報とクエリ統計を併用すると、Spanner のワークロードを調整し最適化できます。
Spanner の利用を開始するには、Cloud Console でインスタンスを作成するか、Spanner Qwiklab でお試しください。
- By ソフトウェア エンジニア Santhosh Yeduguri
