Spanner では、CPU を最も多く使用したクエリや DML ステートメント、およびすべてのクエリ（変更ストリーム クエリを含む）の集計について、多数の統計情報を保持する組み込みテーブルが用意されています。
対象
SPANNER_SYS データは SQL インターフェースを介してのみ使用できます。例えば:
Google Cloud コンソールのデータベースの Spanner Studio ページ
gcloud spanner databases execute-sqlコマンドQuery Insights ダッシュボード
executeQueryAPI
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値のハッシュです。各行には、指定された期間中に Spanner が統計情報をキャプチャした特定の SQL クエリのすべての実行に関する統計情報が含まれています。
期間中に実行されたすべてのクエリを Spanner が保存できない場合は、指定された期間中の CPU 使用率の最も高いクエリが優先されます。
追跡されるクエリには、ユーザーが完了、失敗、キャンセルされたクエリが含まれます。
実行したものの、完了していないクエリに固有の統計情報のサブセット:
完了しなかったクエリの実行数と平均レイテンシ（秒単位）。
タイムアウトしたクエリの実行数。
ユーザーがキャンセルしたか、ネットワーク接続の問題が原因で失敗したクエリの実行数。
テーブル内のすべての列は null 値を許容できます。
テーブル スキーマ
| 列名 | 型 | 説明 | |
|---|---|---|---|
INTERVAL_END |
TIMESTAMP |
その時間間隔に含まれているクエリが実行された時間間隔の終わり。 | |
REQUEST_TAG |
STRING |
このクエリ オペレーションの省略可能なリクエストタグ。タグの使用の詳細については、リクエストタグによるトラブルシューティングをご覧ください | |
QUERY_TYPE |
STRING |
クエリが PARTITIONED_QUERY か QUERY かを示します。PARTITIONED_QUERY は、PartitionQuery API から取得した partitionToken を使用したクエリです。他のすべてのクエリと DML ステートメントは、QUERY クエリタイプで示されます。
パーティション化 DML のクエリ統計はサポートされていません。
|
|
TEXT |
STRING |
SQL クエリテキスト。約 64 KB に切り捨てられます。
同じタグ文字列を持つ複数のクエリの統計情報は、 REQUEST_TAG に一致するタグ文字列とともに 1 行にグループ化されます。このフィールドには、そうしたクエリのいずれかのテキストのみが表示され、約 64 KB に切り捨てられます。
バッチ DML の場合、SQL ステートメントは、区切り文字のセミコロンを使用して 1 行に連結されます。連続する同一の SQL テキストは、切り詰める前に重複が除去されます。 |
|
TEXT_TRUNCATED |
BOOL |
クエリテキストが切り捨てられたかどうか。 | |
TEXT_FINGERPRINT |
INT64 |
REQUEST_TAG 値のハッシュ（存在する場合）。存在しない場合は、TEXT 値のハッシュ。 |
|
EXECUTION_COUNT |
INT64 |
Spanner が一定期間内にクエリを検出した回数。 | |
AVG_LATENCY_SECONDS |
FLOAT64 |
データベース内での各クエリ実行の平均時間（秒単位）。この平均からは、オーバーヘッドだけでなく、結果セットのエンコードおよび伝送時間も除外されます。 | |
AVG_ROWS |
FLOAT64 |
クエリから返された平均行数。 | |
AVG_BYTES |
FLOAT64 |
送信エンコードのオーバーヘッドを除いた、クエリから返されたデータの平均バイト数。 | |
AVG_ROWS_SCANNED |
FLOAT64 |
クエリでスキャンされた平均行数（削除された値を除く）。 | |
AVG_CPU_SECONDS |
FLOAT64 |
Spanner がクエリを実行するためにすべての操作に費やした CPU 時間の平均秒数。 | |
ALL_FAILED_EXECUTION_COUNT |
INT64 |
クエリが一定期間内に失敗した回数。 | |
ALL_FAILED_AVG_LATENCY_SECONDS |
FLOAT64 |
データベース内で失敗した各クエリ実行の平均時間（秒単位）。この平均からは、オーバーヘッドだけでなく、結果セットのエンコードおよび伝送時間も除外されます。 | |
CANCELLED_OR_DISCONNECTED_EXECUTION_COUNT |
INT64 |
ユーザーがキャンセルしたか、一定期間内にネットワーク接続の問題が原因で失敗したクエリの回数。 | |
TIMED_OUT_EXECUTION_COUNT |
INT64 |
クエリが一定期間内にタイムアウトした回数。 | |
AVG_BYTES_WRITTEN |
FLOAT64 |
ステートメントが書き込んだ平均バイト数。 | |
AVG_ROWS_WRITTEN |
FLOAT64 |
ステートメントによって変更された平均行数。 | |
STATEMENT_COUNT |
INT64 |
このエントリに集計されたステートメントの合計。通常のクエリと DML の場合、これは実行回数と同じです。バッチ DML の場合、Spanner はバッチ内のステートメントの数を取得します。 | |
RUN_IN_RW_TRANSACTION_EXECUTION_COUNT |
INT64 |
クエリが読み取り / 書き込みトランザクションの一部として実行された回数。この列は、クエリを読み取り専用トランザクションに移動することで、ロック競合を回避できるかどうかの判別に役立ちます。 | |
LATENCY_DISTRIBUTION |
ARRAY<STRUCT> |
クエリ実行時間のヒストグラム。値は秒単位で測定されます。
この配列には単一の要素が含まれ、次のタイプがあります。 分散から目的のパーセンタイル レイテンシを計算するには、 詳細については、パーセンタイルと分散値の指標をご覧ください。 |
失敗したクエリに対する EXECUTION_COUNT、AVG_LATENCY_SECONDS、LATENCY_DISTRIBUTION には、構文が正しくないか、一時的なエラーが発生したものの、再試行が成功したクエリが含まれます。
統計情報の集計
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 の指標をご覧ください。
テーブル スキーマ
| 列名 | 型 | 説明 |
|---|---|---|
INTERVAL_END |
TIMESTAMP |
その時間間隔に含まれているクエリが実行された時間間隔の終わり。 |
EXECUTION_COUNT |
INT64 |
Spanner が一定期間内にクエリを検出した回数。 |
AVG_LATENCY_SECONDS |
FLOAT64 |
データベース内での各クエリ実行の平均時間（秒単位）。この平均からは、オーバーヘッドだけでなく、結果セットのエンコードおよび伝送時間も除外されます。 |
AVG_ROWS |
FLOAT64 |
クエリから返された平均行数。 |
AVG_BYTES |
FLOAT64 |
送信エンコードのオーバーヘッドを除いた、クエリから返されたデータの平均バイト数。 |
AVG_ROWS_SCANNED |
FLOAT64 |
クエリでスキャンされた平均行数（削除された値を除く）。 |
AVG_CPU_SECONDS |
FLOAT64 |
Spanner がクエリを実行するためにすべての操作に費やした CPU 時間の平均秒数。 |
ALL_FAILED_EXECUTION_COUNT |
INT64 |
クエリが一定期間内に失敗した回数。 |
ALL_FAILED_AVG_LATENCY_SECONDS |
FLOAT64 |
データベース内で失敗した各クエリ実行の平均時間（秒単位）。この平均からは、オーバーヘッドだけでなく、結果セットのエンコードおよび伝送時間も除外されます。 |
CANCELLED_OR_DISCONNECTED_EXECUTION_COUNT |
INT64 |
ユーザーがキャンセルしたか、一定期間内にネットワーク接続の問題が原因で失敗したクエリの回数。 |
TIMED_OUT_EXECUTION_COUNT |
INT64 |
クエリが一定期間内にタイムアウトした回数。 |
AVG_BYTES_WRITTEN |
FLOAT64 |
ステートメントが書き込んだ平均バイト数。 |
AVG_ROWS_WRITTEN |
FLOAT64 |
ステートメントによって変更された平均行数。 |
RUN_IN_RW_TRANSACTION_EXECUTION_COUNT |
INT64 |
クエリが読み取り / 書き込みトランザクションの一部として実行された回数。この列は、一部のクエリを読み取り専用トランザクションに移動することで、ロック競合を回避できるかどうかの判断に役立ちます。 |
LATENCY_DISTRIBUTION |
ARRAY<STRUCT> |
クエリ全体にわたる実行時間のヒストグラム。値は秒単位で測定されます。
配列を次のように指定します。
分散から目的のパーセンタイル レイテンシを計算するには、 詳細については、パーセンタイルと分散値の指標をご覧ください。 |
データの保持
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 Console を使用して実行できます。
特定の期間における各クエリの基本的な統計情報を一覧表示する
次のクエリは、直前の 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;
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 分間における上位クエリに対する失敗したクエリの実行回数と平均レイテンシなどの元データを返します。
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 分間に実行に失敗したクエリの合計数を返します。
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;
クエリ実行の成功と失敗の平均レイテンシを求める
次のクエリは、特定のクエリにおける合計平均レイテンシ、成功した実行の平均レイテンシ、失敗した実行の平均レイテンシを返します。
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;
このクエリを実行すると、次のような結果が生成されます。
| interval_end | 数 | latency | rows_returned | バイト | rows_scanned | avg_cpu |
|---|---|---|---|---|---|---|
| 2020-07-24T16:30:00Z | 6 | 0.06 | 5.00 | 536.00 | 16.67 | 0.035 |
| 2020-07-24T16:40:00Z | 55 | 0.02 | 0.22 | 25.29 | 0.22 | 0.004 |
| 2020-07-24T16:50:00Z | 102 | 0.02 | 0.30 | 33.35 | 0.30 | 0.004 |
2020-07-24T17:00:00Z |
154 |
1.06 |
4.42 |
486.33 |
7792208.12 |
4.633 |
| 2020-07-24T17:10:00Z | 94 | 0.02 | 1.68 | 106.84 | 1.68 | 0.006 |
| 2020-07-24T17:20:00Z | 110 | 0.02 | 0.38 | 34.60 | 0.38 | 0.005 |
| 2020-07-24T17:30:00Z | 47 | 0.02 | 0.23 | 24.96 | 0.23 | 0.004 |
上の結果テーブルでは、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;
このクエリを実行すると、次のような結果が得られます。
| Fingerprint | 数 | latency | CPU | total_cpu |
|---|---|---|---|---|
5505124206529314852 |
30 |
3.88 |
17.635 |
529.039 |
1697951036096498470 |
10 |
4.49 |
18.388 |
183.882 |
| 2295109096748351518 | 1 | 0.33 | 0.048 | 0.048 |
| 11618299167612903606 | 1 | 0.25 | 0.021 | 0.021 |
| 10302798842433860499 | 1 | 0.04 | 0.006 | 0.006 |
| 123771704548746223 | 1 | 0.04 | 0.006 | 0.006 |
| 4216063638051261350 | 1 | 0.04 | 0.006 | 0.006 |
| 3654744714919476398 | 1 | 0.04 | 0.006 | 0.006 |
| 2999453161628434990 | 1 | 0.04 | 0.006 | 0.006 |
| 823179738756093706 | 1 | 0.02 | 0.005 | 0.0056 |
結果テーブルでハイライト表示されている上位 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;
このクエリを実行すると、次のような結果が返されます。
| interval_end | latency | rows_returned | bytes_returned | rows_scanned | CPU |
|---|---|---|---|---|---|
| 2020-07-24T17:00:00Z | 4.55 | 21 | 2365 | 30000000 | 19.255 |
| 2020-07-24T16:00:00Z | 3.62 | 21 | 2365 | 30000000 | 17.255 |
| 2020-07-24T15:00:00Z | 4.37 | 21 | 2365 | 30000000 | 18.350 |
| 2020-07-24T14:00:00Z | 4.02 | 21 | 2365 | 30000000 | 17.748 |
| 2020-07-24T13:00:00Z | 3.12 | 21 | 2365 | 30000000 | 16.380 |
| 2020-07-24T12:00:00Z | 3.45 | 21 | 2365 | 30000000 | 15.476 |
| 2020-07-24T11:00:00Z | 4.94 | 21 | 2365 | 30000000 | 22.611 |
| 2020-07-24T10:00:00Z | 6.48 | 21 | 2365 | 30000000 | 21.265 |
| 2020-07-24T09:00:00Z | 0.23 | 21 | 2365 | 5 | 0.040 |
| 2020-07-24T08:00:00Z | 0.04 | 21 | 2365 | 5 | 0.021 |
| 2020-07-24T07:00:00Z | 0.09 | 21 | 2365 | 5 | 0.030 |
前の結果を確認すると、スキャンされた行数、使用された CPU 数、レイテンシがすべて午前 9 時頃に大幅に変わったことがわかりました。この数値が大幅に増加した理由を把握するため、クエリテキストを調べて、スキーマの変更がクエリに影響を及ぼしたかどうかを確認します。
次のクエリを使用して、調査するクエリのクエリテキストを取得します。
SELECT text,
text_truncated
FROM spanner_sys.query_stats_top_hour
WHERE text_fingerprint = 5505124206529314852
LIMIT 1;
次のような結果が返されます。
| テキスト | text_truncated |
|---|---|
| o_custkey = 36901 の注文から * を選択; | いいえ |
返されたクエリテキストを調べると、クエリが o_custkey というフィールドでフィルタリングされていることがわかりました。これは、orders テーブルの非キー列です。以前は、その列には午前 9 時にドロップされるインデックスがありました。このことから、このクエリの費用が変化した理由がわかります。インデックスは再度追加できます。また、クエリが頻繁に実行されていない場合は、インデックスが保持されないので読み取りコストが高くなります。
これまでの調査では、正常に完了したクエリに焦点を合わせ、データベースのパフォーマンスが低下した原因を 1 つ求めていました。次のステップでは、失敗したクエリまたはキャンセルされたクエリに焦点を絞り、そのデータを詳しく調べて分析情報を得る方法について説明します。
失敗したクエリを調査する
正常に完了していないクエリは、タイムアウト、キャンセル、またはその他の理由で失敗する前にリソースを消費し続けます。Spanner は、完了したクエリと失敗したクエリの実行数と消費されたリソースを追跡します。
失敗したクエリがシステム使用率に大きく寄与しているかどうかを確認するには、まず、特定の期間内に失敗したクエリの数を確認します。
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;
| interval_end | failed_count | latency |
|---|---|---|
| 2020-07-24T16:52:00Z | 1 | 15.211391 |
| 2020-07-24T16:53:00Z | 3 | 58.312232 |
さらに詳しく調べると、次のクエリを使用して失敗した可能性が高いクエリを見つけることができます。
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;
| interval_end | text_fingerprint | execution_count | failed_count | cancel_count | to_count |
|---|---|---|---|---|---|
| 2020-07-24T16:52:00Z | 5505124206529314852 | 3 | 1 | 1 | 0 |
| 2020-07-24T16:53:00Z | 1697951036096498470 | 2 | 1 | 1 | 0 |
| 2020-07-24T16:53:00Z | 5505124206529314852 | 5 | 2 | 1 | 1 |
上のテーブルに示すように、フィンガープリント 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;
| interval_end | combined_avg_latency | failed_execution_latency | success_execution_latency |
|---|---|---|---|
| 2020-07-24T17:00:00Z | 3.880420 | 13.830709 | 2.774832 |
ベスト プラクティスを適用
最適化のための候補クエリを特定したら、次にクエリ プロファイルを確認し、SQL のベスト プラクティスを使用して最適化を試みます。
次のステップ
最も古いアクティブなクエリを使用して、最も実行時間の長いアクティブなクエリを特定します。
高 CPU 使用率の調査の詳細を確認します。
別のイントロスペクション ツールについて学習します。
Spanner が各データベースについて、データベースの情報スキーマ テーブルに保存するその他の情報について学習します。
Spanner に関する SQL のベスト プラクティスについて学習します。