クエリの統計情報

Spanner では、CPU を最も多く使用したクエリやデータ操作言語（DML）ステートメント、およびすべてのクエリ（変更ストリーム クエリを含む）の集計について、多数の統計情報を保持する組み込みテーブルが用意されています。

クエリの統計情報にアクセスする

Spanner は、SPANNER_SYS スキーマにクエリ統計情報を提供します。SPANNER_SYS データにアクセスする方法は次のとおりです。

• Google Cloud コンソール（データベースの Spanner Studio ページ）。

• gcloud spanner databases execute-sql コマンド。

• クエリ分析情報ダッシュボード。

• executeSql メソッドまたは executeStreamingSql メソッド。

Spanner が提供する次の単一読み取りメソッドは、SPANNER_SYS をサポートしていません。

• 強力な読み取りを実行してテーブルから単一行または複数行を読み取る。
• ステイル読み取りを実行してテーブルから単一行または複数行を読み取る。
• セカンダリ インデックスから単一行または複数行を読み取る。

詳細については、単一読み取りメソッドをご覧ください。

クエリごとにグループ化された CPU 使用率

次のテーブルでは、特定の期間中に CPU 使用率が最も高いクエリが追跡されます。

• SPANNER_SYS.QUERY_STATS_TOP_MINUTE: 1 分間のクエリ
• SPANNER_SYS.QUERY_STATS_TOP_10MINUTE: 10 分間のクエリ
• SPANNER_SYS.QUERY_STATS_TOP_HOUR: 1 時間のクエリ

これらのテーブルには以下のプロパティがあります。

• 各テーブルには、テーブル名で指定された長さの、時間間隔が重複しないデータが含まれています。

• 時間間隔は時刻に基づきます。1 分の間隔は現在の分が終わるときに終了し、10 分の間隔は正時に始まって 10 分ごとに終了し、1 時間の間隔は正時になるたびに終了します。

  たとえば、午前 11 時 59 分 30 秒に SQL クエリで使用可能な最新の時間間隔は次のとおりです。

  • 1 分: 午前 11:58:00～11:58:59
  • 10 分: 午前 11:40:00～11:49:59
  • 1 時間: 午前 10:00:00～10:59:59

• Spanner は統計を SQL クエリのテキストごとにグループ化します。クエリでクエリ パラメータを使用する場合、Spanner はそのクエリのすべての実行を 1 行にグループ化します。クエリで文字列リテラルを使用する場合、Spanner はクエリテキスト全体が同一の場合のみ統計をグループ化し、いずれかのテキストが異なっていれば、各クエリは別々の行として表示されます。バッチ DML の場合、Spanner は、フィンガープリントを生成する前に、連続する同一のステートメントを重複除去することによってバッチを正規化します。

• リクエストタグが存在する場合は、FPRINT がリクエストタグのハッシュです。存在しない場合は、TEXT 値のハッシュです。パーティション化 DML の場合、FPRINT は常に TEXT 値のハッシュです。

• 各行には、指定された期間中に Spanner が統計をキャプチャした特定の SQL クエリのすべての実行に関する統計が含まれています。

• 期間中に実行されたすべてのクエリを Spanner が保存できない場合、指定された期間中の CPU 使用率が最も高いクエリが優先されます。

• 追跡されるクエリには、ユーザーが完了、失敗、キャンセルされたクエリが含まれます。

• 実行したものの、完了していないクエリに固有の統計情報のサブセット:

  • 完了しなかったクエリの実行数と平均レイテンシ（秒単位）。

  • タイムアウトしたクエリの実行数。

  • ユーザーがキャンセルしたか、ネットワーク接続の問題が原因で失敗したクエリの実行数。

• テーブル内のすべての列は null 値を許容できます。

以前に実行されたパーティション化 DML ステートメントのクエリ統計情報には、次のプロパティがあります。

• 成功したパーティション化 DML ステートメントはすべて、厳密に 1 回の実行としてカウントされます。失敗、キャンセル、または実行中のパーティション化 DML ステートメントの実行回数は 0 です。

• パーティション化 DML では、ALL_FAILED_EXECUTION_COUNT、ALL_FAILED_AVG_LATENCY_SECONDS、CANCELLED_OR_DISCONNECTED_EXECUTION_COUNT、TIMED_OUT_EXECUTION_COUNT の統計情報は追跡されません。

• 以前に実行された各パーティション化 DML ステートメントの統計情報は、異なる間隔で表示される場合があります。SPANNER_SYS.QUERY_STATS_TOP_10MINUTE と SPANNER_SYS.QUERY_STATS_TOP_HOUR は、それぞれ 10 分と 1 時間以内に完了するパーティション化 DML ステートメントの集計ビューを提供します。1 時間を超えるステートメントの統計情報を表示するには、クエリの例をご覧ください。

テーブル スキーマ

失敗したクエリに対する EXECUTION_COUNT、AVG_LATENCY_SECONDS、LATENCY_DISTRIBUTION には、構文が正しくないか、一時的なエラーが発生したものの、再試行が成功したクエリが含まれます。これらの統計情報では、失敗したパーティション化 DML ステートメントとキャンセルされたパーティション化 DML ステートメントは追跡されません。

統計情報を集計する

Spanner が特定の期間に統計情報をキャプチャした、すべてのクエリの集計データを追跡するテーブルもあります。

• SPANNER_SYS.QUERY_STATS_TOTAL_MINUTE: 1 分間のクエリ
• SPANNER_SYS.QUERY_STATS_TOTAL_10MINUTE: 10 分間のクエリ
• SPANNER_SYS.QUERY_STATS_TOTAL_HOUR: 1 時間のクエリ

これらのテーブルには以下のプロパティがあります。

• 各テーブルには、テーブル名で指定された長さの、時間間隔が重複しないデータが含まれています。

• 時間間隔は時刻に基づきます。1 分の間隔は現在の分が終わるときに終了し、10 分の間隔は正時に始まって 10 分ごとに終了し、1 時間の間隔は正時になるたびに終了します。

  たとえば、午前 11 時 59 分 30 秒に SQL クエリで使用可能な最新の時間間隔は次のとおりです。

  • 1 分: 午前 11:58:00～11:58:59
  • 10 分: 午前 11:40:00～11:49:59
  • 1 時間: 午前 10:00:00～10:59:59

• 各行には、指定した期間中にデータベースに対して実行されたすべてのクエリの統計がまとめて含まれています。時間間隔ごとに 1 行のみが返され、完了したクエリ、失敗したクエリ、ユーザーがキャンセルしたクエリが含まれます。

• TOTAL テーブルにキャプチャされた統計には、Spanner が TOP テーブルでキャプチャしなかったクエリが含まれる場合があります。

• これらのテーブルの一部の列は、Cloud Monitoring で指標として公開されます。公開される指標は次のとおりです。

  • クエリ実行回数
  • クエリの失敗数
  • クエリのレイテンシ
  • 返された行数
  • スキャンされた行数
  • 返されたバイト数
  • クエリの CPU 時間

  詳細については、Spanner の指標をご覧ください。

テーブル スキーマ

データの保持

Spanner は最低でも、次の期間中に各テーブルのデータを保持します。

• SPANNER_SYS.QUERY_STATS_TOP_MINUTE および SPANNER_SYS.QUERY_STATS_TOTAL_MINUTE: 過去 6 時間を対象とする間隔。

• SPANNER_SYS.QUERY_STATS_TOP_10MINUTE および SPANNER_SYS.QUERY_STATS_TOTAL_10MINUTE: 過去 4 日間を対象とするインターフェース。

• SPANNER_SYS.QUERY_STATS_TOP_HOUR および SPANNER_SYS.QUERY_STATS_TOTAL_HOUR: 過去 30 日間を対象とする間隔。

クエリの例

このセクションには、クエリ統計を取得する SQL ステートメントの例がいくつか含まれています。これらの SQL ステートメントは、クライアント ライブラリ、Google Cloud CLI、または Google Cloud コンソールを使用して実行できます。

特定の期間における各クエリの基本的な統計を一覧表示する

次のクエリは、直前の 1 分間における上位のクエリの生データを返します。

SELECT text,
       request_tag,
       interval_end,
       execution_count,
       avg_latency_seconds,
       avg_rows,
       avg_bytes,
       avg_rows_scanned,
       avg_cpu_seconds
FROM spanner_sys.query_stats_top_minute
ORDER BY interval_end DESC;

1 時間を超えて実行されたパーティション化 DML ステートメントの統計情報を一覧表示する

次のクエリは、直前の 1 時間に上位のパーティション化 DML クエリによって書き込まれた実行回数と平均行数を返します。

SELECT text,
       request_tag,
       interval_end,
       sum(execution_count) as execution_count
       sum(avg_rows_written*execution_count)/sum(execution_count) as avg_rows_written
FROM spanner_sys.query_stats_top_hour
WHERE starts_with(text, "UPDATE") AND query_type = "PARTITIONED_QUERY"
group by text, request_tag, interval_end
ORDER BY interval_end DESC;

CPU 使用率が最も高いクエリを一覧表示する

次のクエリは、直前の 1 時間における CPU 使用率が最も高いクエリを返します。

SELECT text,
       request_tag,
       execution_count AS count,
       avg_latency_seconds AS latency,
       avg_cpu_seconds AS cpu,
       execution_count * avg_cpu_seconds AS total_cpu
FROM spanner_sys.query_stats_top_hour
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_top_hour)
ORDER BY total_cpu DESC;

特定の期間における合計実行回数を確認する

次のクエリは、直近の 1 分間に実行されたクエリの総数を返します。

SELECT interval_end,
       execution_count
FROM spanner_sys.query_stats_total_minute
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_top_minute);

クエリの平均レイテンシを求める

次のクエリは、特定のクエリの平均レイテンシ情報を返します。

SELECT avg_latency_seconds
FROM spanner_sys.query_stats_top_hour
WHERE text LIKE "SELECT x FROM table WHERE x=@foo;";

クエリの 99 パーセンタイル レイテンシを確認する

次のクエリは、過去 10 分間に実行されたクエリ全体にわたる実行時間の 99 パーセンタイルを返します。

SELECT interval_end, avg_latency_seconds, SPANNER_SYS.DISTRIBUTION_PERCENTILE(latency_distribution[OFFSET(0)], 99.0)
  AS percentile_latency
FROM spanner_sys.query_stats_total_10minute
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_total_10minute)
ORDER BY interval_end;

平均レイテンシと 99 パーセンタイル レイテンシを比較すると、実行時間が長い可能性のある外れ値クエリを特定できます。

最も多くのデータをスキャンするクエリを見つける

クエリがスキャンしたデータ量の尺度として、クエリによってスキャンされた行数を使用できます。次のクエリは、直前の 1 時間に実行されたクエリによってスキャンされた行数を返します。

SELECT text,
       execution_count,
       avg_rows_scanned
FROM spanner_sys.query_stats_top_hour
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_top_hour)
ORDER BY avg_rows_scanned DESC;

最も多くのデータを書き込んだステートメントを見つける

クエリによって変更されたデータ量の尺度として、DML によって書き込まれた行数（または書き込みバイト数）を使用できます。次のクエリは、直前の 1 時間に実行された DML ステートメントによって書き込まれた行数を返します。

SELECT text,
       execution_count,
       avg_rows_written
FROM spanner_sys.query_stats_top_hour
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_top_hour)
ORDER BY avg_rows_written DESC;

すべてのクエリでの CPU 使用率の合計

次のクエリは、直前の 1 時間に使用された CPU 時間数を返します。

SELECT (avg_cpu_seconds * execution_count / 60 / 60)
  AS total_cpu_hours
FROM spanner_sys.query_stats_total_hour
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_total_hour);

特定の期間内に失敗したクエリを一覧表示する

次のクエリは、過去 1 分間における上位クエリに対する失敗したクエリの実行回数と平均レイテンシなどの元データを返します。これらの統計情報では、失敗したパーティション化 DML ステートメントとキャンセルされたパーティション化 DML ステートメントは追跡されません。

SELECT text,
       request_tag,
       interval_end,
       execution_count,
       all_failed_execution_count,
       all_failed_avg_latency_seconds,
       avg_latency_seconds,
       avg_rows,
       avg_bytes,
       avg_rows_scanned,
       avg_cpu_seconds
FROM spanner_sys.query_stats_top_minute
WHERE all_failed_execution_count > 0
ORDER BY interval_end;

特定の期間における合計エラー数を調べる

次のクエリは、直近の 1 分間に実行に失敗したクエリの合計数を返します。これらの統計情報では、失敗したパーティション化 DML ステートメントとキャンセルされたパーティション化 DML ステートメントは追跡されません。

SELECT interval_end,
       all_failed_execution_count
FROM spanner_sys.query_stats_total_minute
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_top_minute)
ORDER BY interval_end;

タイムアウトが最も多かったクエリを一覧表示する

次のクエリは、直前の 1 時間におけるタイムアウト数が最も多かったがクエリを返します。

SELECT text,
       execution_count AS count,
       timed_out_execution_count AS timeout_count,
       avg_latency_seconds AS latency,
       avg_cpu_seconds AS cpu,
       execution_count * avg_cpu_seconds AS total_cpu
FROM spanner_sys.query_stats_top_hour
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_top_hour)
ORDER BY timed_out_execution_count DESC;

クエリ実行の成功と失敗の平均レイテンシを求める

次のクエリは、特定のクエリにおける合計平均レイテンシ、成功した実行の平均レイテンシ、失敗した実行の平均レイテンシを返します。 これらの統計情報では、失敗したパーティション化 DML ステートメントとキャンセルされたパーティション化 DML ステートメントは追跡されません。

SELECT avg_latency_seconds AS combined_avg_latency,
       all_failed_avg_latency_seconds AS failed_execution_latency,
       ( avg_latency_seconds * execution_count -
         all_failed_avg_latency_seconds * all_failed_execution_count
       ) / (
       execution_count - all_failed_execution_count ) AS success_execution_latency
FROM   spanner_sys.query_stats_top_hour
WHERE  text LIKE "select x from table where x=@foo;";

クエリ統計情報を使用した CPU 使用率が高いクエリ、またはレイテンシが長いクエリについてのトラブルシューティング

クエリ統計情報は、Spanner データベースの高 CPU 使用率を調査する必要がある場合や、データベースで CPU の負荷がかかるクエリを把握する場合に有用です。大量のデータベース リソースを使用するクエリを調査することで、Spanner ユーザーは運用コストを削減し、場合によっては一般的なシステムのレイテンシを短縮できます。

SQL コードまたは Query Insights ダッシュボードを使用して、データベース内の問題のあるクエリを調査できます。以下のトピックでは、SQL コードを使用してそのようなクエリを調査する方法を説明します。

下記の例では CPU 使用率に重点を置いていますが、同様の手順で、クエリのレイテンシの増加をトラブルシューティングし、レイテンシが最大のクエリを特定できます。CPU 使用率ではなく、レイテンシで期間とクエリを選択するだけです。

調査期間を選択する

まず、アプリケーションでの CPU 使用率が高くなり始めた時間を探すことから始めます。たとえば、2020 年 7 月 24 日午後 5 時（UTC）頃に問題が発生するとします。

選択した期間のクエリ統計情報を収集する

調査を開始する期間が指定されている場合は、その時刻の前後に QUERY_STATS_TOTAL_10MINUTE テーブルで収集された統計情報を確認いたします。このクエリの結果は、一定期間に CPU と他のクエリ統計がどのように変化したかを示します。

次のクエリは、午後 4 時 30 分から午後 5 時 30 分（UTC）までの集計されたクエリ統計情報を返します。クエリでは、表示目的で ROUND を使用して小数点以下の桁数を制限します。

SELECT interval_end,
       execution_count AS count,
       ROUND(avg_latency_seconds,2) AS latency,
       ROUND(avg_rows,2) AS rows_returned,
       ROUND(avg_bytes,2) AS bytes,
       ROUND(avg_rows_scanned,2) AS rows_scanned,
       ROUND(avg_cpu_seconds,3) AS avg_cpu
FROM spanner_sys.query_stats_total_10minute
WHERE
  interval_end >= "2020-07-24T16:30:00Z"
  AND interval_end <= "2020-07-24T17:30:00Z"
ORDER BY interval_end;

このクエリを実行すると、次のような結果が生成されます。

上の結果テーブルでは、avg_cpu 列の平均 CPU 時間は、午後 5 時までの期間（ハイライト表示）に最大であることがわかります。また、スキャンされる平均行数も増大しています。これは、よりコストの高いクエリが午後 4 時 50 分から午後 5 時の範囲で実行されたことを示します。この期間を選択して次のステップで詳しく調査します。

CPU 使用率が高いクエリを特定する

調査する時間間隔を指定して、QUERY_STATS_TOP_10MINUTE テーブルに対してクエリを実行します。このクエリの結果は、CPU 使用率が高いクエリを特定するうえで有用です。

SELECT text_fingerprint AS fingerprint,
       execution_count AS count,
       ROUND(avg_latency_seconds,2) AS latency,
       ROUND(avg_cpu_seconds,3) AS cpu,
       ROUND(execution_count * avg_cpu_seconds,3) AS total_cpu
FROM spanner_sys.query_stats_top_10MINUTE
WHERE
  interval_end = "2020-07-24T17:00:00Z"
ORDER BY total_cpu DESC;

このクエリを実行すると、次のような結果が得られます。

結果テーブルでハイライト表示されている上位 2 つのクエリは、平均 CPU とレイテンシ、実行回数、合計 CPU 数といった点で外れ値です。これらの結果で挙げられた最初のクエリを調査します。

クエリの実行の推移を比較する

調査を絞り込むと、QUERY_STATS_TOP_MINUTE テーブルに注目できます。特定のクエリに関する実行時間の推移を比較すると、返される行数またはバイト数、またはスキャンされた行数と CPU やレイテンシの高くなった行数との相関関係を確認できます。偏差は、データにおける不均一性を示す場合があります。スキャン対象の行数が一貫して多い場合、適切なインデックスが存在しないか、最適な結合順序がない可能性があります。

クエリの text_fingerprint をフィルタリングする次のステートメントを実行して、平均 CPU 使用率とレイテンシが最も高いクエリを調査します。

SELECT interval_end,
       ROUND(avg_latency_seconds,2) AS latency,
       avg_rows AS rows_returned,
       avg_bytes AS bytes_returned,
       avg_rows_scanned AS rows_scanned,
       ROUND(avg_cpu_seconds,3) AS cpu,
FROM spanner_sys.query_stats_top_minute
WHERE text_fingerprint = 5505124206529314852
ORDER BY interval_end DESC;

このクエリを実行すると、次のような結果が返されます。

前の結果を確認すると、スキャンされた行数、使用された CPU 数、レイテンシがすべて午前 9 時頃に大幅に変わったことがわかりました。この数値が大幅に増加した理由を把握するため、クエリテキストを調べて、スキーマの変更がクエリに影響を及ぼしたかどうかを確認します。

次のクエリを使用して、調査するクエリのクエリテキストを取得します。

SELECT text,
       text_truncated
FROM spanner_sys.query_stats_top_hour
WHERE text_fingerprint = 5505124206529314852
LIMIT 1;

次のような結果が返されます。

返されたクエリテキストを調べると、クエリが o_custkey というフィールドでフィルタされていることがわかりました。これは、orders テーブルの非キー列です。以前は、その列には午前 9 時にドロップされるインデックスがありました。このことから、このクエリの費用が変化した理由がわかります。インデックスは再度追加できます。また、クエリが頻繁に実行されていない場合は、インデックスが保持されないので読み取りコストが高くなります。

これまでの調査では、正常に完了したクエリに焦点を合わせ、データベースのパフォーマンスが低下した原因を 1 つ求めていました。次のステップでは、失敗したクエリまたはキャンセルされたクエリに焦点を絞り、そのデータを詳しく調べて分析情報を得る方法について説明します。

失敗したクエリを調査する

正常に完了していないクエリは、タイムアウト、キャンセル、またはその他の理由で失敗する前にリソースを消費し続けます。Spanner は、完了したクエリと失敗したクエリの実行数と消費されたリソースを追跡します。これらの統計情報では、失敗したパーティション化 DML ステートメントとキャンセルされたパーティション化 DML ステートメントは追跡されません。

失敗したクエリがシステム使用率に大きく寄与しているかどうかを確認するには、まず、特定の期間内に失敗したクエリの数を確認します。

SELECT interval_end,
       all_failed_execution_count AS failed_count,
       all_failed_avg_latency_seconds AS latency
FROM spanner_sys.query_stats_total_minute
WHERE
  interval_end >= "2020-07-24T16:50:00Z"
  AND interval_end <= "2020-07-24T17:00:00Z"
ORDER BY interval_end;

さらに詳しく調べると、次のクエリを使用して失敗した可能性が高いクエリを見つけることができます。

SELECT interval_end,
       text_fingerprint,
       execution_count,
       avg_latency_seconds AS avg_latency,
       all_failed_execution_count AS failed_count,
       all_failed_avg_latency_seconds AS failed_latency,
       cancelled_or_disconnected_execution_count AS cancel_count,
       timed_out_execution_count AS to_count
FROM spanner_sys.query_stats_top_minute
WHERE all_failed_execution_count > 0
ORDER BY interval_end;

上のテーブルに示すように、フィンガープリント 5505124206529314852 を含むクエリは、異なる期間で何度も失敗しています。このような障害のパターンが発生した場合は、成功した実行と失敗した実行のレイテンシを比較することをおすすめします。

SELECT interval_end,
       avg_latency_seconds AS combined_avg_latency,
       all_failed_avg_latency_seconds AS failed_execution_latency,
       ( avg_latency_seconds * execution_count -
         all_failed_avg_latency_seconds * all_failed_execution_count
       ) / (
       execution_count - all_failed_execution_count ) AS success_execution_latency
FROM   spanner_sys.query_stats_top_hour
WHERE  text_fingerprint = 5505124206529314852;

ベスト プラクティスを適用する

最適化のための候補クエリを特定したら、次にクエリ プロファイルを確認し、SQL のベスト プラクティスを使用して最適化を試みます。

次のステップ

• 最も古いアクティブ クエリを使用して、最も実行時間の長いアクティブなクエリを特定する。

• 高 CPU 使用率の調査について学習する。

• 別のイントロスペクション ツールについて確認する。

• Spanner が各データベースについて、データベースの情報スキーマ テーブルに保存するその他の情報について学習する。

• Spanner に関する SQL のベスト プラクティスについて確認する。