How to Understand Execution Plans

Translated
1

Note:
This topic has been translated from a Chinese forum by GPT and might contain errors.

Original topic: 如何理解执行计划

| username: yulei7633

From the execution plan, can we confirm how many milliseconds this SQL statement took? The final execution result shows 440 milliseconds, but this 440 milliseconds doesn’t seem to correspond to the times in the execution plan. How should we understand the times in this execution plan?

MySQL [xxxxxxxxx]> explain analyze select * FROM xxxxxxxxxxxx WHERE form_id = 1000968 AND form_user_id = 676601837 AND data_index_id > 0;
±-----------------------±--------±--------±----------±-------------------------------±-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±---------------------------------------------------------------------±--------±-----+
| id | estRows | actRows | task | access object | execution info | operator info | memory | disk |
±-----------------------±--------±--------±----------±-------------------------------±-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±---------------------------------------------------------------------±--------±-----+
| TableReader_7 | 0.02 | 170 | root | | time:87.7ms, loops:2, RU:18.324737, cop_task: {num: 1, max: 80.7ms, proc_keys: 170, tot_proc: 51ms, tot_wait: 77.9µs, rpc_num: 1, rpc_time: 80.7ms, copr_cache_hit_ratio: 0.00, build_task_duration: 7.13µs, max_distsql_concurrency: 1} | data:TableRangeScan_6 | 10.6 MB | N/A |
| └─TableRangeScan_6 | 0.02 | 170 | cop[tikv] | table:xxxxxxxxxx | tikv_task:{time:30ms, loops:3}, scan_detail: {total_process_keys: 170, total_process_keys_size: 47258, total_keys: 338, get_snapshot_time: 28µs, rocksdb: {key_skipped_count: 337, block: {cache_hit_count: 6, read_count: 3, read_byte: 95.4 KB, read_time: 55.1µs}}} | range:(1000968 676601837 0,1000968 676601837 +inf], keep order:false | N/A | N/A |
±-----------------------±--------±--------±----------±-------------------------------±-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------±---------------------------------------------------------------------±--------±-----+
2 rows in set (0.44 sec)

2
| username: yulei7633 | Original post link

The calculation result is: 87.72+303=265.4 milliseconds, which is inconsistent with the output result of 440 milliseconds above. How can this be explained?

3
| username: yulei7633 | Original post link

The image is not visible. Please provide the text you need translated.

4
| username: 春风十里 | Original post link

0.44 seconds, which is 440 milliseconds, is the total execution time displayed by the client. It should include the network time from the TiDB server to your client and the time taken for the client to display the result. The execution plan shows the time for each step.

5
| username: yulei7633 | Original post link

Is the time in the execution plan not the total time? Is it just a part of the total execution time?

6
| username: 小龙虾爱大龙虾 | Original post link

It is the total time at the database level, plus the time to your client.

7
| username: forever | Original post link

Your use of count not returning data should be similar.

8
| username: Jellybean | Original post link

The time in the first row of the execution plan indicates the total time the SQL statement took to execute in the database, which is 87.7ms.

9
| username: wangccsy | Original post link

The execution process of SQL

10
| username: 春风十里 | Original post link

“time” represents the total wall time from entering the operator to leaving the operator, including the total execution time of all sub-operator operations. If the operator is called multiple times by the parent operator (loops), this time is the cumulative time. “loops” is the number of times the current operator is called by the parent operator.

11
| username: 江湖故人 | Original post link

The 440ms displayed by the client = 87.7ms in the execution plan + the time for the result to be transmitted from the db_server to the client over the network.
The execution plan cannot pre-fetch the time from the db_server to the client.

12
| username: 随缘天空 | Original post link

I have always had trouble understanding TiDB’s execution plan, especially the execution order.

13
| username: linnana | Original post link

The official documentation doesn’t seem to have much information about explain. From the execution plan, it looks like it goes from bottom to top.

14
| username: 春风十里 | Original post link

The one with the same indentation level is executed first, and for different indentation levels, the rightmost one is executed first.

15
| username: 春风十里 | Original post link

Got it! Please provide the Chinese text you need translated.

16
| username: 随缘天空 | Original post link

Do you mean that tasks at the same level are executed from top to bottom, while tasks at different levels are executed from bottom to top?

17
| username: 春风十里 | Original post link

Although it can be understood this way, I do not recommend memorizing such formulas. Actually, TiDB’s execution plan is quite similar to Oracle’s. You can find a lot of articles online about Oracle’s execution plan sequence. MySQL’s execution plan sequence is not intuitive and not visually appealing (MySQL has Workbench, where the graphical execution plan is very nice). Of course, the simplest way is to look at TiDB’s official documentation or watch free videos. Teacher Dong has videos explaining the execution plan.

First, check the official documentation:

The execution order of operators:
The structure of operators is tree-like, but during query execution, it is not strictly required that child node tasks be completed before the parent node. TiDB supports parallel processing within the same query, meaning child nodes “flow into” parent nodes. Parent nodes, child nodes, and sibling nodes may execute parts of the query in parallel.

In the above example, the operator ├─IndexRangeScan_8(Build) matches rows in the index a(a) and looks up the internal RowID. The operator └─TableRowIDScan_9(Probe) then retrieves these rows from the table.

Build always executes before Probe, and Build always appears before Probe. That is, if an operator has multiple child nodes, the operator with the Build keyword after the child node ID always executes before the operator with the Probe keyword. When TiDB presents the execution plan, the Build side always appears first, followed by the Probe side.

18
| username: 春风十里 | Original post link

Many execution plans are executed in loops. Although there is an order, they are actually dynamically executed in sequence. In TiDB, loops refer to the number of times a loop is called.

19
| username: tidb菜鸟一只 | Original post link

This SQL took 87.7ms to execute.

20
| username: zhanggame1 | Original post link

Execute the one with the same indentation first, and execute the one with more indentation if the indentation is different.