OceanBase 数据库中 SQL 第一次执行远程执行计划（Remote） 的 execute_time 时间较长

本文介绍 OceanBase 数据库中 SQL 第一次执行远程执行计划（Remote） 的 execute_time 时间较长的原因。

问题现象与原因

OceanBase 数据库中 plan_type =1 时，SQL 第一次在 LEADER 主节点执行，此时从 SQL_AUDIT 记录中查询到的本地执行计划（Local）执行所消耗的时间 execute_time 与后续 SQL 执行时间差不多，当 plan_type =2 时，SQL 第一次在 FOLLOWE 从节点执行，此时从 SQL_AUDIT 记录中查询到的远程执行计划（Remote）执行所消耗的时间 execute_time 比后续执行时间效长。有关 plan_type 与 execute_time 具体含义参考视图 gv$sql_audit。

示例如下。

1. 创建表。

   obclient [mysql]> CREATE TABLE test002 (c1 INT, c2 DATE);
   Query OK, 0 rows affected (0.034 sec)\
   

2. 创建插入数据的存储过程。

   obclient [mysql]> delimiter $$
   obclient [mysql]> create procedure proc_test002 (in insertcount int)
   begin
   declare i int default 1;
   label:while i<=insertcount do
   insert into test002 (c1,c2) values (i+FLOOR(RAND() * 100),'2025-05-01');
   set i=i+1;
   end while label;
   end $$
   Query OK, 0 rows affected (0.021 sec)
   

3. 调用存储过程。

   obclient [mysql]> delimiter ;
   obclient [mysql]> call proc_test002(10000);
   Query OK, 0 rows affected (2.697 sec)
   

4. 提交插入数据。

   obclient [mysql]> commit;
   Query OK, 0 rows affected (0.000 sec)
   

5. 通过 2881 端口直连 LEADER 主节点执行 SQL 6 次。

   obclient [mysql]> select c1,c2 from test002 where c1 = 1008;
   Empty set (0.009 sec)
   

6. 通过 2881 端口直连 FOLLOWE 从节点执行相同 SQL 6 次。

   obclient [mysql]> select c1,c2 from test002 where c1 = 1008;
   Empty set (0.006 sec)
   

7. 通过视图获取计划执行所消耗的时间 execute_time 值。

   MySQL [mysql]> select usec_to_time(request_time),svr_ip,sql_id,elapsed_time,execute_time,get_plan_time,is_hit_plan,plan_type,trace_id from oceanbase.gv$sql_audit where sql_id = '0B324789CF03733FB707A0B5C2D29904';
   

   输出结果如下：

   +----------------------------+---------------+----------------------------------+--------------+--------------+---------------+-------------+-----------+-----------------------------------+
   | usec_to_time(request_time) | svr_ip        | sql_id                           | elapsed_time | execute_time | get_plan_time | is_hit_plan | plan_type | trace_id                          |
   +----------------------------+---------------+----------------------------------+--------------+--------------+---------------+-------------+-----------+-----------------------------------+
   | 2024-01-04 18:11:15.728498 | xx.xxx.xx.xxx | 0B324789CF03733FB707A0B5C2D29904 |        10852 |         8699 |          2119 |           0 |         2 | YB420BA65786-00060E1AA0480EB9-0-0 |
   | 2024-01-04 18:11:26.816650 | xx.xxx.xx.xxx | 0B324789CF03733FB707A0B5C2D29904 |         7026 |         6914 |            74 |           1 |         2 | YB420BA65786-00060E1AA0480EBB-0-0 |
   | 2024-01-04 18:11:28.560264 | xx.xxx.xx.xxx | 0B324789CF03733FB707A0B5C2D29904 |         6610 |         6490 |            85 |           1 |         2 | YB420BA65786-00060E1AA0480EBC-0-0 |
   | 2024-01-04 18:11:29.912015 | xx.xxx.xx.xxx | 0B324789CF03733FB707A0B5C2D29904 |         6567 |         6468 |            66 |           1 |         2 | YB420BA65786-00060E1AA0480EBD-0-0 |
   | 2024-01-04 18:17:37.331060 | xx.xxx.xx.xxx | 0B324789CF03733FB707A0B5C2D29904 |         7006 |         6901 |            69 |           1 |         2 | YB420BA65786-00060E1AA0480EC4-0-0 |
   | 2024-01-04 18:17:39.754656 | xx.xxx.xx.xxx | 0B324789CF03733FB707A0B5C2D29904 |         6699 |         6588 |            77 |           1 |         2 | YB420BA65786-00060E1AA0480EC5-0-0 |
   | 2024-01-04 18:08:04.831272 | xx.xxx.xx.xxx | 0B324789CF03733FB707A0B5C2D29904 |         9843 |         6918 |          2888 |           0 |         1 | YB420BA655B1-00060D89865BD92B-0-0 |
   | 2024-01-04 18:09:00.039488 | xx.xxx.xx.xxx | 0B324789CF03733FB707A0B5C2D29904 |         6323 |         6247 |            40 |           1 |         1 | YB420BA655B1-00060D89865BD92D-0-0 |
   | 2024-01-04 18:09:01.589664 | xx.xxx.xx.xxx | 0B324789CF03733FB707A0B5C2D29904 |         6480 |         6347 |            81 |           1 |         1 | YB420BA655B1-00060D89865BD92E-0-0 |
   | 2024-01-04 18:09:02.894740 | xx.xxx.xx.xxx | 0B324789CF03733FB707A0B5C2D29904 |         6327 |         6241 |            49 |           1 |         1 | YB420BA655B1-00060D89865BD92F-0-0 |
   | 2024-01-04 18:09:04.077162 | xx.xxx.xx.xxx | 0B324789CF03733FB707A0B5C2D29904 |         6245 |         6173 |            40 |           1 |         1 | YB420BA655B1-00060D89865BD930-0-0 |
   | 2024-01-04 18:10:22.663582 | xx.xxx.xx.xxx | 0B324789CF03733FB707A0B5C2D29904 |         6519 |         6437 |            48 |           1 |         1 | YB420BA655B1-00060D89865BD933-0-0 |
   +----------------------------+---------------+----------------------------------+--------------+--------------+---------------+-------------+-----------+-----------------------------------+
   12 rows in set (0.06 sec)
   

因为当计划是远程计划时，会有两次硬解析，第一次是在本地，本地硬解析后发现是远程执行计划（Remote），将 SQL 发送至目标节点上，再次进行硬解析和执行。所以对远程执行计划（Remote）来说，从 OB_SQL_AUDIT 里查询到的第一次执行的 execute_time 实际是本地节点的硬解析时间（get_plan_time）+ 目标节点的硬解析时间（get_plan_time） + 目标节点执行时间（execute_time），第二次执行时就只有目标节点的 execute_time，符合预期。

适用版本

OceanBase 数据库 V2.x 和 V3.x 版本。