メインコンテンツまでスキップ

Analyze query profile

クエリプロファイルの分析

このトピックでは、クエリプロファイルのチェック方法について説明します。クエリプロファイルは、StarRocksクラスタのクエリパフォーマンスに影響を与えるボトルネックを迅速に特定するのに役立ちます。クエリプロファイルは、クエリに関与するすべてのワーカーノードの実行情報を記録します。

クエリプロファイルを有効にする

v2.5より前のStarRocksのバージョンでは、変数is_report_successtrueに設定することでクエリプロファイルを有効にすることができます。

SET is_report_success = true;

v2.5以降のStarRocksのバージョンでは、変数enable_profiletrueに設定することでクエリプロファイルを有効にすることができます。

SET enable_profile = true;

ランタイムプロファイル

v3.1以降、StarRocksはランタイムプロファイル機能をサポートしており、クエリが完了する前にクエリプロファイルにアクセスすることができます。

この機能を使用するには、enable_profiletrueにするだけでなく、セッション変数runtime_profile_report_intervalを設定する必要があります(単位:秒、デフォルト:10)。runtime_profile_report_intervalは、プロファイルのレポート間隔を制御し、デフォルトでは10秒に設定されており、クエリが10秒以上かかると自動的にランタイムプロファイル機能が有効になります。

SET runtime_profile_report_interval = 10;

ランタイムプロファイルは通常のクエリプロファイルと同じ情報を表示します。実行中のクエリのパフォーマンスに関する貴重な情報を得るため、通常のクエリプロファイルと同様に分析することができます。

ただし、ランタイムプロファイルは不完全な場合があります。なぜなら、実行計画の一部のオペレータは他に依存する場合があるためです。実行中のオペレータ(RUNNINGとマークされている)と完了したオペレータを簡単に区別するために、ランタイムプロファイルでは実行中のオペレータにはStatus: Runningとマークが付けられます。

クエリプロファイルにアクセスする

注意

StarRocksのエンタープライズエディションを使用している場合、StarRocks Managerを使用してクエリプロファイルにアクセスして視覚化することができます。

StarRocksのコミュニティエディションを使用している場合、次の手順に従ってクエリプロファイルにアクセスします。

  1. ブラウザでhttp://<fe_ip>:<fe_http_port>を開きます。
  2. 表示されるページで、ナビゲーションパネルの上部にあるクエリをクリックします。
  3. 完了したクエリのリストから確認したいクエリを選択し、Profile列のリンクをクリックします。
img

すると、クエリプロファイルが表示される新しいページにリダイレクトされます。

img

クエリプロファイルの解釈

クエリプロファイルの構造

以下はクエリプロファイルの例です。

Query:
Summary:
Planner:
Execution Profile 7de16a85-761c-11ed-917d-00163e14d435:
Fragment 0:
Pipeline (id=2):
EXCHANGE_SINK (plan_node_id=18):
LOCAL_MERGE_SOURCE (plan_node_id=17):
Pipeline (id=1):
LOCAL_SORT_SINK (plan_node_id=17):
AGGREGATE_BLOCKING_SOURCE (plan_node_id=16):
Pipeline (id=0):
AGGREGATE_BLOCKING_SINK (plan_node_id=16):
EXCHANGE_SOURCE (plan_node_id=15):
Fragment 1:
...
Fragment 2:
...

クエリプロファイルは次の3つのセクションで構成されます。

  • Fragment: 実行ツリー(execution tree)。一つのクエリは、1つ以上のフラグメントに分割することができます。
  • Pipeline: 実行チェーン(execution chain)。実行チェーンは分岐を持ちません。フラグメントは複数のパイプラインに分割することができます。
  • Operator: パイプラインは複数のオペレータから構成されます。
img

フラグメントは複数のパイプラインから構成されます。

主なメトリクス

クエリプロファイルには、クエリの実行の詳細を示す多くのメトリクスが含まれています。ほとんどの場合、オペレータの実行時間と処理されたデータのサイズに注目するだけで十分です。ボトルネックを見つけたら、それに応じて解決策を見つけることができます。

概要

メトリック

説明

Total

クエリの総実行時間。計画、実行、プロファイル作成にかかる時間を含みます。

QueryCpuCost

クエリの総CPU時間。CPU時間のコストは並列プロセスごとに集計されます。そのため、このメトリックの値はクエリの実際の実行時間よりも大きい場合があります。

QueryMemCost

クエリの総メモリコスト。

オペレータの共通メトリクス

メトリック

説明

OperatorTotalTime

オペレータの総CPU時間。

PushRowNum

オペレータが送出したデータの合計行数。

PullRowNum

オペレータが受け取ったデータの合計行数。

固有のメトリクス

メトリック

説明

IOTaskExecTime

全てのI/Oタスクの合計実行時間。

IOTaskWaitTime

全てのI/Oタスクの合計待ち時間。

MorselsCount

全てのI/Oタスクの総数。

スキャンオペレータ

メトリック

説明

Table

テーブル名。

ScanTime

スキャン時間の合計。 非同期I/Oスレッドプールでスキャンが実行されます。

TabletCount

タブレットの数。

PushdownPredicates

プッシュダウンされた述語の数。

BytesRead

StarRocksが読み込んだデータのサイズ。

CompressedBytesRead

StarRocksが読み込んだ圧縮データのサイズ。

IOTime

I/O時間の合計。

BitmapIndexFilterRows

Bitmapインデックスによりフィルタされたデータの行数。

BloomFilterFilterRows

Bloomフィルタによりフィルタされたデータの行数。

SegmentRuntimeZoneMapFilterRows

ランタイムZone Mapによりフィルタされたデータの行数。

SegmentZoneMapFilterRows

Zone Mapによりフィルタされたデータの行数。

ShortKeyFilterRows

Short Keyによりフィルタされたデータの行数。

ZoneMapIndexFilterRows

Zone Mapインデックスによりフィルタされたデータの行数。

交換オペレータ

メトリック

説明

PartType

データの分布タイプ。 UNPARTITIONEDRANDOMHASH_PARTITIONEDBUCKET_SHUFFLE_HASH_PARTITIONEDの有効な値が存在します。

BytesSent

送信されたデータのサイズ。

OverallThroughput

全体的なスループット。

NetworkTime

データパッケージの送信時間(受信後の処理時間を除く)。このメトリックがどのように計算され、いつ例外が発生するかについては、以下のFAQを参照してください。

WaitTime

送信元側のキューがいっぱいのための待機時間。

集約オペレータ

メトリック

説明

GroupingKeys

グループキーの名前(GROUP BYの列)。

AggregateFunctions

集約関数。

AggComputeTime

集約関数の実行時間。

ExprComputeTime

式の実行時間。

HashTableSize

ハッシュテーブルのサイズ。

結合オペレータ

メトリック

説明

JoinPredicates

JOIN演算の述語。

JoinType

JOINのタイプ。

BuildBuckets

ハッシュテーブルのバケット数。

BuildHashTableTime

ハッシュテーブルの構築にかかった時間。

ProbeConjunctEvaluateTime

Probe Conjunctにかかった時間。

SearchHashTableTimer

ハッシュテーブルの検索にかかった時間。

ウィンドウ関数オペレータ

メトリック

説明

ComputeTime

ウィンドウ関数の実行時間。

PartitionKeys

パーティションキーの名前(PARTITION BYの列)。

AggregateFunctions

集約関数。

ソートオペレータ

メトリック

説明

SortKeys

ソートキーの名前(ORDER BYの列)。

SortType

結果のソートタイプ:すべての結果をリストアップするか、上位n件の結果をリストアップするか。

テーブル関数オペレータ

メトリック

説明

TableFunctionExecTime

テーブル関数の実行時間。

TableFunctionExecCount

テーブル関数の実行回数。

プロジェクトオペレータ

メトリック

説明

ExprComputeTime

式の実行時間。

CommonSubExprComputeTime

共通のサブエクスプレッションの実行時間。

ローカルエクスチェンジオペレータ

メトリック

説明

Type

ローカルエクスチェンジのタイプ。 PassthroughPartitionBroadcastの有効な値が存在します。

ShuffleNum

シャッフルの数。このメトリックは、TypePartitionの場合にのみ有効です。

Hive コネクタ

メトリック

説明

ScanRanges

スキャンされるタブレットの数。

ReaderInit

Readerの初期化時間。

ColumnReadTime

データの読み込みと解析にかかった時間。

ExprFilterTime

式のフィルタ処理にかかった時間。

RowsRead

読み込まれたデータの行数。

入力ストリーム

メトリック

説明

AppIOBytesRead

アプリケーションレイヤーからのI/Oタスクによって読み込まれたデータのサイズ。

AppIOCounter

アプリケーションレイヤーからのI/Oタスクの数。

AppIOTime

アプリケーションレイヤーからのI/Oタスクによるデータの読み込みにかかる合計時間。

FSBytesRead

ストレージシステムから読み込まれたデータのサイズ。

FSIOCounter

ストレージレイヤーからのI/Oタスクの数。

FSIOTime

ストレージレイヤーがデータを読み込むためにかかる合計時間。

オペレータごとの所要時間

  • OlapScanおよびConnectorScanオペレータの場合、所要時間はOperatorTotalTime + ScanTimeと同じです。スキャンオペレータは非同期I/O操作を行うため、ScanTimeは非同期I/O時間を表します。
  • Exchangeオペレータの所要時間はOperatorTotalTime + NetworkTimeと同じです。Exchangeオペレータはデータパッケージの送受信をBRPCスレッドプールで行うため、NetworkTimeはネットワーク転送にかかる時間を表します。
  • 他のすべてのオペレータの所要時間はOperatorTotalTimeです。

メトリックの統合とMIN/MAX

パイプラインエンジンは並列計算エンジンです。各フラグメントは複数のマシンに分散されて並列処理され、各マシンのパイプラインは複数の並行インスタンスとして並行して実行されます。そのため、プロファイリング中に同じメトリクスをマージし、すべての並行インスタンスの中で各メトリクスの最小値と最大値を記録します。

異なるタイプのメトリクスには異なるマージ戦略が採用されています。

  • 時間メトリクスは平均値です。例:
    • OperatorTotalTimeは、すべての並行インスタンスの平均時間コストを表します。
    • __MAX_OF_OperatorTotalTimeは、すべての並行インスタンスの中での最大時間コストを表します。
    • __MIN_OF_OperatorTotalTimeは、すべての並行インスタンスの中での最小時間コストを表します。
             - OperatorTotalTime: 2.192us
- __MAX_OF_OperatorTotalTime: 2.502us
- __MIN_OF_OperatorTotalTime: 1.882us
  • 時間ではないメトリクスは合計されます。例:

                   - PullChunkNum: 146.66K (146660)
    - __MAX_OF_PullChunkNum: 24.45K (24450)
    - __MIN_OF_PullChunkNum: 24.435K (24435)
    • PullChunkNumはすべての並行インスタンスの合計数です。
    • __MAX_OF_PullChunkNumはすべての並行インスタンスの中での最大値を表します。
    • __MIN_OF_PullChunkNumはすべての並行インスタンスの中での最小値を表します。
  • いくつかの特殊なメトリクスには最小値と最大値が存在せず、すべての並行インスタンスで同じ値(例:DegreeOfParallelism)です。

MINとMAXの間の顕著な違い

通常、MINとMAXの間の顕著な違いは、データがスキューしていることを示します。

             - OperatorTotalTime: 2m48s
- __MAX_OF_OperatorTotalTime: 10m30s
- __MIN_OF_OperatorTotalTime: 279.170us

テキストベースのプロファイル分析を実行する

v3.1以降、StarRocksでは、より使いやすいテキストベースのプロファイル分析機能が提供されています。この機能を使用すると、クエリのボトルネックや最適化の機会を効率的に特定することができます。

既存のクエリを分析する

完了したクエリのQueryIDを使用して、実行中であるかどうかに関係なく、特定のクエリのプロファイルを分析することができます。

プロファイルの一覧表示

次のSQLステートメントを実行して、既存のプロファイルの一覧を表示します。

SHOW PROFILELIST;

例:

MySQL > show profilelist;
+--------------------------------------+---------------------+-------+----------+--------------------------------------------------------------------------------------------------------------------------------------+
| QueryId | StartTime | Time | State | Statement |
+--------------------------------------+---------------------+-------+----------+--------------------------------------------------------------------------------------------------------------------------------------+
| b8289ffc-3049-11ee-838f-00163e0a894b | 2023-08-01 16:59:27 | 86ms | Finished | SELECT o_orderpriority, COUNT(*) AS order_count\nFROM orders\nWHERE o_orderdate >= DATE '1993-07-01'\n AND o_orderdate < DAT ... |
| b5be2fa8-3049-11ee-838f-00163e0a894b | 2023-08-01 16:59:23 | 67ms | Finished | SELECT COUNT(*)\nFROM (\n SELECT l_orderkey, SUM(l_extendedprice * (1 - l_discount)) AS revenue\n , o_orderdate, o_sh ... |
| b36ac9c6-3049-11ee-838f-00163e0a894b | 2023-08-01 16:59:19 | 320ms | Finished | SELECT COUNT(*)\nFROM (\n SELECT s_acctbal, s_name, n_name, p_partkey, p_mfgr\n , s_address, s_phone, s_comment\n F ... |
| b037b245-3049-11ee-838f-00163e0a894b | 2023-08-01 16:59:14 | 175ms | Finished | SELECT l_returnflag, l_linestatus, SUM(l_quantity) AS sum_qty\n , SUM(l_extendedprice) AS sum_base_price\n , SUM(l_exten ... |
| a9543cf4-3049-11ee-838f-00163e0a894b | 2023-08-01 16:59:02 | 40ms | Finished | select count(*) from lineitem |
+--------------------------------------+---------------------+-------+----------+--------------------------------------------------------------------------------------------------------------------------------------+
5 rows in set
Time: 0.006s


MySQL > show profilelist limit 1;
+--------------------------------------+---------------------+------+----------+-------------------------------------------------------------------------------------------------------------------------------------+
| QueryId | StartTime | Time | State | Statement |
+--------------------------------------+---------------------+------+----------+-------------------------------------------------------------------------------------------------------------------------------------+
| b8289ffc-3049-11ee-838f-00163e0a894b | 2023-08-01 16:59:27 | 86ms | Finished | SELECT o_orderpriority, COUNT(*) AS order_count\nFROM orders\nWHERE o_orderdate >= DATE '1993-07-01'\n AND o_orderdate < DAT ... |
+--------------------------------------+---------------------+------+----------+-------------------------------------------------------------------------------------------------------------------------------------+
1 row in set
Time: 0.005s

このSQLステートメントにより、各クエリに関連するQueryIdを簡単に取得することができます。QueryIdは、プロファイル分析や調査のための重要な識別子として使用されます。

プロファイルの分析

QueryIdを取得したら、ANALYZE PROFILEステートメントを使用して特定のクエリの詳細な分析を実行できます。このSQLステートメントにより、クエリのパフォーマンス特性と最適化を詳細に調べるための洞察が提供されます。

ANALYZE PROFILE FROM '<QueryId>' [, <plan_node_id>, ...]

デフォルトでは、分析結果は各オペレータの最も重要なメトリクスのみが表示されます。ただし、1つ以上の計画ノードのIDを指定して、対応するメトリクスを表示することもできます。この機能により、クエリのパフォーマンスのより包括的な調査が可能となり、特定の最適化に役立ちます。

例1:計画ノードのIDを指定せずにプロファイルを分析する:

img

例2:プランノードのIDを指定してプロファイルを分析する:

img

ANALYZE PROFILEステートメントは、実行中のクエリのランタイムプロファイルを分析するための強力な手法を提供します。このステートメントでは、ブロックされている、実行中、完了などの異なる状態を持つオペレータが区別されます。また、処理済みの行数に基づいて全体の進捗状況および個々のオペレータの進捗状況を表示することで、クエリの実行とパフォーマンスに関するより深い理解を可能にします。この機能は、StarRocksでのクエリのプロファイリングと最適化をさらに容易にするものです。

例3:実行中のクエリのランタイムプロファイルを分析する:

img

シミュレートされたクエリを分析する

指定したクエリをシミュレートし、そのプロファイルをEXPLAIN ANALYZEステートメントを使用して分析することもできます。

EXPLAIN ANALYZE <sql>

現在、EXPLAIN ANALYZEは、クエリ(SELECT)ステートメントとINSERT INTOステートメントの2つのタイプのSQLステートメントをサポートしています。INSERT INTOステートメントのシミュレーションとそのプロファイルの分析は、StarRocksのネイティブOLAPテーブル上でのみ行うことができます。INSERT INTOステートメントのプロファイルを分析する場合、実際にはデータは挿入されません。デフォルトではトランザクションが中止され、プロファイル分析のプロセスでデータが意図しない変更が加えられないように確保されます。

例1:特定のクエリのプロファイルを分析する:

img

例2:INSERT INTO操作のプロファイルを分析する:

img

クエリプロファイルの視覚化

StarRocksエンタープライズエディションのユーザーであれば、StarRocks Managerを使用してクエリプロファイルを視覚化することができます。

プロファイルの概要ページでは、総実行時間(ExecutionWallTime)、I/Oメトリック、ネットワーク転送サイズ、CPUとI/O時間の比率など、いくつかのサマリーメトリクスが表示されます。

img

オペレータ(ノード)のカードをクリックすると、右側のペインに詳細情報が表示されます。3つのタブがあります。

  • ノード: このオペレータの主要なメトリクス。
  • ノードの詳細: このオペレータのすべてのメトリクス。
  • パイプライン: オペレータが所属するパイプラインのメトリクス。スケジューリングに関連するため、このタブにはあまり注意を払う必要はありません。
img

ボトルネックの特定

オペレータが占める時間の割合が大きいほど、カードの色が濃くなります。これにより、クエリのボトルネックを簡単に特定することができます。

img

データのスキューをチェックする

時間の割合が大きいオペレータのカードをクリックし、そのMaxTimeおよびMinTimeをチェックします。MaxTimeMinTimeの間に顕著な違いがある場合、データがスキューしている可能性があります。

img

次に、Node Detailタブをクリックし、メトリクスに例外が表示されていないかをチェックします。この例では、集約オペレータのPushRowNumメトリクスがデータのスキューを示しています。

img

パーティショニングやバケット戦略が有効になっているかをチェックする

EXPLAIN <sql_statement>を使用して、対応するクエリプランを表示して、パーティショニングやバケット戦略が有効になっているかを確認することができます。

img

正しいマテリアライズドビューが使用されているかをチェックする

関連するスキャンオペレータをクリックし、Node DetailタブでRollupフィールドをチェックします。

img

JOINプランが左テーブルと右テーブルに適切に適用されているかをチェックする

通常、StarRocksでは、右テーブルを小さい方に選択します。もしクエリプロファイルで異なる結果が表示されている場合、例外が発生します。

img

JOINの分布タイプが正しいかをチェックする

Exchangeオペレータはデータの分布タイプに応じて3つのタイプに分類されます。

  • UNPARTITIONED:Broadcast。データは複数のBEにコピーされて配布されます。
  • RANDOM:ラウンドロビン。
  • HASH_PARTITIONEDおよびBUCKET_SHUFFLE_HASH_PARTITIONED:Shuffle。HASH_PARTITIONEDBUCKET_SHUFFLE_HASH_PARTITIONEDの違いは、ハッシュコードを計算するために使用されるハッシュ関数にあります。

Inner Joinの場合、右テーブルはHASH_PARTITIONEDおよびBUCKET_SHUFFLE_HASH_PARTITIONEDタイプまたはUNPARTITIONEDタイプにできます。通常、UNPARTITIONEDタイプは右テーブルの行数が100K以下の場合にのみ採用されます。

次の例では、ExchangeオペレータのタイプがBroadcastになっていますが、オペレータが送信するデータのサイズが大幅に閾値を超えています。

img

JoinRuntimeFilterが効果的に使用されているかをチェックする

Joinの右側がハッシュテーブルを構築している場合、ランタイムフィルタが作成されます。このランタイムフィルタは、左側のツリーに送信され、可能な場合はScanオペレータにプッシュダウンされます。ScanオペレータのNode DetailタブでJoinRuntimeFilterに関連するメトリクスを確認することができます。

img

FAQ

Exchangeオペレータの所要時間が異常な理由は何ですか?

img

Exchangeオペレータの所要時間はCPU時間とネットワーク時間の2つの部分からなります。ネットワーク時間はシステムクロックに依存します。ネットワーク時間は次のように計算されます:

  1. 送信側は、パッケージを送信するためのBRPCインターフェースを呼び出す前にsend_timestampを記録します。
  2. 受信側は、BRPCインターフェースからパッケージを受信した後のreceive_timestampを記録します(受信後の処理時間は除く)。
  3. 処理が完了したら、受信側はレスポンスを送信し、ネットワークの遅延時間を計算します。パッケージの伝送遅延時間は、receive_timestamp - send_timestampに相当します。

マシン間のシステムクロックが一貫していない場合、Exchangeオペレータの所要時間は例外的な値になります。

すべてのオペレータの総時間コストがクエリの実行時間よりもかなり少ない理由は何ですか?

原因として考えられるのは、高並行性のシナリオでは、いくつかのパイプラインドライバがスケジュール可能であっても、キューに並んでいるために処理されない場合があるためです。待機時間はオペレータのメトリクスには記録されませんが、PendingTimeScheduleTimeIOTaskWaitTimeに記録されます。

例:

プロファイルから、ExecutionWallTimeは約55msであることがわかります。しかし、すべてのオペレータの所要時間の合計は10ms未満であり、ExecutionWallTimeよりもかなり少ないです。

img