BigQuery のクエリプランを確認し、SQLを実行した時の裏側の処理に思いを馳せてみた

2020.12.06

この記事は公開されてから1年以上経過しています。情報が古い可能性がありますので、ご注意ください。

こんにちは、データアナリティクス事業本部のみかみです。

本エントリは、クラスメソッド BigQuery Advent Calendar 2020 の 6 日目のエントリです。 25日のアドベントカレンダー終了まで、弊社クラスメソッド データアナリティクス事業本部のメンバーで Google BigQuery に関する記事を紡いでいこうと思います。

実行計画と BigQuery のクエリプラン

MySQL や PostgreSQL などのデータベースエンジンでは、SQL の前に EXPLAIN を付けて実行することで、SQL の中の各ステートメントがどういう順番でどのくらいのデータ量を処理するのか、実行計画を確認することができます。 SQL のパフォーマンスチューニングなどで実行計画を確認しながら効率よく処理できるように SQL を修正していると、だんだんデータベースエンジンの考え方が分かってくるようになり、意思疎通ができたような気になって非常にうれしかったものです。

BigQuery では EXPLAIN は使えませんが、SQL を実行した後に、コンソールや API からどんな処理順でどのくらいのデータ量が処理されたのか、クエリプランを確認することができるそうです。

やりたいこと

  • BigQuery のクエリプランで何が見れるのか確認したい
  • BigQuery で SQL を実行した時の裏側の処理を知りたい
  • BigQuery ともっと仲良くなりたい

BigQuery のアーキテクチャ

BigQuery は、データを保持するストレージ層と SQL を処理するコンピューティング層から成り、 ストレージ層には高可用性を誇る Google の分散ファイルシステム Colossus が使われ、コンピューティング層には Google 社内で利用されていた大規模データ分散処理エンジン Dremel が利用されているそうです。

コンピューティング層では実行した SQL クエリが細かく分割されてリーフノードで並列処理され、処理結果はミキサーノードで集約されて返却されます。 このリーフノードが「スロット」と呼ばれる BigQuery の処理単位で、実行されるクエリの複雑さや SQL 同時実行数に合わせて動的に割り当てられます。 オンデマンド料金の場合、デフォルトでは 2000 スロットが利用できますが、たくさんの複雑な SQL が同時実行された場合などに空きスロットがなくなると、スロットの空き待ちが発生するため BigQuery のパフォーマンスが悪化します。

コンピューティング層内の各ノード間の通信には Google 独自のネットワーク技術である Jupiter が使われていて、ペタビットを1秒で処理するのに十分なネットワークスループットが確保されています。 また、大量のノードを可用性を保ちながら管理するためのクラスター管理システムとして Borg も利用されているそうです。

つまり BigQuery のコンピューティング層では、高速処理に必要な分だけ仮想 CPU をフルマネージドで割り当てて超並列分散処理を実行していて、Google の各種技術で高スループット、高可用性も担保されているということですね。(若干のちからずく感は否めませんが、それを含めて実現してしまう Google さん、やはりさすがです!@@v

管理コンソールからクエリプランを確認

では実際に SQL を実行して、クエリプランを確認してみます。

BigQuery 管理コンソールのクエリエディタに以下の SQL を入力して実行しました。 対象テーブルには 7 レコードのデータしかなく、SQL も特定の条件で SELECT した結果をソートして返すだけのシンプルなものです。

SELECT
    name
FROM
    dataset_1.dogs
WHERE
    id IN (1, 3, 5)
ORDER BY id

実行結果が表示されたら「実行の詳細」タブをクリックします。

「経過時間」で SQL の実行時間、「消費したスロット時間」でリーフノードが処理を実行した時間が確認できます。 コンピューティング層の各ノード間のデータのやり取りをシャッフルと呼び、「シャッフルされたバイト数」ではノード間でやり取りされたデータ量が確認できます。 「ディスクにオーバーフローしたバイト数」にはオンメモリで処理しきれなかった場合にディスクストレージに退避したデータ量が表示され、この数値が大きいほどパフォーマンスが悪くなります。

その下にはステージごとの処理内容が表示され、下向き矢印アイコンクリックで詳細が確認できます。

「S00: Input」は主に読み取り処理を実行しているので、リーフノードの処理のようです。 右端の「入力」と「出力」で、ノードへの入力行と出力行が確認できます。 詳細を見ると、ストレージから指定した条件のデータを READ して、データ受け渡し用のメモリ領域と思われる __stage00_output に WRITE しています。

「S01: Output」では S00 から受け取ったデータを指定条件で並び替え、結果を __stage01_output に WRITE しているので、こちらはミキサーの処理でしょうか。

続いてもっとデータ量の多いパブリックデータセットテーブルに対して、もう少し複雑な以下の SQL を実行してみます。

SELECT
  name, gender,
  SUM(number) AS total
FROM
  `bigquery-public-data.usa_names.usa_1910_2013`
GROUP BY
  name, gender
ORDER BY
  total DESC
LIMIT
  10

先ほどはなかった「Sort+」というステージが増えています。

各ステージの処理詳細も確認してみます。

先ほどのシンプルなクエリでは、ストレージからのデータ読み取りにほとんどの時間を費やしていた Input のステージ 00 ですが、今回はコンピューティングに大分時間がかかっています。 また、1ms ではありますが、待機時間も発生しています。

GROUP BY して SUM 結果を集計する AGGREGATE の工程が発生しています。 また、次のステージに渡す処理結果に、BY HASH という文字が現れました。 処理高速化のため、データのハッシュ化も行っているのでしょうか。

次の Sort ステージでも、やはりわずかですが待機時間が発生し、ほとんどの処理時間をコンピューティングに費やしてます。

処理内容としては、結果を SORT して指定された LIMIT をかけて、こちらでもグルーピング結果の集計を行っています。

最後の Output ステージでは、前のステージで LIMIT された 10 行を受け取り、さらに SORT した結果を返却しているようです。

何の処理にどのくらいの時間がかかっているのか視覚的に確認できるので非常に分かりやすいです。 各ステージの処理対象レコード数、待機時間やスロットの稼働時間も確認できるので、SQL のパフォーマンスが思ったように出ない時には確認すると役に立ちそうです。

API 実行結果からクエリプランを確認

Python SDK から BigQuery API を実行して、最初にコンソールから確認したシンプルな SQL のクエリプランを確認してみます。

以下の python コードを、Cloud Shell から実行しました。

from google.cloud import bigquery
from pprint import pprint

job_id = 'bquxjob_235c9af8_1762d37ca63'
location = 'asia-northeast1'

client = bigquery.Client()
job = client.get_job(job_id, location=location)
for obj in job.timeline:
    pprint(vars(obj))
for stage in job.query_plan:
    print('--------')
    pprint(vars(stage))
gcp_da_user@cloudshell:~/temp (cm-da-mikami-yuki-258308)$ python3 get_job.py
{'_properties': {'completedUnits': '2',
                 'elapsedMs': '417',
                 'pendingUnits': '0',
                 'totalSlotMs': '67'}}
--------
{'_properties': {'completedParallelInputs': '1',
                 'computeMsAvg': '6',
                 'computeMsMax': '6',
                 'computeRatioAvg': 0.07228915662650602,
                 'computeRatioMax': 0.07228915662650602,
                 'endMs': '1607076477517',
                 'id': '0',
                 'name': 'S00: Input',
                 'parallelInputs': '1',
                 'readMsAvg': '83',
                 'readMsMax': '83',
                 'readRatioAvg': 1,
                 'readRatioMax': 1,
                 'recordsRead': '7',
                 'recordsWritten': '3',
                 'shuffleOutputBytes': '78',
                 'shuffleOutputBytesSpilled': '0',
                 'slotMs': '62',
                 'startMs': '1607076477427',
                 'status': 'COMPLETE',
                 'steps': [{'kind': 'READ',
                            'substeps': ['$1:id, $2:name',
                                         'FROM dataset_1.dogs',
                                         'WHERE in($1, 1, 3, 5)']},
                           {'kind': 'WRITE',
                            'substeps': ['$1, $2', 'TO __stage00_output']}],
                 'waitMsAvg': '0',
                 'waitMsMax': '0',
                 'waitRatioAvg': 0,
                 'waitRatioMax': 0,
                 'writeMsAvg': '1',
                 'writeMsMax': '1',
                 'writeRatioAvg': 0.012048192771084338,
                 'writeRatioMax': 0.012048192771084338}}
--------
{'_properties': {'completedParallelInputs': '1',
                 'computeMsAvg': '1',
                 'computeMsMax': '1',
                 'computeRatioAvg': 0.012048192771084338,
                 'computeRatioMax': 0.012048192771084338,
                 'endMs': '1607076477531',
                 'id': '1',
                 'inputStages': ['0'],
                 'name': 'S01: Output',
                 'parallelInputs': '1',
                 'readMsAvg': '0',
                 'readMsMax': '0',
                 'readRatioAvg': 0,
                 'readRatioMax': 0,
                 'recordsRead': '3',
                 'recordsWritten': '3',
                 'shuffleOutputBytes': '51',
                 'shuffleOutputBytesSpilled': '0',
                 'slotMs': '4',
                 'startMs': '1607076477526',
                 'status': 'COMPLETE',
                 'steps': [{'kind': 'READ',
                            'substeps': ['$1, $2', 'FROM __stage00_output']},
                           {'kind': 'SORT', 'substeps': ['$1 ASC']},
                           {'kind': 'WRITE',
                            'substeps': ['$10', 'TO __stage01_output']}],
                 'waitMsAvg': '0',
                 'waitMsMax': '0',
                 'waitRatioAvg': 0,
                 'waitRatioMax': 0,
                 'writeMsAvg': '0',
                 'writeMsMax': '0',
                 'writeRatioAvg': 0,
                 'writeRatioMax': 0}}

コンソールには表示されていなかった、各ステージごとのシャッフルデータ量など、より詳細な情報が取得できました。

やはりコンソールの方がビジュアル的に見やすいですが、より詳細に調査などを行う時には、API の取得結果を確認するのも良さそうです。

まとめ(所感)

今まで全く聞こえなかった BigQuery の声が、クエリプランを紐解くことで、少しだけ聞こえるようになった気がします。 今回はあまりいろいろなパターンのクエリを確認できませんでしたが、引き続き BigQuery を使う時には合わせてクエリプランも確認し、BigQuery との仲をもっと深めていこうと思います。

明日 7 日目の BigQuery Advent Calendar 2020しんやからお送り予定です。また、今後のアドベントカレンダーの予定はこちらにも掲載しておりますので、引き続きお楽しみいただけますと幸いです。

参考