GBase 8a数据库集群，可以通过开启详细日志级别，查看在SQL整个过程的耗时情况，包括执行计划，下发，返回结果给客户端等。
目录导航
1.1.1. 作用
记录集群层SQL的完整执行过程，包括锁，对外交互(比如ftp加载)，执行计划等，重点过程上。具体的SQL执行，内部资源消耗，还得看trc日志。
1.1.2. 使用方法
使用集群客户端 gccli
// 默认值是3，这个是session级别的，无需恢复
gbase> set gcluster_log_level=7;
// 日志级别更细
gbase> set global gbase_sql_trace_level=15;
// 打开日志
gbase> set gbase_sql_trace=1;
第一个参数是设置集群层日志的等级，包括锁，对外交互等。记录在express.log里。
第二个参数是SQL执行日志，记录在trc日志里。
第三个参数是设置打开和关闭跟踪日志，可以是session级的。 执行SQL语句后，在gcluster的log目录下的express.log里有详细的集群层调度日志。在gnode的log目录下生成执行计划每一步的具体SQL的trc结尾的日志。
express.log的样例。 里面可以根据[S:65][Q:274] 进行过滤。S代表sessionID, 而Q是queryid也就是每个查询有不同的编号(taskid)。
一个session可以执行多个任务,其SessionID相同，但QueryId不同。
gbase> set gcluster_log_level=7;
Query OK, 0 rows affected (Elapsed: 00:00:00.00)
gbase> select id,count(*) from testdb.t1 group by id;
+--------+----------+
| id | count(*) |
+--------+----------+
| 111111 | 1 |
+--------+----------+
1 row in set (Elapsed: 00:00:00.05)
2020-11-06 17:49:39.972 [EXEC_P][INFO ][S:65][Q:274]:Original SQL:
2020-11-06 17:49:39.972 [EXEC_P][INFO ][S:65][Q:274]:##############################
2020-11-06 17:49:39.972 [EXEC_P][INFO ][S:65][Q:274]:#### Main Query Begin ####
2020-11-06 17:49:39.972 [EXEC_P][INFO ][S:65][Q:274]:##############################
2020-11-06 17:49:39.972 [EXEC_P][INFO ][S:65][Q:274]:---Top plan is [0x512e2e0]---
2020-11-06 17:49:39.972 [EXECTR][INFO ][S:65][Q:274]:Involved in 1 distribuitons
2020-11-06 17:49:39.973 [EXECTR][INFO ][S:65][Q:274]:Selected a random coordinator node: 10.0.2.102
2020-11-06 17:49:39.973 [EXECTR][INFO ][S:65][Q:274]:Coordinator node is 10.0.2.102
2020-11-06 17:49:39.973 [EXECTR][INFO ][S:65][Q:274]:--#--Begin a async API mode--#--
2020-11-06 17:49:39.973 [EXECTR][INFO ][S:65][Q:274]:A plan Begin ...
2020-11-06 17:49:39.973 [EXECTR][INFO ][S:65][Q:274]:Current plan [0x512e2e0] has 0 scalar subquery.
2020-11-06 17:49:39.973 [EXECTR][INFO ][S:65][Q:274]:Current plan [0x512e2e0] has 0 from subquery.
2020-11-06 17:49:39.973 [EXECTR][INFO ][S:65][Q:274]:Current plan [0x512e2e0] has 0 union subquery.
2020-11-06 17:49:39.973 [EXEC_P][INFO ][S:65][Q:274]:Current plan [0x512e2e0] has 2 steps.
2020-11-06 17:49:39.973 [EXEC_P][INFO ][S:65][Q:274]:## STEP: 0 ...
2020-11-06 17:49:39.973 [EXECTR][INFO ][S:65][Q:274]:Current plan [0x512e2e0] has 0 uncorrelated subquery.
2020-11-06 17:49:39.973 [EXECTR][INFO ][S:65][Q:274]:Distribution Info, /[8a:P1C1]
2020-11-06 17:49:39.973 [EXECTR][INFO ][S:65][Q:274]:---Step detail: hash redistribute the table in gbase.
2020-11-06 17:49:39.973 [EXECTR][INFO ][S:65][Q:274]:Passed tasks to async API, good luck!
2020-11-06 17:49:39.974 [EXECTR][INFO ][S:65][Q:274]:AsyncAPI connect success!
2020-11-06 17:49:39.974 [SQLDISP][INFO ][S:65][Q:274]:Target:10.0.2.102, SQL:CREATE TABLE `gctmpdb`._tmp_rht_1711407114_65_t30_1_1604624808_s_n1 AS SELECT /*10.0.2.102_65_87_2020-11-06_17:49:39*/ /*+ TID('1048772') */ `testdb.t1`.`id` AS `c1`, COUNT(0) AS `c2` FROM `testdb`.`t1_n1` `testdb.t1` GROUP BY `testdb.t1`.`id` LIMIT 0 ; commit.
2020-11-06 17:49:39.980 [EXECTR][INFO ][S:65][Q:274]:
2020-11-06 17:49:39.980 [EXECTR][INFO ][S:65][Q:274]:Passed tasks to async API, good luck!
2020-11-06 17:49:39.981 [EXECTR][INFO ][S:65][Q:274]:AsyncAPI connect success!
2020-11-06 17:49:39.984 [SQLDISP][INFO ][S:65][Q:274]:Target:10.0.2.102, SQL:SELECT /*10.0.2.102_65_87_2020-11-06_17:49:39*/ /*+ TID('1048772') */ `testdb.t1`.`id` AS `c1`, COUNT(0) AS `c2` FROM `testdb`.`t1_n1` `testdb.t1` GROUP BY `testdb.t1`.`id` target into server (HOST '10.0.2.102', PORT 5050, USER 'root', PASSWORD '', DATABASE 'gctmpdb', TABLE '_tmp_rht_1711407114_65_t30_1_1604624808_s_n1', COMMENT 'group 0, distribution 1, 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 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 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-06 17:49:40.014 [EXECTR][INFO ][S:65][Q:274]:
2020-11-06 17:49:40.014 [EXECTR][INFO ][S:65][Q:274]:Passed tasks to async API, good luck!
2020-11-06 17:49:40.015 [EXECTR][INFO ][S:65][Q:274]:AsyncAPI connect success!
2020-11-06 17:49:40.015 [SQLDISP][INFO ][S:65][Q:274]:Target:10.0.2.102, SQL:flush temporary commit `gctmpdb`._tmp_rht_1711407114_65_t30_1_1604624808_s_n1.
2020-11-06 17:49:40.017 [EXECTR][INFO ][S:65][Q:274]:
2020-11-06 17:49:40.018 [EXEC_P][INFO ][S:65][Q:274]:## STEP: 1 ...
2020-11-06 17:49:40.018 [EXECTR][INFO ][S:65][Q:274]:Current plan [0x512e2e0] has 0 uncorrelated subquery.
2020-11-06 17:49:40.018 [EXECTR][INFO ][S:65][Q:274]:Distribution Info, /[8a:P1]
2020-11-06 17:49:40.018 [EXECTR][INFO ][S:65][Q:274]:---Step detail: 8a to client, query to all gnode
2020-11-06 17:49:40.018 [EXECTR][INFO ][S:65][Q:274]:Passed tasks to async API, good luck!
2020-11-06 17:49:40.018 [EXECTR][INFO ][S:65][Q:274]:AsyncAPI connect success!
2020-11-06 17:49:40.018 [SQLDISP][INFO ][S:65][Q:274]:Target:10.0.2.102, SQL:SELECT /*10.0.2.102_65_87_2020-11-06_17:49:39*/ /*+ TID('1048772') */ `_tmp_rht_1711407114_65_t30_1_1604624808_s_n1`.`c1` AS `id`, cast(SUM_2ND(`_tmp_rht_1711407114_65_t30_1_1604624808_s_n1`.`c2`) as signed) AS `count(*)` FROM `gctmpdb`._tmp_rht_1711407114_65_t30_1_1604624808_s_n1 GROUP BY `_tmp_rht_1711407114_65_t30_1_1604624808_s_n1`.`c1`.
2020-11-06 17:49:40.020 [EXECTR][INFO ][S:65][Q:274]:Sent Rows: 1
2020-11-06 17:49:40.020 [EXECTR][INFO ][S:65][Q:274]:
2020-11-06 17:49:40.020 [EXECTR][INFO ][S:65][Q:274]:Finish all steps of plan [0x512e2e0].
2020-11-06 17:49:40.020 [EXECTR][INFO ][S:65][Q:274]:Passed tasks to async API, good luck!
2020-11-06 17:49:40.020 [EXECTR][INFO ][S:65][Q:274]:AsyncAPI connect success!
2020-11-06 17:49:40.020 [SQLDISP][INFO ][S:65][Q:274]:Target:10.0.2.102, SQL:DROP TABLE IF EXISTS `gctmpdb`._tmp_rht_1711407114_65_t30_1_1604624808_s_n1.
2020-11-06 17:49:40.021 [EXECTR][INFO ][S:65][Q:274]: