作者简介：肖意，OceanBase高级技术专家。曾多次参加蚂蚁双十一大促支持工作，是TPC-C、TPC-H性能攻坚项目组核心成员，主要负责SQL引擎相关研发，包括链路协议、执行计划管理、执行引擎等方向的设计与开发工作。
在上一篇 4.0 解读文章中，我们回顾了单机到分布式跨越给数据库 DDL 带来的挑战，并介绍了 OceanBase 的应对策略及设计思路，以便为用户提供更高效、更透明的运维体验。本篇将继续数据库运维的话题，展开对故障追踪与定位能力的讨论。
首先让我们看下这样一个场景:
业务部门：数据库请求好慢，可以看看哪里出问题了吗？
DBA：【DBA 查看数据库节点实时监控】我在数据库节点的实时监控并未发现很慢的 SQL。
业务部门：那是怎么回事？
DBA：可能是客户端到数据库节点这一链路有问题，我来看一下中间代理服务器的日志。
DBA：【DBA 开始查询日志，1 hour later……】从代理服务器日志看耗时也是正常的。可能是客户端到代理服务器的网络问题？
该场景描述的是分布式数据库下运维遇到慢 SQL 时的场景，如果运维无法及时找出问题原因，就会非常影响使用体验，甚至导致业务服务不可用。因此，如何提供简单、高效的诊断能力，一直是我们思考的问题。相比单机数据库，分布式数据库系统涉及多个节点、多组件协同工作，集群规模可能达到几十、上百台服务器，用户请求链路会更加复杂，要实现快速高效地问题诊断与定位也会更有挑战。
OceanBase 4.0 在诊断能力方面有了显著提升，其中包括首次实现对 SQL 请求的可视化全链路追踪，能够帮助用户快速追踪并定位具体问题发生在哪个执行阶段、哪台机器以及哪个模块，并提供具体的相关执行信息，为用户提供简单、高效的运维体验。本文将分享我们对数据库高效诊断的思考，介绍 OceanBase全链路追踪能力及设计思路。
- 全链路追踪要解决什么问题；
- 全链路追踪的关键能力有哪些；
- 我们如何设计全链路追踪；
- 4.0 全链路追踪效果展示。
全链路跟踪要解决什么问题？
在 OceanBase 中，当用户发起一个请求后，首先会被发送给 OBProxy（SQL请求代理），由 OBProxy 路由转发到 OceanBase 集群，进入集群中的某一个 OBServer 节点，随后会经过 SQL 引擎、存储引擎、事务引擎等（不同的请求会涉及不同引擎中的诸多处理模块），该请求也有可能通过 rpc 任务访问多个 OBServer 节点的数据，最终将结果返回给客户端。
图1 OceanBase SQL请求执行过程示意图
当用户请求出现报错或者执行慢的问题时, 可能是请求执行过程中的某个组件问题，也可能是不同组件节点间的网络等问题。在 4.0 之前的版本中，OceanBase 已经为用户提供了较为完善的监控和诊断能力，包括 SysStat、Sql Audit、Trans Stat、Tenant Dump、Slow Trans、Slow Query 等，OceanBase 运维平台（OCP）根据上述监控输出的信息实现了白屏化监控和诊断，包括事务诊断、TopSQL 诊断、SlowSQL 诊断等。但这些诊断能力缺乏请求全链路视角的信息, 导致往往定位问题发生在哪个执行阶段、哪个机器以及哪个模块就花费了很多时间；有时甚至需要各组件专家一起参与排查才能定位，影响运维人员对问题快速诊断和恢复的效率。
为进一步提高分布式场景下用户请求问题诊断效率, OceanBase 实现了全链路追踪机制, 能够追踪用户 SQL 请求在数据库全链路过程中，在不同阶段、不同组件执行的相关信息，并以可视化方式展现给用户，从而帮助用户快速定位问题所在位置。
全链路追踪的关键能力
▋ 事务 + SQL 维度的全链路追踪
OceanBase 提供了面向用户的事务 + SQL 维度的全链路追踪能力。对于业务部门而言，更关心的往往是一笔业务服务总的耗时情况。例如在 OLTP 系统中，一笔业务服务一般由一个或多个事务组成。因此，我们把事务作为追踪单位会更贴合用户的实际业务，一个事务形成一个追踪的 Trace，并对事务中每条 SQL 请求记录 OBClient -> OBProxy -> OBServer 内部全链路过程中相关执行信息，用户可以通过一个 Trace 快速找到该事务执行了哪些语句，以及这些语句从客户端视角看到的执行情况。
在实际业务中，一旦用户发现有慢的 SQL 请求，或者存在某个慢的事务，可以从慢 SQL 的整个执行链路中快速定位是哪个执行阶段慢。又或者在某个事务中，如果发现一个 SQL 结束到另一个 SQL 再发起之间的时间较长，则可请业务同学查看业务逻辑侧可能存在的问题。
图2 事务中SQL调用过程图
▋ 支持分布式环境下的全链路追踪
OceanBase 支持分布式环境下的全链路追踪能力。首先，OceanBase 作为一个分布式系统，当 OBProxy 接收到一个客户端请求后，有可能会将其路由到 OBServer 集群中任意一台 OBbServer 上。同时，该请求涉及到的数据可能分布在不同的 OBServer 中。具体到 SQL 执行阶段，执行引擎会向不同的 OBServer 发送执行子任务 task，当 OBServer 数量很多时，这些 SQL 请求和 Task 具体是在哪个 Server上执行？Server 内具体各模块执行的耗时情况是怎样的？都会困扰运维人员。
全链路追踪机制实现了 SQL 请求在分布式场景下，涉及多 Server 时完整执行链路的追踪。用户能够直观地看到是哪个 OBServer 上接收请求，哪个 OBServer 上执行远程 task，每个 task 的调度情况，以及执行耗时等信息。
图3 分布式请求执行过程图
▋ 提供便捷的业务系统关联能力
在实际业务中，不少用户都会建立自己的监控及诊断系统。当数据库发生请求调用慢或报错时，用户可能需要系统快速关联到数据库对应的某个 SQL 诊断，进一步缩短从发现问题到解决问题的耗时。全链路追踪机制可以为用户提供便捷的业务系统关联能力，用户通过 JDBC 接口/SQL 接口，能够在业务数据库连接上设置调用请求对应的 app trace id, 该 app trace id 会记录到 OceanBase 全链路追踪对应的信息中。
当用户发现某个 app trace id 对应的请求或服务数据库调用有报错时, 可以使用该 app trace id 在全链路诊断系统中快速搜索到对应的 app trace id 关联的数据库 Trace，然后直接查看该请求在数据库链路中各阶段耗时情况及报错点，快速确定触发问题的组件。
▋ 多种全链路信息展示方式
用户通过 OceanBase 运维平台（OCP），可以通过不同维度快速检索到有问题的请求，比如按耗时检索, 按指定 Trace id 或者 SQL ID 检索等，并且直观地看到请求从客户端到数据库内部全链路各组件的执行信息, 方便快速定位出问题的阶段。
图4 OCP平台展示效果图
此外，用户可以在 OceanBase 新版本的交互场景使用全链路诊断能力。用户在命令行中手动执行某一个语句后，如果想分析该语句的执行调用链路情况，以及链路中各阶段耗时情况，以便进行性能分析或调优，可以使用 show Trace 功能便捷地找到性能瓶颈点。如下所示，我们可以看到两个分布式并行执行任务(px_task) 的执行情况，如果想看更多明细，也可以通过 show Trace 其他不同命令展现出来。
OceanBase(admin@test)>select/*+parallel(2)*/ count(*) from t1;+----------+| count(*) |+----------+| 5 |+----------+1 row in set (0.005 sec)OceanBase(admin@test)>show trace;+-------------------------------------------+----------------------------+------------+| Operation | StartTime | ElapseTime |+-------------------------------------------+----------------------------+------------+| obclient | 2023-03-01 17:51:30.143537 | 4.667 ms || └─ ob_proxy | 2023-03-01 17:51:30.143716 | 4.301 ms || └─ com_query_process | 2023-03-01 17:51:30.145119 | 2.527 ms || └─ mpquery_single_stmt | 2023-03-01 17:51:30.145123 | 2.513 ms || ├─ sql_compile | 2023-03-01 17:51:30.145133 | 0.107 ms || │ └─ pc_get_plan | 2023-03-01 17:51:30.145135 | 0.061 ms || └─ sql_execute | 2023-03-01 17:51:30.145252 | 2.350 ms || ├─ open | 2023-03-01 17:51:30.145252 | 0.073 ms || ├─ response_result | 2023-03-01 17:51:30.145339 | 2.186 ms || │ ├─ px_schedule | 2023-03-01 17:51:30.145342 | 1.245 ms || │ │ ├─ px_task | 2023-03-01 17:51:30.146391 | 1.113 ms || │ │ │ ├─ get_das_id | 2023-03-01 17:51:30.146979 | 0.001 ms || │ │ │ ├─ do_local_das_task | 2023-03-01 17:51:30.147012 | 0.050 ms || │ │ │ └─ close_das_task | 2023-03-01 17:51:30.147237 | 0.014 ms || │ │ └─ px_task | 2023-03-01 17:51:30.146399 | 0.868 ms || │ │ ├─ get_das_id | 2023-03-01 17:51:30.147002 | 0.001 ms || │ │ ├─ do_local_das_task | 2023-03-01 17:51:30.147036 | 0.041 ms || │ │ └─ close_das_task | 2023-03-01 17:51:30.147183 | 0.011 ms || │ └─ px_schedule | 2023-03-01 17:51:30.147437 | 0.001 ms || └─ close | 2023-03-01 17:51:30.147536 | 0.049 ms || └─ end_transaction | 2023-03-01 17:51:30.147571 | 0.002 ms |+-------------------------------------------+------------------------
▋ 建立从定位到诊断的一站式体验
我们已经知道，用户可以借助全链路追踪能力快速定位出故障发生的组件或模块。如果具体讨论某个比较小的模块呢？此时用户就可以关联各模块对应的其他诊断机制进行问题定位。
举例来说，我们通过全链路追踪定位到是 SQL 执行引擎慢，则可以通过 SQL 请求的 sql_trace_id 关联，自动跳转到 SQL Plan Monitor 诊断机制，查看执行计划各线程各算子执行情况。如图 5 所示，可以看到每个算子执行 CPU 时间（DBTime 绿色）、等待时间（DBTime 红色）、算子返回行数等信息。
图5 SQL Plan Monitor展示执行信息图
我们如何设计全链路追踪
如下图所示，可以看到 OceanBase 全链路追踪能力实现涉及的主要板块。我们记录 Trace 信息使用的数据模型是 OpenTracing 的模型，具体到实现则主要分 2 个部分：Trace 数据生成以及 OCP 分析展示集成，下文将展开详细介绍。
图6 OceanBase全链路追踪实现示意图
▋ 数据模型
OceanBase 全链路追踪记录数据使用 OpenTracing 模型，该数据模型在分布式追踪系统中被大量使用，下图中左边是 OpenTracing 数据模型，右图是对应 OceanBase 全链路追踪的记录模型，一个 Trace 对应于一个数据库的事务，每个 Trace 会对应多个 Span，比如一个 SQL 请求是一个 Span，Span 中会记录某个过程执行相关信息，每个 Span 会记录一条日志持久化到 Trace 文件中。
图7 全链路追踪数据模型
▋ Trace数据生成
生成完整有效的 Trace 数据，是全链路追踪能力的关键。请求全链路涉及的各个组件，哪些阶段需要单独记录 Span，以及记录哪些关键有用信息，我们都会仔细斟酌，确保全链路信息准确有用，另一方面，生成 Trace 数据的性能损耗，我们也需要重点考虑，这块开销主要分两部分， 一部分是 Trace 数据记录到内存开销，另一部分是将 Trace 数据写入到 Trace 文件的开销，为了尽量不影响性能，同时为用户提供更多有用的全链路诊断信息, 我们提供了多种控制策略，为不同用户链接可以设置不同 Trace 级采样频率，记录完整 Trace 信息，同时也会将用户更关注的慢 SQL 及报错的 SQL 对应的 Trace 信息 100% 打印到 Trace 日志中。
图8 各组件trace日志生成示意图
Trace 文件会独立记录到 OBProxy 和 OBServer 不同进程所在机器，考虑到数据库客户端使用是在业务服务端，OceanBase 数据库 OBClient 端的全链路 Trace 信息并没有记录到业务服务器上，而是传输到 OBProxy 记录。
▋ OCP平台分析与展示集成
OCP 平台中，实现了链路 Trace 信息的页面搜索及展示能力，它可以根据用户设定的条件，搜索某个请求涉及的 Trace 信息，让用户直观地查看整个链路的详细信息。而这些数据的来源, 主要来自 OBProxy 和 OBServer 不同服务器上的Trace日志, OCP 后台会有专门的采集工具, 对这些 Trace 日志进行采集, 并解析，最后存储到ES中。 但这些采集数据是原始的 Span 数据，同一个 Trace 的数据可能分散在不同机器的不同 Span 中，要实现按一个 Trace 中不同的 Span 上的 Tag 作为条件来搜索会较困难。因此，OCP Server 会定时把 Trace 的关键 Span 数据（如不同阶段的耗时、重要 Tag）合在一条数据中，构造每条 Trace 的概要。从而实现让用户按不同的条件组合高效地查询 Trace 信息，用于页面展示。
OceanBase 4.0全链路追踪效果展示
回到文章开头的慢 SQL 问题，在 4.0 提供了全链路追踪能力后，运维人员的操作会有什么变化呢？
现在，用户如果发现业务请求变慢，可以在 OCP 的全链路搜索页面中依据耗时对 SQL 进行排序，找到某个时间段内耗时高的请求，检查是否有执行时间不符合预期的 SQL。如果通过 TopSQL 诊断已经确定是某个 SQL 耗时高，或者获取到有关联用户的 app trace id，也可以作为查找过滤条件，进一步减少查找范围。
图9 OCP全链路追踪搜索
当确定耗时高的请求后，接下来我们需要诊断具体是哪里出了问题。此时，用户可以在 OCP 中直接点击有问题的 Trace id，展开请求的 Trace 信息（如图 10 所示）。可以看到，从客户端视角看，该请求总共耗时是 4.47ms，OBProxy 视角总耗时 4.366ms，OBServer 中耗时是 3.246ms，主要耗时在 OBServer 端，进一步看，可以看到主要耗时在 SQL compile 阶段, 也就是 SQL 生成执行计划阶段。此时，我们便可以得出初步结论：这条 SQL 执行慢耗时高，是它没有命中执行计划导致的。
图10 OCP全链路信息展示
在 OCP 的全链路详情中，可以看到相应 SQL 请求调用个模块的路径，并可以详细看到各阶段的耗时。举例来说，当用户要了解客户端发起请求到 OBProxy 接收请求这个阶段的具体耗时，从时间轴上看到 OBClient 和 OBProxy 间的网络耗时并不是主要耗时。如果用户想进一步了解该阶段耗时具体信息，可以分别点击对应 OBClient 发送请求的 Span 和 OBProxy 接收请求的 Span，如图 11 所示，可以快速看到两者开始时间差为 187 us，也就是这个从客户端发送请求到 OBProxy 接收请求的耗时，这样可以帮助我们更加细化地分析问题。
图11 全链路追踪阶段信息展示
写在最后
OceanBase 4.0 的全链路追踪能力实现了对每个事务、每条 SQL 请求的可观测性，提供了高效的问题诊断和定位能力。我们相信这一新能力将帮助用户更加快速地定位问题并解决问题, 从而带来更简单、更高效地数据库运维体验。作为改善 OceanBase 易用性的重要一环，我们也将在未来的 4.x 中着力提升运维体验，新增包括 ASH（Active Session History）、Realtime SQL Plan Monitor、Logical Plan Manager 等在内的更多功能。最后，欢迎大家在评论区留言，一起探讨对数据库问题诊断的看法。
