dbms_xplan.display_active_session_plan 记录的 real_time 实时时间不准确问题

问题现象

在 OceanBase 数据库中，使用 dbms_xplan.display_active_session_plan 查看 SQL 执行计划时，发现记录的 real_time（实际执行时间）与 gv$ob_processlist 中显示的时间不一致。具体表现为 dbms_xplan.display_active_session_plan 内的 real_time 显示的时间远大于 gv$ob_processlist 中的时间，而后者被认为是准确的时间。此问题在 SQL 执行跨分钟后尤为明显。 第一次复现： gv$ob_processlist 中目标 SQL 的 TIME、TOTAL_TIME 为 175 秒，TOTAL_CPU_TIME 为 176 秒，但 dbms_xplan.display_active_session_plan 内显示的 REAL.TIME 超过 4300 秒（以 gv$ob_processlist 为准）。

1. 通过如下 SQL 查询 gv$ob_processlist，确认目标 SQL 的执行时间：

   select t.info, t.* from gv$ob_processlist t where t.state = 'ACTIVE';
   

   查询结果中，目标 SQL 行的关键字段如下（已省略非关键字段）： | INFO | ID | COMMAND | TIME | TOTAL_TIME | TOTAL_CPU_TIME | | --- | --- | --- | --- | --- | --- | | insert into ... select ... | 3221696845 | Query | 175 | 175 | 176 |

2. 通过如下 SQL 查询目标会话的执行计划：

   select * from table(dbms_xplan.display_active_session_plan(3221696845));
   

   执行计划中 REAL.TIME(us) 显示异常，关键算子摘录如下： | ID | OPERATOR | NAME | EST.ROWS | EST.TIME(us) | REAL.ROWS | REAL.TIME(us) | IO TIME(us) | CPU TIME(us) | | --- | --- | --- | --- | --- | --- | --- | --- | --- | | 0 | INSERT | | 40677437 | 392069733 | 0 | 0 | 0 | 196045588 | | 1 | └─PX COORDINATOR | | 40677437 | 134472356 | 22255872 | 0 | 2080 | 5033069 | | 2 | └─EXCHANGE OUT DISTR | :EX10000 | 40677437 | 93601122 | 22262486 | 0 | 195058144 | 199859739 | | 3 | └─SUBPLAN SCAN | ANONYMOUS_VIEW1 | 40677437 | 1710380 | 22262486 | 0 | 0 | 84626 | | 4 | └─PX PARTITION ITERATOR | | 40677437 | 1602710 | 22262486 | 0 | 0 | 19344 | | 5 | └─TABLE FULL SCAN | <table_name> | 40677437 | 1602710 | 22262486 | 4318182198 | 0 | 1122308 | 第二次复现： gv$ob_processlist 中目标 SQL 的 TIME、TOTAL_TIME、TOTAL_CPU_TIME 均为 204 秒，而 dbms_xplan.display_active_session_plan 内的 REAL.TIME 显示为 322 秒（以 gv$ob_processlist 为准）。

3. 通过如下 SQL 查询 gv$ob_processlist，确认目标 SQL 的执行时间：

   select t.info, t.* from gv$ob_processlist t where t.state = 'ACTIVE';
   

   查询结果中，目标 SQL 行的关键字段如下（已省略非关键字段）： | INFO | ID | COMMAND | TIME | TOTAL_TIME | TOTAL_CPU_TIME | | --- | --- | --- | --- | --- | --- | | insert into ... select ... | 3221739044 | Query | 204 | 204 | 204 |

4. 通过如下 SQL 查询目标会话的执行计划：

   select * from table(dbms_xplan.display_active_session_plan(3221739044, 'all', 'x.x.x.x', 2882));
   

   执行计划中 REAL.TIME(us) 显示异常，关键算子摘录如下： | ID | OPERATOR | NAME | EST.ROWS | EST.TIME(us) | REAL.ROWS | REAL.TIME(us) | IO TIME(us) | CPU TIME(us) | | --- | --- | --- | --- | --- | --- | --- | --- | --- | | 0 | INSERT | | 40677437 | 392069733 | 0 | 0 | 0 | 197131675 | | 1 | └─PX COORDINATOR | | 40677437 | 134472356 | 21240064 | 0 | 2586 | 4961088 | | 2 | └─EXCHANGE OUT DISTR | :EX10000 | 40677437 | 93601122 | 21246568 | 0 | 195593768 | 200854057 | | 3 | └─SUBPLAN SCAN | ANONYMOUS_VIEW1 | 40677437 | 1710380 | 21246568 | 0 | 0 | 85896 | | 4 | └─PX PARTITION ITERATOR | | 40677437 | 1602710 | 21246568 | 0 | 0 | 33880 | | 5 | └─TABLE FULL SCAN | <table_name> | 40677437 | 1602710 | 21246568 | 322018618 | 0 | 1110025 |

关键诊断信息

触发条件

• 目标 SQL 执行跨分钟后，使用 dbms_xplan.display_active_session_plan 查询执行计划时出现 real_time 显示异常。

事后诊断

1. 执行如下 SQL 查询 gv$ob_processlist 视图，TOTAL_TIME 字段显示的时间被认为是准确的时间：

   select t.info, t.* from gv$ob_processlist t where t.state = 'ACTIVE';
   

2. 执行如下 SQL 查询目标会话的执行计划，获取 real_time：

   select * from table(dbms_xplan.display_active_session_plan(<session_id>));
   

3. 对比两者的时间：若 dbms_xplan.display_active_session_plan 内的 real_time 远大于 gv$ob_processlist 中的 TOTAL_TIME，且目标 SQL 执行跨分钟，则可确认命中此问题。

问题原因

该问题由 OceanBase 数据库内核缺陷导致：dbms_xplan.display_active_session_plan 在计算 real_time（实际执行时间）时存在缺陷，导致 SQL 执行跨分钟后计算出的 real_time 明显偏大，与 gv$ob_processlist 中显示的实际执行时间不一致。

问题的风险及影响

dbms_xplan.display_active_session_plan 的 real_time 展示错误，可能导致用户对 SQL 执行效率的误解，影响性能调优和故障排查工作。

影响租户

影响所有使用 dbms_xplan.display_active_session_plan 查询 SQL 执行计划的租户。

影响版本

影响所有 4.x 版本中支持 dbms_xplan.display_active_session_plan 查询的版本。 | 影响版本 | | --- | | V4.0.x | | V4.1.x | | V4.2.x | | V4.3.x | | V4.4.x |

解决方法

升级到修复该问题的 OceanBase 数据库版本，升级后 real_time 将恢复正常显示。

规避方式

暂无有效的规避方式。在升级到修复版本前，可以以 gv$ob_processlist 中的时间作为参考。