TiDBのPlannerのデバッグトレース

TL;DR

TiDBではPlannerで行われる最適化の途中経過を出力する TRACE PLAN 文が存在する。これを使うと $TMPDIR/optimizer_trace/ 以下にトレースがjson形式で出力される。
※ ローカルファイルに出力されるので、TiDB cloudでは利用できない

Plannerのトレース

TiDB Source Code Reading #2の準備でソースコードを読んでいたら、Plannerでは定期的にtraceにメッセージを書いていることが分かったが、これがどこに出力されているか謎だった。

コールスタックを辿って見つけたそのやり方は、TRACE PLAN 文を打つということだった。公式ドキュメントには記載がないし、出力もPlannerのソース読まないと意味わからないので開発者用なんだろうと思う。

今回はtiup playgroundを使って、trace planの出力の仕方を見ていく。

準備

1. Tiup Playgroundを起動。バージョンは何でもいいと思われるので、デフォルトのv8.2（当時）を利用。

> tiup playground

Note: Version constraint  is resolved to v8.2.0. If you'd like to use other versions:
...

🎉 TiDB Playground Cluster is started, enjoy!

Connect TiDB:    mysql --comments --host 127.0.0.1 --port 4000 -u root
TiDB Dashboard:  http://127.0.0.1:2379/dashboard
Grafana:         http://127.0.0.1:3000

2. サンプルデータの投入
   よく使っているのはMySQLのEmployeeデータベース。そこそこ複雑でデータ量もあり、お試しには十分。

利用法はGitリポジトリをcloneして、employees.sqlを実行するだけ。

 mysql --comments --host 127.0.0.1 --port 4000 -u root < employees.sql

実行

あとは TRACE PLAN を実行するだけ。EXPLAINと使い方は一緒で、後続にSQLを記載する。
今回はEmployeeデータベースを使ったサンプルクエリから、複数のテーブルのJOINがあるProblem 7を選択して実行。

mysql> use employees;
Database changed

mysql> trace plan SELECT dept.dept_name,
    ->        MIN(TIMESTAMPDIFF(YEAR, e.birth_date, e.hire_date)) AS age_hire_date
    -> FROM employees e
    -> JOIN dept_emp d_emp ON e.emp_no = d_emp.emp_no
    -> JOIN departments dept ON d_emp.dept_no = dept.dept_no
    -> GROUP BY dept.dept_name
    -> ;
+------------------------------------------------------------------+
| Dump_link                                                        |
+------------------------------------------------------------------+
| optimizer_trace_PtlwTi4TDp-ZbnITqoShlA==_1723883692172129000.zip |
+------------------------------------------------------------------+
1 row in set (0.01 sec)

こんな感じでzipファイル名が表示される。このファイルは $TMPDIR/optimizer_trace/<tidbサーバのpid>/ 以下に出力されている。(MacOSの場合)

ファイルの内容

zipを解凍すると trace.jsonというファイルが一つだけ入っており、これがトレース出力になる。
jsonファイルの構造は、

{
  "logical":{...},
  "physical":{...},
  "final":{...},
  "isFastPlan":false
}

となっており、それぞれ論理最適化、物理最適化、最終実行計画を表しているのだろうと思われる。今回の読書会のメインである論理最適化を詳しくみていくことにする。

出力を見ていく前に、先ほどのSQLをEXPLAINして、実行計画の最終版を確認する。

論理最適化部分を詳しく見る

logical以下の構造について詳しく見ていく。

{
  "logical":{
    "final":[...],
    "steps":[...]
}

となっていて、それぞれ最終版と途中経過の論理プランツリーが記載されているようだ。

final

            {
                "type": "DataSource",
                "property": "",
                "info": "table:dept",
                "children": [],
                "id": 5,
                "cost": 0,
                "selected": false
            },
            {
                "type": "DataSource",
                "property": "",
                "info": "table:d_emp",
                "children": [],
                "id": 2,
                "cost": 0,
                "selected": false
            },
            {
                "type": "Join",
                "property": "",
                "info": "inner join, equal:[eq(employees.departments.dept_no, employees.dept_emp.dept_no)]",
                "children": [
                    5,
                    2
                ],
                "id": 10,
                "cost": 0,
                "selected": false
            },

といった形で、プランツリーが記載されている。なんとなく構造はわかるが、ここはGPTの力をかりて図示してもらおう。

               9 (Projection)
                    |
               8 (Aggregation)
                    |
               12 (Projection)
                    |
               11 (Join)
              /           \
        10 (Join)         1 (DataSource: e)
       /         \
5 (DataSource: dept)  2 (DataSource: d_emp)

すごい。一発でこれ出してきた。物理最適化前なので最終的な実行計画とは異なるが、テーブルのJOINの順番などは同じことがわかる。この段階ではJOINの具体的なアルゴリズムなどはわからない。

steps

"steps":[
  {
    "name":"column_prune",
    "before":[],
    "steps":[],
    "index":1
  },
  ...
]

stepsでは、論理最適化の各ステップについて、beforeで実行前の論理プランツリー、stepsで実行時のトレース情報が記載されている。
ここでは、テーブルの結合順を見る Join Reorder に注目してみる。 beforeにはこの最適化を行う前のツリーが記載されているので、同様にGPTに図示してもらう。

           9 (Projection)
                |
           8 (Aggregation)
                |
           6 (Join)
          /        \
    3 (Join)       5 (DataSource: dept)
   /       \
1 (DataSource: e)  2 (DataSource: d_emp)

この時点の結合順は最終結果とは異なり、SQLに記載の順番になっていることがわかる。
次にstepsを確認すると、

"steps": [
    {
        "action": "join order becomes ((dept*d_emp)*e) from original ((e*d_emp)*dept)",
        "reason": "join cost during reorder: [[((dept*d_emp)*e), cost:1.2926429065164637e+06],[(dept*d_emp), cost:663211],[d_emp, cost:331603],[dept, cost:9],[e, cost:300024]]",
        "type": "Projection",
        "id": 9,
        "index": 0
    }
],

と書いてあり、元々の結合順から変更されていることがわかる。reasonにコスト計算の途中経過が記載されている。TiDBがJoin Reorderを行う際のデフォルトとして利用しているGreedyアルゴリズムは行数をコストとしており、実際単独のテーブルのコストは行数に等しくなっている。

このようにして、元のSQLから実行計画が導出されていったのかをステップごとに追跡することができる。便利かどうかはともかく結構面白いのではないだろうか。