診断の実行：SQL_PLAN_MONITORを使用してパフォーマンスの問題を分析する

SQLはAPシナリオにおいて、演算子レベルの実行モニタリングが不足しています。例えば、パラレル実行タスクがいくつに分割されたか、偏りがあるかどうか、HASH衝突が深刻かどうか、実行がhangした場合にどの演算子で詰まっているのかといった問題を診断する際に、ログに依存する必要があります。これらの問題を解決するために、OceanBaseデータベースはOracle互換ビューGV$SQL_PLAN_MONITORを導入しました。このビューを使用することで、各演算子の実行に関する重要な詳細を正確に把握できます。

ビューの紹介

SQL演算子レベルのモニタリングをサポートします。各行は演算子インスタンスの実行時のモニタリングデータに対応し、一般的なモニタリングデータと演算子固有のモニタリングデータが含まれます。一般的なモニタリングデータには、演算子が処理したデータ行数、openとcloseの時間、メモリ使用量などが含まれます。演算子固有のモニタリングデータには、HASH衝突率、GI分割block数、table scanでスキャンされた行数などが含まれます。

ビューにおける重要なフィールドの詳細説明は以下のとおりです。

｜OTHERSTAT_9_VALUE｜NUMBER｜実装関連｜ | OTHERSTAT_10_ID | NUMBER | 実装関連 | | OTHERSTAT_10_VALUE | NUMBER | 実装関連 | | OUTPUT_BATCHES | NUMBER | ベクトル化モデルの下で、演算子がget_next_batchインターフェースを呼び出す回数。
OceanBaseデータベース特有のフィールド。 | | SKIPPED_ROWS_COUNT | NUMBER | ベクトル化モードにおいて、演算子の計算処理中に、計算を必要としない行の総数(filterによって除外された行の総数)。
OceanBaseデータベース特有のフィールド。| | DB_TIME | NUMBER | DB Timeは、現在の演算子が消費する実行時間であり、CPU消費時間、必要なI/O (ディスクの読み書き、ネットワークパケットなど)の待ち時間を含みます。単位：us。注：childオペレータの消費時間を除いた実行時間。 | | USER_IO_WAIT_TIME | NUMBER | 現在の演算子に必要なI/O待ち時間。ディスクI/Oやネットワークなどの時間を含みます。単位：us。注：childオペレータの消費時間を除いた実行時間。 |

異なる演算子は、OTHERSTAT_N_VALUEに異なる意味を付与し、異なる値を埋め込むことができます。

具体的には、OTHERSTAT_N_IDの値を利用して、V$SQL_MONITOR_STATNAMEテーブルのクエリを行い、ID列をフィルタリングできます。

パフォーマンス問題分析の例

SQL_PLAN_MONITORは、パフォーマンス問題の分析によく使用されます。

インデックス低下問題分析

obclient [SYS]> select output_rows, plan_operation, OTHERSTAT_3_VALUE scans from gv$sql_plan_monitor where trace_id = 'xxx' and plan_operation like '%TABLE_SCAN';
+-------------+--------------------+--------+
| OUTPUT_ROWS | PLAN_OPERATION     | SCANS  |
+-------------+--------------------+--------+
|           5 | PHY_VEC_TABLE_SCAN | 500072 |

上記のSQLを使用すると、table scan演算子がスキャンした行数と出力した行数をクエリできます。2つが大きく異なる場合、たとえば上記の例では50万行スキャンして5行しか出力していない場合、そのテーブルに適切なインデックスが不足していることを示しています。

JOIN方法選択における低下問題分析

一般的なのはhash joinを使用することですが、実際にはnested-loop joinが生成され、左側のテーブルの行数が多くなると、右側のテーブルが非常に頻繁にrescanされ、性能が低下します。以下のSQLクエリ演算子で最大rescan回数を調べることができます。この値が大きい場合、join方法の選択ミスが発生している可能性が非常に高くなります。

select max(starts) rescans from gv$sql_plan_monitor where trace_id = 'xxx';

汎用的な分析方法

個別に上記の問題が存在するかどうかを判断するのは少し手間がかかるかもしれません。多くの場合、一般的な方法を用いて、計画のどの部分が比較的時間を要しているかを直接判断できます。

1. まず、以下のSQLクエリを使用して、このqueryに対応するSQL_PLAN_MONITORレコードをクエリします。クエリ結果には、各演算子のopen、close、最初の行の出力、最後の行の出力の時間が含まれています。

   select plan_line_id, concat(lpad(' ', plan_depth, ' '), plan_operation) op, sum(output_rows) rowss, sum(STARTS) rescan, min(first_refresh_time) open_time, max(last_refresh_time) close_time, min(first_change_time) first_row_time, max(last_change_time) last_row_eof_time, count(1) threads from gv$sql_plan_monitor where trace_id = 'xxx' group by plan_line_id, plan_operation, plan_depth order by 1;
   

2. クエリ結果を上から下へ確認します。まず、最上位の0番演算子について、そのLAST_ROW_EOF_TIMEはCLOSE_TIMEとほぼ等しくなるはずです。これがhash join演算子であると仮定すると、hash joinの実行時には、まず左側のすべてのデータを受け取ってhashテーブルを構築し、次に右側の子ノードからデータを取り出して、行ごとにhashテーブルをprobeします。そこで、演算子1、即ちhash joinの左側の子ノードのLAST_ROW_EOF_TIMEを観察することができます。

   1. もし演算子1のLAST_ROW_EOF_TIMEが大きい場合、hash joinの左側のブランチの実行に多くの時間が費やされていることを意味します。そのため、演算子1の下にあるサブプランをさらに観察することができます。
   2. もし演算子1のLAST_ROW_EOF_TIMEが小さい場合、大部分の時間はhash joinの右側のブランチの実行とhashテーブルの検出に費やされていることを示唆しています。この場合、hash join演算子0の右側の子ノードのサブプランをさらに観察することができます。

以下の計画を例に、分析方法を説明します。

まず、最上位がmerge join演算子であることに着目します。この演算子は、最初に左側の子ノードから1行取得し、次に右側の子ノードから1行取得します。演算子のopen時間は25.792777秒、merge joinの左側の子ノードが最初の行を出力した時間は25.793831秒、merge joinの右側の子ノードが最初の行を出力した時間は27.572661秒であることから、merge joinの右側のブランチは最初の行のデータを出力するために1秒以上の時間を費やしていることがわかります。

merge joinの右側の子ノードをさらに観察すると、sort演算子であることがわかります。この演算子は、下層からすべてのデータを受け取り、ソートしてから上層に出力します。ROWSSフィールドから、この演算子が160万行のデータを受け取っていることがわかります。このデータのソートには多くの時間がかかります。ソートキーにインデックスを作成することで、ソート処理を省略し、パフォーマンスを向上させることができます。

| ==========================================================        |
| |ID|OPERATOR                  |NAME|EST.ROWS|EST.TIME(us)|        |
| ----------------------------------------------------------        |
| |0 |MERGE JOIN                |    |1       |5           |        |
| |1 |├─SORT                    |    |1       |3           |        |
| |2 |│ └─COLUMN TABLE FULL SCAN|T1  |1       |3           |        |
| |3 |└─SORT                    |    |1       |3           |        |
| |4 |  └─TABLE FULL SCAN       |T0  |1       |3           |        |
| ==========================================================        |

select plan_line_id, concat(lpad(' ', plan_depth, ' '), plan_operation) op, sum(output_rows) rowss, sum(STARTS) rescan, min(first_refresh_time) open_time, max(last_refresh_time) close_time, min(first_change_time) first_row_time, max(last_change_time) last_row_eof_time, count(1) threads from gv$sql_plan_monitor where trace_id = 'YC3500BA2DAC4-0006198CC947196A-0-0' group by plan_line_id, plan_operation, plan_depth order by 1;

+--------------+-----------------------+---------+--------+----------------------------+----------------------------+----------------------------+----------------------------+---------+
| PLAN_LINE_ID | OP                    | ROWSS   | RESCAN | OPEN_TIME                  | CLOSE_TIME                 | FIRST_ROW_TIME             | LAST_ROW_EOF_TIME          | THREADS |
+--------------+-----------------------+---------+--------+----------------------------+----------------------------+----------------------------+----------------------------+---------+
|            0 | PHY_MERGE_JOIN        |       0 |      0 | 2024-05-29 16:29:25.792777 | 2024-05-29 16:29:27.664014 | NULL                       | 2024-05-29 16:29:27.664014 |       1 |
|            1 |  PHY_SORT             |       2 |      0 | 2024-05-29 16:29:25.792777 | 2024-05-29 16:29:27.664014 | 2024-05-29 16:29:25.793831 | NULL                       |       1 |
|            2 |   PHY_VEC_TABLE_SCAN  |       2 |      0 | 2024-05-29 16:29:25.792777 | 2024-05-29 16:29:27.664014 | 2024-05-29 16:29:25.793831 | 2024-05-29 16:29:25.793831 |       1 |
|            3 |  PHY_SORT             | 1599984 |      0 | 2024-05-29 16:29:25.792777 | 2024-05-29 16:29:27.664014 | 2024-05-29 16:29:27.572661 | 2024-05-29 16:29:27.664014 |       1 |
|            4 |   PHY_VEC_TABLE_SCAN  | 1599984 |      0 | 2024-05-29 16:29:25.792777 | 2024-05-29 16:29:27.664014 | 2024-05-29 16:29:25.793831 | 2024-05-29 16:29:26.642023 |       1 |
+--------------+-----------------------+---------+--------+----------------------------+----------------------------+----------------------------+----------------------------+---------+

SQL PLAN MONITORを使ってパフォーマンスの問題を分析するには、さまざまな演算子の実行方法についてある程度の理解が必要であることがわかります。以下に、一般的な演算子の実行方法をいくつか示します。

1. ストリーミング出力。下層からデータを受け取りつつ、上層にデータを出力します。

   limit, merge group by, merge distinct, subplan scan

2. ブロッキング。下層からすべてのデータを受け取った後、上層へデータを出力します。

   sort, hash group by, hash distinct, material

3. その他

   演算子	実行方法
   merge join/union/intersect/except	2つの子ノードから同時にデータを受け取り、左側を先に収集します。
   ｜nested-loop join,subplan filter｜ 最初の子ノードから行単位でデータを受け取り、次に他の子ノードをrescanしてデータを受け取ります。
   hash join/union/intersect/except	まず左の子ノードからすべてのデータを収集し、次に右の子ノードからデータを収集します。

関連ドキュメント

• GV$SQL_PLAN_MONITORビューの詳細については、GV$SQL_PLAN_MONITOR (MySQLモード)および GV$SQL_PLAN_MONITOR (Oracleモード)を参照してください。