2.21 单条SQL性能trace

这个功能与MySQL的profile功能类似,用于统计一条查询在dble内部的各个阶段的耗时情况,用来发现性能瓶颈,改进SQL或者dble配置,达到提高性能的目的。 此功能为session 级别。

1. 可以通过此命令检查trace功能是否开启

mysql> select @@trace;
+---------+
| @@trace |
+---------+
| 0       |
+---------+
1 row in set (0.02 sec)

2. 开启 trace 功能

mysql> set trace =1;
Query OK, 0 rows affected (0.09 sec)

mysql> select @@trace;
+---------+
| @@trace |
+---------+
| 1       |
+---------+
1 row in set (0.00 sec)

3. 单节点查询的trace结果举例

mysql> select * from sharding_two_node where id =1;
+----+--------+-----------+
| id | c_flag | c_decimal |
+----+--------+-----------+
|  1 | 1      |    1.0000 |
+----+--------+-----------+
1 row in set (0.02 sec)

mysql> show trace;
+-------------------+-----------+-----------+--------------+-----------+---------------------------------------------+
| OPERATION         | START(ms) | END(ms)   | DURATION(ms) | DATA_NODE | SQL/REF                                     |
+-------------------+-----------+-----------+--------------+-----------+---------------------------------------------+
| Read SQL          | 0.0       | 0.1085    | 0.1085       | -         | -                                           |
| Parse SQL         | 0.1085    | 0.49607   | 0.38757      | -         | -                                           |
| Route Calculation | 0.49607   | 1.274142  | 0.778072     | -         | -                                           |
| Prepare to Push   | 1.274142  | 1.560543  | 0.286401     | -         | -                                           |
| Execute SQL       | 1.560543  | 18.711851 | 17.151308    | dn1       | select * from sharding_two_node where id =1 |
| Fetch result      | 18.711851 | 18.978213 | 0.266362     | dn1       | select * from sharding_two_node where id =1 |
| Write to Client   | 18.711851 | 19.276344 | 0.564493     | -         | -                                           |
| Over All          | 0.0       | 19.276344 | 19.276344    | -         | -                                           |
+-------------------+-----------+-----------+--------------+-----------+---------------------------------------------+
8 rows in set (0.00 sec)

4. 多节点查询的trace结果举例

mysql> select * from sharding_two_node ;
+-----+--------+-----------+
| id  | c_flag | c_decimal |
+-----+--------+-----------+
| 513 | 513    |  513.0000 |
| 514 | 514    |  514.0000 |
| 515 | 515    |  515.0000 |
| 516 | 516    |  516.0000 |
|   1 | 1      |    1.0000 |
|   2 | 2      |    2.0000 |
|   3 | 3      |    3.0000 |
|   4 | 4      |    4.0000 |
|   5 | 5      |    5.0000 |
|   7 | 7      |    7.0000 |
|   8 | 8      |    8.0000 |
|   9 | 9      |    9.0000 |
|  10 | 10     |   10.0000 |
|  11 | 11     |   11.0000 |
|  12 | 12     |   12.0000 |
+-----+--------+-----------+
15 rows in set (0.01 sec)

mysql> show trace;
+-------------------+-----------+----------+--------------+-----------+-------------------------------------------+
| OPERATION         | START(ms) | END(ms)  | DURATION(ms) | DATA_NODE | SQL/REF                                   |
+-------------------+-----------+----------+--------------+-----------+-------------------------------------------+
| Read SQL          | 0.0       | 0.079175 | 0.079175     | -         | -                                         |
| Parse SQL         | 0.079175  | 0.637315 | 0.55814      | -         | -                                         |
| Route Calculation | 0.637315  | 1.046389 | 0.409074     | -         | -                                         |
| Prepare to Push   | 1.046389  | 1.465238 | 0.418849     | -         | -                                         |
| Execute SQL       | 1.465238  | 8.141409 | 6.676171     | dn1       | SELECT * FROM sharding_two_node LIMIT 100 |
| Execute SQL       | 1.465238  | 7.59109  | 6.125852     | dn2       | SELECT * FROM sharding_two_node LIMIT 100 |
| Fetch result      | 8.141409  | 8.817824 | 0.676415     | dn1       | SELECT * FROM sharding_two_node LIMIT 100 |
| Fetch result      | 7.59109   | 8.366718 | 0.775628     | dn2       | SELECT * FROM sharding_two_node LIMIT 100 |
| Write to Client   | 7.59109   | 9.324157 | 1.733067     | -         | -                                         |
| Over All          | 0.0       | 9.324157 | 9.324157     | -         | -                                         |
+-------------------+-----------+----------+--------------+-----------+-------------------------------------------+
10 rows in set (0.00 sec)

5. 多节点写入的SQL 的trace结果举例,事实上,这是一个隐式分布式事务

mysql> insert into sharding_two_node values(15,'15',15),(519,'519',519);
Query OK, 2 rows affected (0.06 sec)

mysql> show trace;
+---------------------------------+-----------+-----------+--------------+-----------+--------------------------------------------------------+
| OPERATION                       | START(ms) | END(ms)   | DURATION(ms) | DATA_NODE | SQL/REF                                                |
+---------------------------------+-----------+-----------+--------------+-----------+--------------------------------------------------------+
| Read SQL                        | 0.0       | 0.131959  | 0.131959     | -         | -                                                      |
| Parse SQL                       | 0.131959  | 0.601637  | 0.469678     | -         | -                                                      |
| Route Calculation               | 0.601637  | 0.825479  | 0.223842     | -         | -                                                      |
| Prepare to Push                 | 0.825479  | 1.025374  | 0.199895     | -         | -                                                      |
| Execute SQL                     | 1.025374  | 27.095675 | 26.070301    | dn1       | INSERT INTO sharding_two_node VALUES (15, '15', 15)    |
| Execute SQL                     | 1.025374  | 25.023911 | 23.998537    | dn2       | INSERT INTO sharding_two_node VALUES (519, '519', 519) |
| Fetch result                    | 27.095675 | 27.405046 | 0.309371     | dn1       | INSERT INTO sharding_two_node VALUES (15, '15', 15)    |
| Fetch result                    | 25.023911 | 26.478398 | 1.454487     | dn2       | INSERT INTO sharding_two_node VALUES (519, '519', 519) |
| Distributed Transaction Prepare | 27.405046 | 27.736411 | 0.331365     | -         | -                                                      |
| Distributed Transaction Commit  | 27.736411 | 57.426311 | 29.6899      | -         | -                                                      |
| Write to Client                 | 25.023911 | 57.428266 | 32.404355    | -         | -                                                      |
| Over All                        | 0.0       | 57.428266 | 57.428266    | -         | -                                                      |
+---------------------------------+-----------+-----------+--------------+-----------+--------------------------------------------------------+
12 rows in set (0.00 sec)

6. 复杂查询的trace结果举例

mysql> select count(*) from sharding_two_node;  
+----------+
| COUNT(*) |
+----------+
|       20 |
+----------+
1 row in set (0.01 sec) 

mysql> show trace;
+-----------------------+-----------+-----------+--------------+-----------------+--------------------------------------------------------------------------+  
| OPERATION             | START(ms) | END(ms)   | DURATION(ms) | DATA_NODE       | SQL/REF                                                                  |  
+-----------------------+-----------+-----------+--------------+-----------------+--------------------------------------------------------------------------+  
| Read SQL              | 0.0       | 0.08553   | 0.08553      | -               | -                                                                        |  
| Parse SQL             | 0.08553   | 0.56987   | 0.48434      | -               | -                                                                        |  
| Try Route Calculation | 0.56987   | 0.71698   | 0.14711      | -               | -                                                                        |
| Try to Optimize       | 0.71698   | 1.237487  | 0.520507     | -               | -                                                                        |  
| Execute SQL           | 1.237487  | 9.091029  | 7.853542     | dn1.0           | select COUNT(*) as `_$COUNT$_rpda_0` from  `sharding_two_node` LIMIT 100 |
| Fetch result          | 9.091029  | 10.186782 | 1.095753     | dn1.0           | select COUNT(*) as `_$COUNT$_rpda_0` from  `sharding_two_node` LIMIT 100 |  
| Execute SQL           | 1.237487  | 8.348635  | 7.111148     | dn2.0           | select COUNT(*) as `_$COUNT$_rpda_0` from  `sharding_two_node` LIMIT 100 |
| Fetch result          | 8.348635  | 9.342241  | 0.993606     | dn2.0           | select COUNT(*) as `_$COUNT$_rpda_0` from  `sharding_two_node` LIMIT 100 |
| MERGE                 | 8.721543  | 10.289905 | 1.568362     | merge.1         | dn1.0; dn2.0                                                             |
| ORDERED_GROUP         | 8.726919  | 10.424309 | 1.69739      | ordered_group.1 | merge.1                                                                  |
| LIMIT                 | 9.020162  | 10.499574 | 1.479412     | limit.1         | ordered_group.1                                                          |
| SHUFFLE_FIELD         | 9.023584  | 10.501529 | 1.477945     | shuffle_field.1 | limit.1                                                                  |
| Write to Client       | 9.072457  | 11.52055  | 2.448093     | -               | -                                                                        |
| Over All              | 0.0       | 11.52055  | 11.52055     | -               | -                                                                        |
+-----------------------+-----------+-----------+--------------+-----------------+--------------------------------------------------------------------------+
14 rows in set (0.03 sec)

7. 子查询的trace结果举例

mysql> select count(*) from sharding_two_node where id =(select id from sharding_two_node where id=1); 
+----------+ 
| COUNT(*) | 
+----------+
|        1 |
+----------+
1 row in set (0.03 sec) 

mysql> show trace; 
+-----------------------+-----------+-----------+--------------+--------------------+-------------------------------------------------------------------------------------------------------------------+
| OPERATION             | START(ms) | END(ms)   | DURATION(ms) | DATA_NODE          | SQL/REF                                                                                                           |
+-----------------------+-----------+-----------+--------------+--------------------+-------------------------------------------------------------------------------------------------------------------+
| Read SQL              | 0.0       | 0.063047  | 0.063047     | -                  | -                                                                                                                 |
| Parse SQL             | 0.063047  | 0.491182  | 0.428135     | -                  | -                                                                                                                 |
| Try Route Calculation | 0.491182  | 0.799576  | 0.308394     | -                  | -                                                                                                                 |
| Try to Optimize       | 0.799576  | 2.347412  | 1.547836     | -                  | -                                                                                                                 |
| Execute SQL           | 2.347412  | 11.183808 | 8.836396     | dn1.0              | select `sharding_two_node`.`id` as `autoalias_scalar` from  `sharding_two_node` where id = 1 LIMIT 2              |
| Fetch result          | 11.183808 | 12.360691 | 1.176883     | dn1.0              | select `sharding_two_node`.`id` as `autoalias_scalar` from  `sharding_two_node` where id = 1 LIMIT 2              |
| MERGE                 | 11.889546 | 12.436445 | 0.546899     | merge.1            | dn1.0                                                                                                             |
| LIMIT                 | 11.894923 | 12.483364 | 0.588441     | limit.1            | merge.1                                                                                                           |
| SHUFFLE_FIELD         | 11.896389 | 12.48483  | 0.588441     | shuffle_field.1    | limit.1                                                                                                           |
| SCALAR_SUB_QUERY      | 12.038123 | 12.485808 | 0.447685     | scalar_sub_query.1 | shuffle_field.1                                                                                                   |
| Generate New Query    | 12.485808 | 13.824463 | 1.338655     | -                  | -                                                                                                                 |
| Execute SQL           | 13.824463 | 26.749647 | 12.925184    | dn1.1              | scalar_sub_query.1; select COUNT(*) as `_$COUNT$_rpda_0` from  `sharding_two_node` where sharding_two_node.id = 1 |
| Fetch result          | 26.685134 | 28.753476 | 2.068342     | dn1.1              | scalar_sub_query.1; select COUNT(*) as `_$COUNT$_rpda_0` from  `sharding_two_node` where sharding_two_node.id = 1 |
| MERGE                 | 26.954918 | 29.091683 | 2.136765     | merge.2            | dn1.1                                                                                                             |
| ORDERED_GROUP         | 26.977889 | 29.563316 | 2.585427     | ordered_group.1    | merge.2                                                                                                           |
| SHUFFLE_FIELD         | 27.568285 | 29.567226 | 1.998941     | shuffle_field.2    | ordered_group.1                                                                                                   |
| Write to Client       | 27.72517  | 30.014911 | 2.289741     | -                  | -                                                                                                                 |
| Over All              | 0.0       | 30.014911 | 30.014911    | -                  | -                                                                                                                 |
+-----------------------+-----------+-----------+--------------+--------------------+-------------------------------------------------------------------------------------------------------------------+
18 rows in set (0.01 sec)

results matching ""

    No results matching ""