GBase 8a通过集群日志查看执行计划和每个阶段的整体耗时和各个节点的耗时做性能排查

GBase 8a提供了执行计划,以及不同的日志级别,现实整体各个节点耗时,以及每个节点的耗时,来方便用户进行性能排查,本文介绍详细的分析方法。

参考

GBase 8a 执行计划Explain介绍
GBase 8a集群开启执行日志分析性能
GBase 8a集群性能监控SQL在每个节点执行时间

环境

2节点虚拟机集群

[gbase@rh6-1 ~]$ gcadmin
CLUSTER STATE:  ACTIVE
CLUSTER MODE:   NORMAL

=================================================================
|             GBASE COORDINATOR CLUSTER INFORMATION             |
=================================================================
|   NodeName   |     IpAddress     |gcware |gcluster |DataState |
-----------------------------------------------------------------
| coordinator1 |    10.0.2.201     | OPEN  |  OPEN   |    0     |
-----------------------------------------------------------------
=============================================================
|              GBASE DATA CLUSTER INFORMATION               |
=============================================================
|NodeName |     IpAddress     |gnode |syncserver |DataState |
-------------------------------------------------------------
|  node1  |    10.0.2.201     | OPEN |   OPEN    |    0     |
-------------------------------------------------------------
|  node2  |    10.0.2.202     | OPEN |   OPEN    |    0     |
-------------------------------------------------------------

简单的单列表,50万行

gbase> show create table t1;
+-------+-------------------------------------------------------------------------------------------------------------------+
| Table | Create Table                                                                                                      |
+-------+-------------------------------------------------------------------------------------------------------------------+
| t1    | CREATE TABLE "t1" (
  "id" int(11) DEFAULT NULL
) ENGINE=EXPRESS DEFAULT CHARSET=utf8 TABLESPACE='sys_tablespace' |
+-------+-------------------------------------------------------------------------------------------------------------------+
1 row in set (Elapsed: 00:00:00.00)

gbase> select count(*) from t1;
+----------+
| count(*) |
+----------+
|   500000 |
+----------+
1 row in set (Elapsed: 00:00:00.06)

打开参数

其中profiling参数是可以直观的查看执行过程每个阶段的整体耗时。重点关注其中的Sending task to gnodes部分耗时。

gcluster_log_level参数7是可以查看到每个节点的具体SQL以及每个节点的耗时。

gbase> set profiling=1;
Query OK, 0 rows affected (Elapsed: 00:00:00.01)

gbase> set gcluster_log_level=7;
Query OK, 0 rows affected (Elapsed: 00:00:00.01)

执行计划

可以看到分成了3大部分。第0部分REDIST(id)是根据id列做重分布。第1部分[GATHER]是将各个节点的数据汇总,第2部分[RESULT]是返回结果。

gbase> explain select id,count(*) from t1 group by id order by count(*) desc limit 10;
+----+--------------+-----------+---------+-------------------------------------------------+-----------------+
| ID | MOTION       | OPERATION | TABLE   | CONDITION                                       | NO STAT Tab/Col |
+----+--------------+-----------+---------+-------------------------------------------------+-----------------+
| 02 | [RESULT]     |  Step     | <01>    |                                                 |                 |
|    |              |  ORDER    |         | ORDER BY cast(SUM_2ND(COUNT(0)) as signed) DESC |                 |
|    |              |  LIMIT    |         | LIMIT 10                                        |                 |
| 01 | [GATHER]     |  Step     | <00>    |                                                 |                 |
|    |              |  GROUP    |         | GROUP BY id                                     |                 |
|    |              |  ORDER    |         | ORDER BY .. DESC                                |                 |
|    |              |  LIMIT    |         | LIMIT 10                                        |                 |
| 00 | [REDIST(id)] |  Table    | t1[DIS] |                                                 | t1              |
|    |              |  GROUP    |         | GROUP BY id                                     |                 |
+----+--------------+-----------+---------+-------------------------------------------------+-----------------+
9 rows in set (Elapsed: 00:00:00.00)

执行SQL

包括profile的输出以及执行计划explain的结果。

gbase> select id,count(*) from t1 group by id order by count(*) desc limit 10;
+-------+----------+
| id    | count(*) |
+-------+----------+
| 27347 |       34 |
| 14427 |       32 |
| 27569 |       32 |
|  6983 |       32 |
| 32549 |       32 |
| 10186 |       32 |
| 25857 |       31 |
|  2197 |       31 |
| 23008 |       31 |
|  6582 |       31 |
+-------+----------+
10 rows in set (Elapsed: 00:00:00.77)

gbase> show profile;
+------------------------+----------+
| Status                 | Duration |
+------------------------+----------+
| parse                  | 0.000284 |
| init                   | 0.001421 |
| Preparing metadata     | 0.000495 |
| Executing by step      | 0.000550 |
| Creating tmp tables    | 0.000082 |
| Sending task to gnodes | 0.006993 |
| Sending task to gnodes | 0.666324 |
| Sending task to gnodes | 0.003851 |
| Creating tmp tables    | 0.000141 |
| Sending task to gnodes | 0.004463 |
| Sending task to gnodes | 0.068458 |
| Sending task to gnodes | 0.002863 |
| Sending task to gnodes | 0.011147 |
| Clearing tmp tables    | 0.000021 |
| Sending task to gnodes | 0.003134 |
| query end              | 0.000009 |
| freeing items          | 0.000113 |
| cleaning up            | 0.000003 |
+------------------------+----------+
18 rows in set (Elapsed: 00:00:00.00)

查看日志

查看gcluser/log/gcluster/express.log的对应输出。内部包含了整个执行过程以及每一步在每个节点的耗时情况。

先汇总一下后面详细日志的,方便查看

# 原始SQL
# 执行计划阶段
#0 第0步
##0-0 创建临时表
##0-1-1 创建临时表各个节点的执行时间
##0-2 将数据重分布到临时表
##0-2-1 重分布在各个节点的耗时
##0-3 刷新,因为重分布是底层操作,所以表一级要flush一下。
##0-3-1 刷新在各个节点耗时
#1 第1步
##1-1 在1个节点创建汇总临时表
##1-1-1 创建汇总临时表的耗时,注意只有1个
##1-2 汇总每个节点的结果到汇总表
##1-2-1 汇总耗时
##1-3 刷新汇总表
##1-3-1 刷新汇总表耗时
#2 第2步
##2-1 查询汇总表,得到结果
##2-1-1 查询汇总表耗时
#3 删除临时表,注意不同节点的SQL是不同的
#3-1 删除临时表耗时

原始日志

如下是express.log里面,日志等级为7的部分输出信息,其中[S:18]是对应的connection_id的编号18.

# 原始SQL
2020-11-10 09:54:16.382 [EXEC_P][INFO ][S:18][Q:38]:Original SQL:
select id,count(*) from t1 group by id order by count(*) desc limit 10
2020-11-10 09:54:16.382 [EXEC_P][INFO ][S:18][Q:38]:##############################
2020-11-10 09:54:16.382 [EXEC_P][INFO ][S:18][Q:38]:#### Main Query Begin ####
2020-11-10 09:54:16.382 [EXEC_P][INFO ][S:18][Q:38]:##############################

# 执行计划阶段
2020-11-10 09:54:16.382 [EXEC_P][INFO ][S:18][Q:38]:---Top plan is [0x5149de0]---

2020-11-10 09:54:16.382 [EXECTR][INFO ][S:18][Q:38]:Involved in 1 distribuitons
2020-11-10 09:54:16.383 [EXECTR][INFO ][S:18][Q:38]:===========Datacopymap Of Distribution 2===========
2020-11-10 09:54:16.383 [EXECTR][INFO ][S:18][Q:38]:|| n1 | ::ffff:10.0.2.202, ::ffff:10.0.2.201, ||
2020-11-10 09:54:16.383 [EXECTR][INFO ][S:18][Q:38]:|| n2 | ::ffff:10.0.2.201, ::ffff:10.0.2.202, ||
2020-11-10 09:54:16.383 [EXECTR][INFO ][S:18][Q:38]:===================================================
2020-11-10 09:54:16.383 [EXECTR][INFO ][S:18][Q:38]:Selected a random coordinator node: 10.0.2.201
2020-11-10 09:54:16.383 [EXECTR][INFO ][S:18][Q:38]:Coordinator node is 10.0.2.201
2020-11-10 09:54:16.383 [EXECTR][INFO ][S:18][Q:38]:--#--Begin a async API mode--#--
2020-11-10 09:54:16.383 [EXECTR][INFO ][S:18][Q:38]:A plan Begin ...
2020-11-10 09:54:16.383 [EXECTR][INFO ][S:18][Q:38]:Current plan [0x5149de0] has 0 scalar subquery.
2020-11-10 09:54:16.383 [EXECTR][INFO ][S:18][Q:38]:Current plan [0x5149de0] has 0 from subquery.
2020-11-10 09:54:16.383 [EXECTR][INFO ][S:18][Q:38]:Current plan [0x5149de0] has 0 union subquery.
2020-11-10 09:54:16.383 [EXEC_P][INFO ][S:18][Q:38]:Current plan [0x5149de0] has 3 steps.


#0 第0步
2020-11-10 09:54:16.383 [EXEC_P][INFO ][S:18][Q:38]:## STEP: 0 ...

2020-11-10 09:54:16.383 [EXECTR][INFO ][S:18][Q:38]:Current plan [0x5149de0] has 0 uncorrelated subquery.
2020-11-10 09:54:16.383 [EXECTR][INFO ][S:18][Q:38]:Distribution Info, /[8a:P2C2]
##0-0 创建临时表
2020-11-10 09:54:16.383 [EXECTR][INFO ][S:18][Q:38]:---Step detail: hash redistribute the table in gbase.
2020-11-10 09:54:16.384 [EXECTR][INFO ][S:18][Q:38]:Passed tasks to async API, good luck!

2020-11-10 09:54:16.385 [SQLDISP][INFO ][S:18][Q:38]:Target:HOST(::ffff:10.0.2.202:5050->33) , SQL:CREATE TABLE `gctmpdb`._tmp_rht_3372351498_18_t2_1_1604972970_s_n1 AS SELECT /*::ffff:10.0.2.201_18_4_2020-11-10_09:54:16*/ /*+ TID('2621458') */ `testdb.t1`.`id` AS `c2`, COUNT(0) AS `c3` FROM `testdb`.`t1_n1` `testdb.t1` GROUP BY `testdb.t1`.`id` LIMIT 0 ; commit.
2020-11-10 09:54:16.385 [SQLDISP][INFO ][S:18][Q:38]:Target:HOST(::ffff:10.0.2.201:5050->10) , SQL:CREATE TABLE `gctmpdb`._tmp_rht_3372351498_18_t2_1_1604972970_s_n2 AS SELECT /*::ffff:10.0.2.201_18_4_2020-11-10_09:54:16*/ /*+ TID('2621458') */ `testdb.t1`.`id` AS `c2`, COUNT(0) AS `c3` FROM `testdb`.`t1_n2` `testdb.t1` GROUP BY `testdb.t1`.`id` LIMIT 0 ; commit.

##0-1-1 创建临时表各个节点的执行时间
2020-11-10 09:54:16.393 [EXECTR][INFO ][S:18][Q:38]:
-----------------+----Node Performance----+---------------
+-Type-+-------Node------+-Port-+---Elapsed---+--Status--+
|  T   | ::ffff:10.0.2.202 | 5050 | 0         s | Finish   |
|  T   | ::ffff:10.0.2.201 | 5050 | 0         s | Finish   |
+------+-----------------+------+-------------+----------+

2020-11-10 09:54:16.394 [EXECTR][INFO ][S:18][Q:38]:Passed tasks to async API, good luck!

##0-2 将数据重分布到临时表
2020-11-10 09:54:16.397 [SQLDISP][INFO ][S:18][Q:38]:Target:HOST(::ffff:10.0.2.202:5050->33) , SQL:SELECT /*::ffff:10.0.2.201_18_4_2020-11-10_09:54:16*/ /*+ TID('2621458') */ `testdb.t1`.`id` AS `c2`, COUNT(0) AS `c3` FROM `testdb`.`t1_n1` `testdb.t1` GROUP BY `testdb.t1`.`id` target into server (HOST '::ffff:10.0.2.202,::ffff:10.0.2.201', PORT 5050, USER 'root', PASSWORD '', DATABASE 'gctmpdb', TABLE '_tmp_rht_3372351498_18_t2_1_1604972970_s_n1,_tmp_rht_3372351498_18_t2_1_1604972970_s_n2', COMMENT 'group 0, distribution 2, hash_map 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
2020-11-10 09:54:16.400 [SQLDISP][INFO ][S:18][Q:38]:Target:HOST(::ffff:10.0.2.201:5050->10) , SQL:SELECT /*::ffff:10.0.2.201_18_4_2020-11-10_09:54:16*/ /*+ TID('2621458') */ `testdb.t1`.`id` AS `c2`, COUNT(0) AS `c3` FROM `testdb`.`t1_n2` `testdb.t1` GROUP BY `testdb.t1`.`id` target into server (HOST '::ffff:10.0.2.202,::ffff:10.0.2.201', PORT 5050, USER 'root', PASSWORD '', DATABASE 'gctmpdb', TABLE '_tmp_rht_3372351498_18_t2_1_1604972970_s_n1,_tmp_rht_3372351498_18_t2_1_1604972970_s_n2', COMMENT 'group 0, distribution 2, hash_map 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0

##0-2-1 重分布在各个节点的耗时
2020-11-10 09:54:17.140 [EXECTR][INFO ][S:18][Q:38]:
-----------------+----Node Performance----+---------------
+-Type-+-------Node------+-Port-+---Elapsed---+--Status--+
|  T   | ::ffff:10.0.2.201 | 5050 | 1         s | Finish   |
|  T   | ::ffff:10.0.2.202 | 5050 | 0         s | Finish   |
+------+-----------------+------+-------------+----------+

2020-11-10 09:54:17.140 [EXECTR][INFO ][S:18][Q:38]:Passed tasks to async API, good luck!

##0-3 刷新,因为重分布是底层操作,所以表一级要flush一下。
2020-11-10 09:54:17.141 [SQLDISP][INFO ][S:18][Q:38]:Target:HOST(::ffff:10.0.2.202:5050->33) , SQL:flush temporary commit `gctmpdb`._tmp_rht_3372351498_18_t2_1_1604972970_s_n1.
2020-11-10 09:54:17.141 [SQLDISP][INFO ][S:18][Q:38]:Target:HOST(::ffff:10.0.2.201:5050->10) , SQL:flush temporary commit `gctmpdb`._tmp_rht_3372351498_18_t2_1_1604972970_s_n2.

##0-3-1 刷新在各个节点耗时
2020-11-10 09:54:17.144 [EXECTR][INFO ][S:18][Q:38]:
-----------------+----Node Performance----+---------------
+-Type-+-------Node------+-Port-+---Elapsed---+--Status--+
|  T   | ::ffff:10.0.2.202 | 5050 | 0         s | Finish   |
|  T   | ::ffff:10.0.2.201 | 5050 | 0         s | Finish   |
+------+-----------------+------+-------------+----------+

#1 第1步
2020-11-10 09:54:17.144 [EXEC_P][INFO ][S:18][Q:38]:## STEP: 1 ...

2020-11-10 09:54:17.144 [EXECTR][INFO ][S:18][Q:38]:Current plan [0x5149de0] has 0 uncorrelated subquery.
2020-11-10 09:54:17.144 [EXECTR][INFO ][S:18][Q:38]:Distribution Info, [Coor:C2]/[8a:P2]
2020-11-10 09:54:17.144 [EXECTR][INFO ][S:18][Q:38]:---Step detail: 8a to cluster, gbase8a is producer and gcluster is consumer, the query result is store in gcluster.
2020-11-10 09:54:17.145 [EXECTR][INFO ][S:18][Q:38]:Passed tasks to async API, good luck!

##1-1 在1个节点创建汇总临时表
2020-11-10 09:54:17.145 [SQLDISP][INFO ][S:18][Q:38]:Target:HOST(::ffff:10.0.2.201:5050->10) , SQL:CREATE TABLE `gctmpdb`._tmp_3372351498_18_t2_2_1604972970_s AS SELECT /*::ffff:10.0.2.201_18_4_2020-11-10_09:54:16*/ /*+ TID('2621458') */ `_tmp_rht_3372351498_18_t2_1_1604972970_s_n2`.`c2` AS `c4`, cast(SUM_2ND(`_tmp_rht_3372351498_18_t2_1_1604972970_s_n2`.`c3`) as signed) AS `c5` FROM `gctmpdb`._tmp_rht_3372351498_18_t2_1_1604972970_s_n2 GROUP BY `_tmp_rht_3372351498_18_t2_1_1604972970_s_n2`.`c2` LIMIT 0 ; commit.

##1-1-1 创建汇总临时表的耗时,注意只有1个
2020-11-10 09:54:17.181 [EXECTR][INFO ][S:18][Q:38]:
-----------------+----Node Performance----+---------------
+-Type-+-------Node------+-Port-+---Elapsed---+--Status--+
|  T   | ::ffff:10.0.2.201 | 5050 | 0         s | Finish   |
+------+-----------------+------+-------------+----------+

2020-11-10 09:54:17.181 [EXECTR][INFO ][S:18][Q:38]:Passed tasks to async API, good luck!

##1-2 汇总每个节点的结果到汇总表
2020-11-10 09:54:17.181 [SQLDISP][INFO ][S:18][Q:38]:Target:HOST(::ffff:10.0.2.202:5050->33) , SQL:SELECT /*::ffff:10.0.2.201_18_4_2020-11-10_09:54:16*/ /*+ TID('2621458') */ `_tmp_rht_3372351498_18_t2_1_1604972970_s_n1`.`c2` AS `c4`, cast(SUM_2ND(`_tmp_rht_3372351498_18_t2_1_1604972970_s_n1`.`c3`) as signed) AS `c5` FROM `gctmpdb`._tmp_rht_3372351498_18_t2_1_1604972970_s_n1 GROUP BY `_tmp_rht_3372351498_18_t2_1_1604972970_s_n1`.`c2` ORDER BY `c5` DESC LIMIT 10 target into server (HOST '::ffff:10.0.2.201', PORT 5050, USER 'root', PASSWORD '', DATABASE 'gctmpdb', TABLE '_tmp_3372351498_18_t2_2_1604972970_s', COMMENT '' ).
2020-11-10 09:54:17.181 [SQLDISP][INFO ][S:18][Q:38]:Target:HOST(::ffff:10.0.2.201:5050->10) , SQL:SELECT /*::ffff:10.0.2.201_18_4_2020-11-10_09:54:16*/ /*+ TID('2621458') */ `_tmp_rht_3372351498_18_t2_1_1604972970_s_n2`.`c2` AS `c4`, cast(SUM_2ND(`_tmp_rht_3372351498_18_t2_1_1604972970_s_n2`.`c3`) as signed) AS `c5` FROM `gctmpdb`._tmp_rht_3372351498_18_t2_1_1604972970_s_n2 GROUP BY `_tmp_rht_3372351498_18_t2_1_1604972970_s_n2`.`c2` ORDER BY `c5` DESC LIMIT 10 target into server (HOST '::ffff:10.0.2.201', PORT 5050, USER 'root', PASSWORD '', DATABASE 'gctmpdb', TABLE '_tmp_3372351498_18_t2_2_1604972970_s', COMMENT '' ).

##1-2-1 汇总耗时
2020-11-10 09:54:17.270 [EXECTR][INFO ][S:18][Q:38]:
-----------------+----Node Performance----+---------------
+-Type-+-------Node------+-Port-+---Elapsed---+--Status--+
|  T   | ::ffff:10.0.2.201 | 5050 | 0         s | Finish   |
|  T   | ::ffff:10.0.2.202 | 5050 | 0         s | Finish   |
+------+-----------------+------+-------------+----------+

2020-11-10 09:54:17.271 [EXECTR][INFO ][S:18][Q:38]:Passed tasks to async API, good luck!

##1-3 刷新汇总表
2020-11-10 09:54:17.271 [SQLDISP][INFO ][S:18][Q:38]:Target:HOST(::ffff:10.0.2.201:5050->10) , SQL:flush temporary commit `gctmpdb`._tmp_3372351498_18_t2_2_1604972970_s.

##1-3-1 刷新汇总表耗时
2020-11-10 09:54:17.272 [EXECTR][INFO ][S:18][Q:38]:
-----------------+----Node Performance----+---------------
+-Type-+-------Node------+-Port-+---Elapsed---+--Status--+
|  T   | ::ffff:10.0.2.201 | 5050 | 0         s | Finish   |
+------+-----------------+------+-------------+----------+


#2 第2步
2020-11-10 09:54:17.272 [EXEC_P][INFO ][S:18][Q:38]:## STEP: 2 ...

2020-11-10 09:54:17.272 [EXECTR][INFO ][S:18][Q:38]:Current plan [0x5149de0] has 0 uncorrelated subquery.
2020-11-10 09:54:17.272 [EXECTR][INFO ][S:18][Q:38]:Distribution Info, [Coor:P2]
2020-11-10 09:54:17.272 [EXECTR][INFO ][S:18][Q:38]:---Step detail: cluster to client, gcluster is procducer and send the query result to client.
2020-11-10 09:54:17.272 [EXECTR][INFO ][S:18][Q:38]:Passed tasks to async API, good luck!

##2-1 查询汇总表,得到结果
2020-11-10 09:54:17.273 [SQLDISP][INFO ][S:18][Q:38]:Target:HOST(::ffff:10.0.2.201:5050->10) , SQL:SELECT /*::ffff:10.0.2.201_18_4_2020-11-10_09:54:16*/ /*+ TID('2621458') */ `_tmp_3372351498_18_t2_2_1604972970_s`.`c4` AS `id`, `_tmp_3372351498_18_t2_2_1604972970_s`.`c5` AS `count(*)` FROM `gctmpdb`._tmp_3372351498_18_t2_2_1604972970_s ORDER BY `count(*)` DESC LIMIT 10.
2020-11-10 09:54:17.274 [EXECTR][INFO ][S:18][Q:38]:Sent Rows: 10

##2-1-1 查询汇总表耗时
2020-11-10 09:54:17.274 [EXECTR][INFO ][S:18][Q:38]:
-----------------+----Node Performance----+---------------
+-Type-+-------Node------+-Port-+---Elapsed---+--Status--+
|  T   | ::ffff:10.0.2.201 | 5050 | 0         s | Finish   |
+------+-----------------+------+-------------+----------+

2020-11-10 09:54:17.274 [EXECTR][INFO ][S:18][Q:38]:Finish all steps of plan [0x5149de0].

2020-11-10 09:54:17.274 [EXECTR][INFO ][S:18][Q:38]:Passed tasks to async API, good luck!


#3 删除临时表,注意不同节点的SQL是不同的
2020-11-10 09:54:17.276 [SQLDISP][INFO ][S:18][Q:38]:Target:HOST(::ffff:10.0.2.201:5050->24) , SQL:DROP TABLE IF EXISTS `gctmpdb`._tmp_3372351498_18_t2_2_1604972970_s;DROP TABLE IF EXISTS `gctmpdb`._tmp_rht_3372351498_18_t2_1_1604972970_s_n2.
2020-11-10 09:54:17.278 [SQLDISP][INFO ][S:18][Q:38]:Target:HOST(::ffff:10.0.2.202:5050->42) , SQL:DROP TABLE IF EXISTS `gctmpdb`._tmp_rht_3372351498_18_t2_1_1604972970_s_n1.

#3-1 删除临时表耗时
2020-11-10 09:54:17.279 [EXECTR][INFO ][S:18][Q:38]:
-----------------+----Node Performance----+---------------
+-Type-+-------Node------+-Port-+---Elapsed---+--Status--+
|  T   | ::ffff:10.0.2.202 | 5050 | 0         s | Finish   |
|  T   | ::ffff:10.0.2.201 | 5050 | 0         s | Finish   |
+------+-----------------+------+-------------+----------+