在分布式数据库环境下,慢 SQL 诊断是运维人员面临的一大挑战。在无法及时发现问题根本原因的情况下,可能会严重影响用户体验,甚至会导致业务服务不可用。相对于单机数据库,分布式数据库系统涉及多个节点、多组件的协同工作,集群规模可能扩展至几十甚至上百台服务器,用户请求链路因此变得更为复杂,使得快速、高效的问题诊断与定位变得更加具有挑战性。
OceanBase 4.2 LTS 在诊断能力方面取得了显著的进展,新版本首次引入了 SQL 请求的可视化全链路追踪功能(Show Trace),协助用户迅速追踪并定位问题发生的具体执行阶段、哪台机器以及哪个模块,并提供详实的相关执行信息,为用户提供更简单、更高效的运维体验。
(一)事务 + SQL 维度的 Show Trace
OceanBase 提供了面向用户的事务 + SQL 维度的 Show Trace 能力。通常,业务部门更关心一笔业务的服务总耗时。在 OLTP 系统中,一笔业务服务一般由一个或多个事务组成,因此,把事务作为追踪单位会更贴合用户的实际业务。每个事务形成一个Trace,并对事务中每条 SQL 请求记录从 OBClient 到 OBProxy 再到 OBServer 的全链路执行信息。用户可以通过一个 Trace 快速找到该事务执行了哪些语句,以及这些语句从客户端视角看到的执行情况。
在实际业务中,当用户发现慢 SQL 请求或某个事务存在性能问题时,可以通过慢 SQL 整个执行链路快速定位具体执行阶段的性能瓶颈。另外,在某个事务中,如果发现一个 SQL 结束到另一个 SQL 再发起之间的时间较长,可协助业务同学查看可能存在的业务逻辑问题。
图1 事务中SQL调用过程图
(二)支持分布式环境下的 Show Trace
OceanBase 提供了针对分布式环境的 Show Trace 能力。作为一个分布式系统,当 OBProxy 接收到客户端请求时,可能会将其路由到 OBServer 集群中的任一台 OBServer 上。同时,该请求涉及的数据可能分布在不同的 OBServer 中。具体到 SQL 执行阶段,执行引擎会向不同的 OBServer 发送执行子任务。在 OBServer 数量较多的情况下,如何确定这些 SQL 请求和 Task 到底在哪个 Server 上执行,以及 Server 内各模块的执行耗时情况,都是运维人员面临的挑战。
Show Trace 实现了对 SQL 请求在分布式场景下的完整执行链路进行追踪。用户能够直观地了解哪个 OBServer 上接收了请求,哪个 OBServer 上执行了远程任务,每个任务的调度情况,以及执行的耗时等详细信息。这为运维人员提供了有力的工具,帮助他们更好地理解和优化分布式环境下的 SQL 执行过程。
图2 分布式请求执行过程图
(三)提供便捷的业务系统关联能力
在实际业务中,用户往往需要建立自己的监控和诊断系统,以便快速发现和定位数据库问题。当数据库请求调用慢或报错时,用户可能需要系统快速关联到数据库对应的某个 SQL 诊断,以缩短从发现问题到解决问题的耗时。Show Trace 提供了便捷的业务系统关联能力,可以帮助用户快速定位数据库问题。用户可以通过 JDBC 接口或 SQL 接口,在业务数据库连接上设置调用请求对应的 app trace id。该 app trace id 会记录到 OceanBase 全链路追踪的信息中,并在 Show Trace 中展示出来。
当用户发现某个 app trace id 对应的请求或服务数据库调用有报错时,可以使用该 app trace id 在全链路诊断系统中快速搜索到对应的 app trace id 关联的数据库 Trace。然后,用户可以直接查看该请求在数据库链路中各阶段的耗时情况及报错点,快速确定触发问题的组件。
(四)灵活的 Show Trace 信息展示方式
用户通过 OCP,可以通过不同维度快速检索到有问题的请求,比如按耗时检索, 按指定 Trace id 或者 SQL ID 检索等, 并且直观的看到请求从客户端到数据库内部全链路各组件的执行信息, 方便快速定位出问题的阶段。
OCP 为用户提供了一个可视化界面,可以帮助用户快速检索有问题的请求。用户可以根据不同的维度进行检索,例如按耗时、Trace ID 或 SQL ID 等。OCP 还可以直观地展示请求从客户端到数据库内部全链路各组件的执行信息,方便用户快速定位问题的阶段。
图3 OCP平台展示效果图
此外,用户还可以通过 ODC 查看 Show Trace 信息,用户可以在执行语句后详细地看到本次请求执行的状态。借助该功能,用户可以直观地看到请求从客户端到数据库内部的执行情况,快速看到当前的瓶颈点在何处。
图4 ODC效果展示图
最后,用户可以在 OceanBase 新版本的交互场景使用 Show Trace 能力,用户在命令行中手动执行某一个语句后,如果想分析该语句的执行调用链路情况,以及链路中各阶段耗时情况,以便进行性能分析或调优,可以使用 Show Trace 功能便捷地找到性能瓶颈点。如图 5 所示,我们可以通过直接使用 Show Trace 命令,看到两个分布式并行执行任务(px_task) 的执行情况。另一方面,也可以通过 Show Trace 的 JSON 展示版来显示更多明细信息。获取到明细信息后,用 OBDiag 工具展示 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 | 2024-01-12 10:51:30.143537 | 4.667 ms |
| └─ ob_proxy | 2024-01-12 10:51:30.143716 | 4.301 ms |
| └─ com_query_process | 2024-01-12 10:51:30.145119 | 2.527 ms |
| └─ mpquery_single_stmt | 2024-01-12 10:51:30.145123 | 2.513 ms |
| ├─ sql_compile | 2024-01-12 10:51:30.145133 | 0.107 ms |
| │ └─ pc_get_plan | 2024-01-12 10:51:30.145135 | 0.061 ms |
| └─ sql_execute | 2024-01-12 10:51:30.145252 | 2.350 ms |
| ├─ open | 2024-01-12 10:51:30.145252 | 0.073 ms |
| ├─ response_result | 2024-01-12 10:51:30.145339 | 2.186 ms |
| │ ├─ px_schedule | 2024-01-12 10:51:30.145342 | 1.245 ms |
| │ │ ├─ px_task | 2024-01-12 10:51:30.146391 | 1.113 ms |
| │ │ │ ├─ get_das_id | 2024-01-12 10:51:30.146979 | 0.001 ms |
| │ │ │ ├─ do_local_das_task | 2024-01-12 10:51:30.147012 | 0.050 ms |
| │ │ │ └─ close_das_task | 2024-01-12 10:51:30.147237 | 0.014 ms |
| │ │ └─ px_task | 2024-01-12 10:51:30.146399 | 0.868 ms |
| │ │ ├─ get_das_id | 2024-01-12 10:51:30.147002 | 0.001 ms |
| │ │ ├─ do_local_das_task | 2024-01-12 10:51:30.147036 | 0.041 ms |
| │ │ └─ close_das_task | 2024-01-12 10:51:30.147183 | 0.011 ms |
| │ └─ px_schedule | 2024-01-12 10:51:30.147437 | 0.001 ms |
| └─ close | 2024-01-12 10:51:30.147536 | 0.049 ms |
| └─ end_transaction | 2024-01-12 10:51:30.147571 | 0.002 ms |
+-------------------------------------------+----------------------------+------------+
图 5 Show Trace交互式展示效果
OceanBase 4.x 版本提供了全链路追踪能力,这极大地方便了运维人员对慢 SQL 的定位。运维人员现在可以有两种方式来使用 Show Trace:
方式一:简略信息跟踪
用户如果发现业务请求变慢,可以重新运行一次该 SQL,然后使用 Show Trace 命令,将其 span 打印出来。如图 5 所示,用户可以看到该 SQL 的耗时、执行阶段、各阶段耗时等信息。
方式二:详细信息跟踪
对于一些复杂的问题,单靠查看 span 的状态是定位不出问题所在的。因此,运维人员可以使用 Show Trace 命令来展示该 Query 的详细执行信息,例如:
OceanBase(SYS@SYS)>select * from t where c1=1;
Empty set (0.001 sec)
OceanBase(SYS@SYS)>show trace format='json'\G
*************************** 1. row ***************************
SHOW_TRACE_JSON: [{"logs":null,"tags":[{"sess_id":3221487638},{"action_name":""},{"module_name":""},{"client_info":""},{"receive_ts":1682407095822071},{"log_trace_id":"YA9257F000001-0005FA206441ADD9-0-0"}],"elapse":419,"end_ts":"2024-01-12 10:18:15.822547","parent":"0005fa23-ed50-66bb-9e0a-700e959f21ff","span_id":"0005fa23-ed50-6730-0748-1e63c6a2a636","start_ts":"2024-01-12 10:18:15.822128","trace_id":"0005fa23-ed50-66bb-caca-b2a1132f8eae","span_name":"com_query_process","tenant_id":1002,"rec_svr_ip":"127.0.0.1","rec_svr_port":43301},{"logs":null,"tags":null,"elapse":396,"end_ts":"2024-01-12 10:18:15.822532","parent":"0005fa23-ed50-6730-0748-1e63c6a2a636","span_id":"0005fa23-ed50-6738-75c5-5292251b8159","start_ts":"2024-01-12 10:18:15.822136","trace_id":"0005fa23-ed50-66bb-caca-b2a1132f8eae","span_name":"mpquery_single_stmt","tenant_id":1002,"rec_svr_ip":"127.0.0.1","rec_svr_port":43301},{"logs":null,"tags":[{"sql_text":"select * from t where c1=1"},{"sql_id":"A07D4B0B800C20F31180D2E0F3F73BFE"},{"database_id":201006},{"plan_hash":288002381100833637},{"hit_plan":true}],"elapse":112,"end_ts":"2024-01-12 10:18:15.822261","parent":"0005fa23-ed50-6738-75c5-5292251b8159","span_id":"0005fa23-ed50-6745-22f3-e1a1a5ee9745","start_ts":"2024-01-12 10:18:15.822149","trace_id":"0005fa23-ed50-66bb-caca-b2a1132f8eae","span_name":"sql_compile","tenant_id":1002,"rec_svr_ip":"127.0.0.1","rec_svr_port":43301},{"logs":null,"tags":null,"elapse":45,"end_ts":"2024-01-12 10:18:15.822197","parent":"0005fa23-ed50-6745-22f3-e1a1a5ee9745","span_id":"0005fa23-ed50-6748-4017-1c4d2fbacb63","start_ts":"2024-01-12 10:18:15.822152","trace_id":"0005fa23-ed50-66bb-caca-b2a1132f8eae","span_name":"pc_get_plan","tenant_id":1002,"rec_svr_ip":"127.0.0.1","rec_svr_port":43301},{"logs":null,"tags":null,"elapse":213,"end_ts":"2024-01-12 10:18:15.822490","parent":"0005fa23-ed50-6738-75c5-5292251b8159","span_id":"0005fa23-ed50-67c5-73cc-f89ef6db2fd9","start_ts":"2024-01-12 10:18:15.822277","trace_id":"0005fa23-ed50-66bb-caca-b2a1132f8eae","span_name":"sql_execute","tenant_id":1002,"rec_svr_ip":"127.0.0.1","rec_svr_port":43301},{"logs":null,"tags":null,"elapse":26,"end_ts":"2024-01-12 10:18:15.822303","parent":"0005fa23-ed50-67c5-73cc-f89ef6db2fd9","span_id":"0005fa23-ed50-67c5-cfcb-14906e4d8a27","start_ts":"2024-01-12 10:18:15.822277","trace_id":"0005fa23-ed50-66bb-caca-b2a1132f8eae","span_name":"open","tenant_id":1002,"rec_svr_ip":"127.0.0.1","rec_svr_port":43301},{"logs":null,"tags":null,"elapse":103,"end_ts":"2024-01-12 10:18:15.822420","parent":"0005fa23-ed50-67c5-73cc-f89ef6db2fd9","span_id":"0005fa23-ed50-67ed-720e-a5cda0d41ebe","start_ts":"2024-01-12 10:18:15.822317","trace_id":"0005fa23-ed50-66bb-caca-b2a1132f8eae","span_name":"response_result","tenant_id":1002,"rec_svr_ip":"127.0.0.1","rec_svr_port":43301},{"logs":null,"tags":null,"elapse":48,"end_ts":"2024-01-12 10:18:15.822373","parent":"0005fa23-ed50-67ed-720e-a5cda0d41ebe","span_id":"0005fa23-ed50-67f5-3e19-76474bad2e23","start_ts":"2024-01-12 10:18:15.822325","trace_id":"0005fa23-ed50-66bb-caca-b2a1132f8eae","span_name":"do_local_das_task","tenant_id":1002,"rec_svr_ip":"127.0.0.1","rec_svr_port":43301},{"logs":null,"tags":null,"elapse":45,"end_ts":"2024-01-12 10:18:15.822478","parent":"0005fa23-ed50-67c5-73cc-f89ef6db2fd9","span_id":"0005fa23-ed50-6861-929b-21bacd1577b8","start_ts":"2024-01-12 10:18:15.822433","trace_id":"0005fa23-ed50-66bb-caca-b2a1132f8eae","span_name":"close","tenant_id":1002,"rec_svr_ip":"127.0.0.1","rec_svr_port":43301},{"logs":null,"tags":null,"elapse":9,"end_ts":"2024-01-12 10:18:15.822443","parent":"0005fa23-ed50-6861-929b-21bacd1577b8","span_id":"0005fa23-ed50-6862-3659-7b0b257c849c","start_ts":"2024-01-12 10:18:15.822434","trace_id":"0005fa23-ed50-66bb-caca-b2a1132f8eae","span_name":"close_das_task","tenant_id":1002,"rec_svr_ip":"127.0.0.1","rec_svr_port":43301},{"logs":null,"tags":[{"trans_id":0}],"elapse":3,"end_ts":"2024-01-12 10:18:15.822464","parent":"0005fa23-ed50-6861-929b-21bacd1577b8","span_id":"0005fa23-ed50-687d-e820-9144206234b6","start_ts":"2024-01-12 10:18:15.822461","trace_id":"0005fa23-ed50-66bb-caca-b2a1132f8eae","span_name":"end_transaction","tenant_id":1002,"rec_svr_ip":"127.0.0.1","rec_svr_port":43301}]
确定了耗时高的请求后,我们需要进一步诊断具体是哪里出了问题。此时,用户可以使用 OCP 中的 trace visualizer,将得到的 JSON 数据导入其中,即可展示出每个部分的详细耗时,如图 6 所示。
图6 Show trace信息详细版展示
Q1: Show Trace 和全链路诊断在机制上有哪些异同点,Trace 数据保存在哪里?
A:Show Trace 和全链路诊断在 Trace 诊断信息的组织方式上是一致的,都是将每个诊断信息作为一个 span,标明当前 span ID 和 parent span ID,然后以树的形式组织起来。但在数据存储方式上存在差异:Show Trace 的数据完全存储在内存中,是即时的,只会保存最近的诊断信息;而全链路的数据存储在磁盘中,是历史的,会保存执行过的信息。
Q2: 没有 Proxy 的时候,OCP 里能不能用 Show Trace 功能?
A:Proxy 不是使用 Show Trace 能力的必要条件。是否存在 Proxy,在 Show Trace 上显示的差异主要在:如果 Proxy 存在,那么 Show Trace 的树状结构就会有 Proxy 的信息;如果不存在,那么 Show Trace 的树状结构就不会有 Proxy 的信息。
Q3: 如何在 OCP 中找到 Show Trace 功能?
A:根据指定 Trace id 或者 SQL ID 检索,然后查看链路详情,即可看到 Show Trace 功能。
Q4: OBClient/OBjdbc/OBProxy 的版本有没有要求?要什么版本?
A:OBClient 2.2.0 及以上版本,OBjdbc 2.4.0 及以上版本,OBProxy 4.x 以上版本。
Show Trace 是生产场景中常用的分析数据库性能的重要利器,可以帮助用户快速定位查询性能瓶颈。本文介绍了 OceanBase 4.2 新增的 Show Trace 能力特性,从语法使用、使用场景等角度来详细解析了该特性的使用方法,并分享了底层实现原理和一些使用场景。希望本文能够帮助大家更好地理解和使用 Show Trace 特性,提升数据库性能诊断效率。
Show Trace 全链路诊断标志着易用性一个重要的起点,我们深知易用性对于数据库用户至关重要。一款备受欢迎的数据库基础软件离不开对易用性的精心打磨,更离不开用户的认可与反馈。我们期待大家提出宝贵的意见和反馈,希望与更多用户一起努力,共同打造一款更好用、更易用的一体化数据库。