分享：ODC 如何精准展现 SQL 执行的耗时？

2023-03-24
浙江
本文字数：3656 字
阅读完需：约 12 分钟

欢迎访问 OceanBase 官网获取更多信息：https://www.oceanbase.com/

本文来自 OceanBase 社区分享，仅限交流探讨。原作者刘亦卓，OceanBase 开发工程师

前言

在我们程序员或 DBA 的工作中，写 SQL 并执行就像吃一口饭一样平常。使用黑屏客户端时，往往要面对 SQL 编写困难、错误难以快速识别、查询结果不易读等问题，因此通常会选择一款图形化化工具以调试、执行 SQL 。那么你是否会好奇，当我们使用可视化的开发者工具执行一条 SQL 时，从点击执行，到展示结果、查询执行计划这个过程，这条 SQL 经历了什么呢？如果点击执行很久才能得到结果，这中间又是哪个阶段出了问题呢？

ODC 作为数据库开发者工具，致力于为用户提供更高效、更易用的 SQL 执行与诊断方案，在 4.1.0 版本，对 SQL 执行阶段的耗时也做了进一步的细化展示，以方便用户更清晰的了解 SQL 耗时详情。本文以 OB-Oracle 模式下一条 SQL 在 ODC 以及 OBServer 上的生命周期为例，介绍 ODC SQL 执行过程及耗时计算方案。

SQL 的执行过程

前置处理

在 SQL 被实际执行前，首先会被解析，获取其操作对象类型、是否加写锁（for update）、是否为多表查询等基础信息。之后根据解析结果，若其满足一定的条件，可能会对 SQL 进行改写操作。

Apply SQL

改写包括两点，一是为了提升查询性能，当语句为 SELECT 类型，查询字段中包含 * 且非 .* 的语句时，会尝试替换为 table.* ；二是会在 SELECT 后增加 ROWID AS __ODC_INTERNAL_ROWID__ 的字段，这是因为结果集编辑时，若查询中未指定 ROWID 字段，那么可能会出现数据误更新的情况。

以 SELECT * FROM DEMO; 为例，在发出执行请求后，会被改写为：

SELECT ROWID AS "__ODC_INTERNAL_ROWID__", DEMO.* FROM DEMO;

Validate SQL semantics

尽管对是否改写 SQL 已经经过了一定的判定，但仍然可能出现改写后无法执行的情况，例如查询 GV$SYSSTAT 等不支持 ROWID 的系统视图，那么即便语法不存在错误，也会导致执行失败。

为了避免改写导致的执行失败，在真实执行 SQL 之前，会执行 EXPLAIN + SQL ，若执行成功则说明改写成功，执行改写后的 SQL 并返回结果，否则仍然会采用原 SQL。

SQL 执行

SQL 执行阶段是 SQL 生命周期中最主要的阶段，其经过内部处理和准备后，通过网络协议一次或多次发送至 OceanBase Server 端，由 OBServer 进行具体执行操作，之后将结果以同样的方式返回客户端。

一条 SQL 在调用 JDBC 驱动执行语句后，驱动首先会进行一系列准备，例如设置查询行数限制、判断是否通过代理连接 Server 、设置执行超时计时器等，这个阶段记作 Jdbc prepare 。

SQL 在从客户端发送至 OceanBase Server 端后，会进入等待队列，若租户 CPU 不足或服务器负载过高，则此过程可能会耗费大量时间。结束排队后，将会对其进行解析、改写和获取 SELECT 语句的执行计划，该过程若未命中缓存，也可能占用较长时间。拿到物理执行计划后，执行器才会调用线程执行该条 SQL ，并将计划保存至缓存中。为简化理解成本，上述一系列操作合并记作 OBServer wait 阶段。

OBServer 执行完成后，将数据返回客户端，通过 Get result-set 阶段，从返回结果中解析出要展示的数据，至此，便是一条 SQL 的实际执行过程。

后置处理

在获取到执行结果后，为了客户端的展示、编辑及错误提示，还会对该条 SQL 和执行结果进行几项后置处理。

Init SQL type

针对不同类型的 SQL，Navicat、SQL Developer 等数据库开发工具一般会给出不同的结果展示方式，例如 Navicat 对于 DML（INSERT、DELETE、UPDATE）类型语句会展示 Affected rows 影响行数，而对于 DDL、DQL 等仅提示 OK 执行成功，且展示 DQL 类型的查询结果。

ODC 对 SQL 类型的结果展示逻辑与 Navicat 基本相同，而解析类型的过程即被记作 Init SQL type 阶段，具体解析工作通过 OceanBase sql-parser 工具完成。

Init column comment 与 Init editable Info

在解析完 SQL 类型后，如果执行结果包含一个或多个表的列数据，则 ODC 会从字典视图 ALL_TAB_COLUMNS 中尝试获取相关列和表信息，并将其暂存在缓存中，以供接下来获取列注释和判断结果集是否可编辑。

若当前 SQL 涉及到对表或视图对象的查询，那么在展示时会显示列注释。而且，若当前 SQL 为单表查询，那么 ODC 能够允许用户对结果集进行编辑；若为多表查询，有且只有其中一张表的 ROWID 被指定，则指定 ROWID 的表的列可编辑，其余列不可。

Init warning message

OceanBase 数据库提供了字典视图 ALL_ERRORS，用于查看当前用户可访问的存储对象的错误。由于 SQL 窗口同样可以执行 PL，因此在执行结束后，ODC 将尝试查询 ALL_ERRORS 视图，通过对象名名称、Schema 名称和对象类型进行标识。若存在错误信息，则将其结构化处理后返回给用户。

至此，SQL 和结果集的后置处理也结束了，我们通过在执行记录界面中的 DB 耗时，查看上述各阶段的具体耗时。

OBServer 上的执行时间

SQL_AUDIT 视图

OceanBase 数据库将每一次 SQL 执行的来源、执行状态、详细耗时等信息存储在 GV$SQL_AUDIT 系统视图中，您可以通过该视图来查询 SQL 在 OBServer 端的耗时详情。

SQL_AUDIT 视图相关字段如下所示：

注：在 OceanBase 4.0 版本之后，GV $S Q L_{A} U D I T 命名更改为 G V$ OB_SQL_AUDIT 。该视图按照租户拆分，除了系统租户，其他租户不能跨租户查询。

SQL TRACE

此外， OceanBase 支持 Trace 功能，通过变量 OB_ENABLE_TRACE_LOG 控制。

开启该功能后，可以使用 SHOW TRACE 命令来快速获取最近一次 SQL 请求的完整日志。该命令获取的数据格式如下所示：

示例结果说明如下：

Title 列包含整个 SQL 执行经历的各个阶段的信息以及该 SQL 真实的执行路径。若结果中有经过 Resolve、Transform、Optimizer 和 Code Generate 四个流程，则说明该 SQL 重新生成了计划，没有命中 Plan Cache。
KeyValue 列包含一些执行信息，可以用于排查问题：

TRACE_ID 可以作为 SQL_AUDIT 视图中的过滤条件，快速找到该 SQL 执行信息，同时也可以通过该 TRACE_ID 快速查找相关的 OBServer 日志。
plan_id 可以用于在 v$plan_cache_plan_explain 中查看 Plan Cache 中缓存的具体执行计划。
phy_plan_type 指出该次执行计划的类型（1 表示本地计划/2 表示远程计划/3 表示分布式计划），可以辅助 SQL 诊断。

Time 列显示上一个阶段点到这次阶段点执行耗时。如果某个 SQL 执行很慢，则通过查看 TIME 列，能够快速定位出具体是哪个阶段执行较慢，然后再进行具体分析。假设执行耗时主要在生成计划过程中，则只需要分析没有命中 Plan Cache 的原因，可能是计划淘汰后第一次执行该 SQL，或是 Plan Cache 不支持的 SQL。

ODC 如何计算耗时

Jdbc 准备耗时

JDBC 驱动记录了执行请求发送和接收结果的时间节点，通过 api 来获取 JDBC 网络开销的时间，ODC 通过调用接口获取两个关键时间戳，将其作为计算耗时的数据来源。

Jdbc prepare 阶段耗时通过计算真实发送网络请求与调用执行方法之间的时间差得到。当 Server 端的查询结果较多时，会分多次网络通信返回数据，我们使用 Jdbc 记录第一个数据包接收的时间戳，用于后续计算 Network consumption 阶段的耗时。

实际执行耗时

在 SQL 执行完成后，ODC 会通过 SHOW TRACE 命令获取查询该条 SQL 在 OBServer 端的实际执行日志。通过分析计算该日志，可得到该次请求的 ELAPSED_TIME （接收到请求到执行结束消耗的总时间）和 EXECUTE_TIME （实际执行物理计划所消耗的时间）。

其中 EXECUTE_TIME 即为 OBServer Execute SQL 阶段耗时，且被展示为执行记录中做外层的 DB 耗时。解析、改写、获取执行计划等预处理操作的耗时为除 EXECUTE_TIME 之外时间之和，合并记作 OBServer wait 阶段。

网络耗时

虽然 GV$SQL_AUDIT 视图中记录了每条 SQL 执行请求的 REQUEST_TIME ，理论上可通过该时间戳与请求发送之间的时间差获取到网络延时。但实际上由于该字段取自 OBServer 本地服务器时钟，而不同服务器间的·，时钟存在时间差异，因此难以单独计算请求发送或接收的耗时。

ODC 将接收到第一个回包的时间节点与请求发送的时间节点之间的差值作为请求往返时间，并减去上一步获取到的 ELAPSED_TIME 即 OBServer 端总耗时，从而获取到请求发送与接收的总网络耗时，记作 Network consumption 阶段。

ODC 执行耗时展示

在 ODC 中，我们可以通过“执行记录”界面的 “DB 耗时”功能查看 SQL 执行各个阶段的耗时，进而定位问题所在。ODC 在 4.1.0 版本，将每个阶段的执行耗时时间单位进行了自适应处理，保留小数点后两位，且对 SQL 执行阶段的耗时也做了进一步的细化展示，以方便用户更清晰的了解 SQL 耗时详情。

文中的例子是在 OB-Oracle 模式下运行，OB-MySQL 模式与之相比，不会对 SQL 进行解析与改写，而是直接交由驱动和 OBServer 执行，其余阶段基本相同，因此不再赘述。

总结

SQL 的一生很长，本文仅仅是简要描述了其被 ODC 执行时，各个生命周期中的主要工作以及耗时是如何得到的，对 SQL 在 OceanBase Server 端内部的执行过程也仅是粗略介绍。

后续的文章中将会带大家了解 ODC 的权限管理模型，敬请期待。