暂无图片
暂无图片
暂无图片
暂无图片
暂无图片

OceanBase 全链路追踪中的故障排查与性能优化 | OceanBase最佳实践 13

原创 OceanBase数据库 2025-01-24
416

在分布式数据库环境中,链路复杂性和性能问题往往成为主要挑战。面对复杂的架构,问题排查和性能优化显得尤为重要。本文将重点探讨如何通过 OceanBase 的全链路追踪技术,快速定位问题并实施有效的优化措施。


全链路顾名思义就是从业务生成 SQL 到 SQL 从数据库执行完返回客户端一整套下来的链路。在分布式架构下,链路较长,问题的分析处理也变得复杂。


在 OceanBase 4.0 之前,可以使用业务 SQL 请求的 trace_id 进行追踪,但是 OBProxy 和 OBServer 记录的不是应用或 SQL 设置的 trace_id,而是各自的内部 trace_id,还需要使用 SQL 语句的特征(比如,主键或者唯一键的值)进行辅助定位。

一、4.x 版本全链路追踪介绍

OceanBase 4.x 版本新增全链路追踪 trace,运维人员通过对所有 trace 日志进行搜集分析后,可以追踪每个事务或每个 SQL 在整条链路中的执行耗时等相关信息,以此帮助运维人员定位整条访问链路的问题所在。更多信息可以通过以下链接或二维码,查看《全链路追踪》。


https://www.oceanbase.com/docs/common-oceanbase-database-cn-1000000001499852

🚩  4.x 版本使用全链路追踪定位问题示例

在进行 SQL 查询时,发现执行语句的时间过长,通过全链路追踪,来分析对应的原因。


1、开启 Show Trace 功能。

obclient [testdb]> set ob_enable_show_trace = 'on';


2、执行以下查询语句。

obclient [testdb]> select * from tp1 where c1 = 938599;

返回结果如下:

+--------+--------+| c1     | c2     |+--------+--------+| 938599 | 518633 |+--------+--------+1 row in set (0.481 sec)


3、通过 Show Trace 语句查看该语句的执行调用链路情况以及链路中各阶段的耗时情况。

obclient [testdb]> Show Trace;

返回结果如下:

+-----------------------------------------------------------+----------------------------+------------+| Operation                                                 | StartTime                  | ElapseTime |+-----------------------------------------------------------+----------------------------+------------+| obclient                                                  | 2023-11-05 19:02:40.723072 | 481.285 ms || └── com_query_process                                     | 2023-11-05 19:02:40.723219 | 481.069 ms ||     └── mpquery_single_stmt                               | 2023-11-05 19:02:40.723225 | 481.057 ms ||         ├── sql_compile                                   | 2023-11-05 19:02:40.723233 | 2.904 ms   ||         │   ├── pc_get_plan                               | 2023-11-05 19:02:40.723236 | 0.008 ms   ||         │   └── hard_parse                                | 2023-11-05 19:02:40.723269 | 2.861 ms   ||         │       ├── parse                                 | 2023-11-05 19:02:40.723269 | 0.054 ms   ||         │       ├── resolve                               | 2023-11-05 19:02:40.723338 | 0.187 ms   ||         │       ├── rewrite                               | 2023-11-05 19:02:40.723556 | 0.342 ms   ||         │       ├── optimize                              | 2023-11-05 19:02:40.723906 | 2.015 ms   ||         │       │   ├── inner_execute_read                | 2023-11-05 19:02:40.724391 | 0.126 ms   ||         │       │   │   ├── sql_compile                   | 2023-11-05 19:02:40.724400 | 0.043 ms   ||         │       │   │   │   └── pc_get_plan               | 2023-11-05 19:02:40.724402 | 0.023 ms   ||         │       │   │   ├── open                          | 2023-11-05 19:02:40.724450 | 0.018 ms   ||         │       │   │   └── do_local_das_task             | 2023-11-05 19:02:40.724485 | 0.016 ms   ||         │       │   └── close                             | 2023-11-05 19:02:40.724525 | 0.023 ms   ||         │       │       ├── close_das_task                | 2023-11-05 19:02:40.724526 | 0.005 ms   ||                 │       └── end_transaction               | 2023-11-05 19:02:40.724539 | 0.003 ms   ||         │       ├── code_generate                         | 2023-11-05 19:02:40.725930 | 0.092 ms   ||         │       └── pc_add_plan                           | 2023-11-05 19:02:40.726091 | 0.033 ms   ||         └── sql_execute                                   | 2023-11-05 19:02:40.726143 | 478.105 ms ||             ├── open                                      | 2023-11-05 19:02:40.726143 | 0.012 ms   ||             ├── response_result                           | 2023-11-05 19:02:40.726160 | 477.975 ms ||             │   └── do_local_das_task                     | 2023-11-05 19:02:40.726165 | 0.078 ms   ||             └── close                                     | 2023-11-05 19:02:41.204164 | 0.076 ms   ||                 ├── close_das_task                        | 2023-11-05 19:02:41.204166 | 0.037 ms   ||                 └── end_transaction                       | 2023-11-05 19:02:41.204227 | 0.004 ms   |+-----------------------------------------------------------+----------------------------+------------+27 rows in set

通过上述回显结果,可以分析得出,导致 SQL 语句执行慢的原因是 sql_execute 占用了大量的时间,从而导致查询耗时增加。


4、查询表 TP 1 的结构并分析。

obclient [testdb]> desc tp1;

返回结果如下:

+-------+------------+------+-----+---------+-------+| Field | Type       | Null | Key | Default | Extra |+-------+------------+------+-----+---------+-------+| c1    | bigint(20) | YES  | MUL | NULL    |       || c2    | bigint(20) | YES  |     | NULL    |       |+-------+------------+------+-----+---------+-------+2 rows in set

通过查询表 TP1 的结构,发现查询字段 c1 上没有创建索引,导致在第 5 步查询时,走的全表扫描,从而使 SQL 语句执行缓慢,因此为表中 c1 字段创建索引。


5、为测试表创建索引。

obclient [testdb]> create index z on tp1(c1) global;


6、重新执行上述查询语句。

obclient [testdb]> select * from tp1 where c1 = 938599;

返回结果如下:

+--------+--------+| c1     | c2     |+--------+--------+| 938599 | 518633 |+--------+--------+1 row in set (0.006 sec)


7、通过 Show Trace 语句查看该语句的执行调用链路情况以及链路中各阶段的耗时情况,此时发现查询效率明显提升。

obclient [testdb]> show trace;

返回结果如下:

+-----------------------------------------------+----------------------------+------------+| Operation                                     | StartTime                  | ElapseTime |+-----------------------------------------------+----------------------------+------------+| obclient                                      | 2023-11-05 19:04:02.473941 | 5.719 ms   || └── com_query_process                         | 2023-11-05 19:04:02.474078 | 5.517 ms   ||     └── mpquery_single_stmt                   | 2023-11-05 19:04:02.474082 | 5.507 ms   ||         ├── sql_compile                       | 2023-11-05 19:04:02.474092 | 4.549 ms   ||         │   ├── pc_get_plan                   | 2023-11-05 19:04:02.474095 | 0.055 ms   ||         │   └── hard_parse                    | 2023-11-05 19:04:02.474174 | 4.458 ms   ||         │       ├── parse                     | 2023-11-05 19:04:02.474175 | 0.056 ms   ||         │       ├── resolve                   | 2023-11-05 19:04:02.474244 | 0.193 ms   ||         │       ├── rewrite                   | 2023-11-05 19:04:02.474512 | 0.321 ms   ||         │       ├── optimize                  | 2023-11-05 19:04:02.474842 | 3.562 ms   ||         │       ├── code_generate             | 2023-11-05 19:04:02.478417 | 0.094 ms   ||         │       └── pc_add_plan               | 2023-11-05 19:04:02.478588 | 0.038 ms   ||         └── sql_execute                       | 2023-11-05 19:04:02.478649 | 0.908 ms   ||             ├── open                          | 2023-11-05 19:04:02.478650 | 0.019 ms   ||             ├── response_result               | 2023-11-05 19:04:02.478674 | 0.819 ms   ||             │   └── do_local_das_task         | 2023-11-05 19:04:02.478687 | 0.364 ms   ||             └── close                         | 2023-11-05 19:04:02.479500 | 0.051 ms   ||                 ├── close_das_task            | 2023-11-05 19:04:02.479501 | 0.021 ms   ||                 └── end_transaction           | 2023-11-05 19:04:02.479541 | 0.003 ms   |+-----------------------------------------------+----------------------------+------------+19 rows in set (0.004 sec)

通过上述回显结果与第 3 步的内容对比得出,此时的 sql_execute 的耗时由 478.105 ms 降到了 0.908 ms,很大程度的提高了查询的效率。

二、2.x、3.x 版本全链路追踪介绍

(一)负载均衡层

1、SLB 问题排查方法

一个 SLB 负载均衡地址后端会挂载多个后端服务地址,快速定位是不是 SLB 这层出问题的办法是绕过 SLB 直连数据库服务器地址进行验证。


例如:A 为负载均衡地址,b、c、d 为后端服务器地址。


正常连接是:app-->A-->(b or c or d)


验证问题:app-->b、app-->c、app-->d 如果连接都没有问题,那说明肯定是负载均衡设备问题。


2、SLB 常见问题处理

① SLB 配置不足

🔎 问题现象:可能有两类表现:

业务使用负载均衡地址连接 hang。

没有到达连接数上限但是应用报错无法创建连接。此类问题还有可能是 SQL 执行过慢,导致获取连接超时了。

💡 问题原因:可能 SLB 配置不足,达到了瓶颈。

📕 处理方法: 扩容。具体操作如下:登录负载均衡设备--> 查看 SLB 配置-->修改配置项增加配置。

🎬 例如:某客户出现 SLB 连接使用达到 100% 问题,通过流量监控可以发现问题时间点的连接数和流量。查看对应 SLB 配置,显示该 SLB 配置规格为最大支持 5000 连接数,实际上压测阶段已经超过 5000,资源明显不够,需要修改配置进行扩容。


② SLB 网络存在问题

🔎 问题现象:通过负载均衡地址连接 hang 或者直接网络不通。

💡 问题原因:可能是防火墙策略、网络路由问题等其他硬件问题。

📕 处理方法:排查防火墙策略是否存在端口限制、网络路由是否存在问题,同时检查交换机设备模块是否存在丢包等问题。


③ 流量负载不均衡问题

🔎 问题现象:不同后端服务流量不一致。

💡 问题原因:SLB 负载均衡算法存在一定问题或者业务模型存在问题。

📕 处理方法:对于算法问题可以动态调整 SLB 负载均衡算法(推荐最大权重和 hash 算法)找到比较合适的算法,或者联系技术支持人员进行协助处理。

(二)OBProxy 层

OBProxy 只是全链路中的一个组件,在对 OBProxy 进行排查时,需要明确问题的场景,确定排查的方向。

👉 OBProxy 日志是问题诊断的主要信息来源,善于利用 trace_id、session_id、错误码以及 SQL 语句等信息进行日志的搜索。

👉 OCP 监控平台也提供了 OBProxy 的日志检索功能,对于有多个 OBPrxoy 节点的环境特别有用。


在全链路追踪中,对 OBProxy 进行排查首先要确定 OBProxy 实例的地址。在私有云场景,OBProxy 上面往往会有一个负载均衡,应用通常不直接连接 OBProxy 的地址,而是连接一个 VIP。此时,要确定 OBProxy 的地址可以采取以下方法:

👉 在 OceanBase 数据库中通过 sql_audit 查看 client_ip,client_ip 即为 OBProxy 的 地址。

👉 查看 LB 的配置情况,确定应用连接对应的 OBProxy 的范围列表。


🚩 慢查询诊断

在 obproxy.log 中会记录更详细的 Slow query 和 Slow transaction 日志。我们可以使用 obproxy.log 来查询从 OBProxy 视角统计的 SQL 与交易执行时间,通过对比上游的应用耗时统计,以及下游的 OBServer 的 SQL 和交易的耗时统计,从而得知 SQL 或者交易执行是慢在哪个环节。


要使用的慢查询日志,需要配置相应的 OBProxy 配置项:

👉 slow_query_time_threshold:obproxy_slow.log 的打印阈值,慢查询同时打印到 obproxy.log 日志中。

👉 query_digest_time_threshold:obproxy_digest.log 的打印阈值。

👉 slow_transaction_time_threshold:obproxy.log 的慢事务打印阀值。

(三)OBServer 层

SQL 执行失败如果发生在 OBServer 端,则 OBProxy 以及应用侧均会收到对于的 SQL 错误码,可以根据对应的错误码进行相应的分析处理。


在 OceanBase 数据库中进行问题诊断,根据问题类型的不同,可能会用到分布在不同位置的诊断信息。比如说,应用侧收到的错误码,OCP 监控平台的告警,OBServer 的运行日志,系统监控视图,以及操作系统日志等。


OceanBase 数据库的问题诊断要根据问题发生模块的不同而采用不同的真的方法,详细的诊断方法可通过以下链接或二维码进行问题排查。


https://www.oceanbase.com/docs/enterprise-oceanbase-database-cn-10000000000944054

综上所述,OceanBase 的全链路追踪在不同版本中展现出了其独特的优势和不断的进化。通过对 2.x、3.x 版本以及 4.x 版本的深入探讨,我们可以看到从负载均衡层的 SLB 问题,到 OBProxy 层的日志分析,再到 OBServer 层的 SQL 执行失败诊断,以及 4.x 版本中新增的全链路追踪功能,为运维人员提供了丰富的问题定位和性能优化的手段。无论是对于负载均衡设备的问题排查、慢查询的诊断,还是根据错误码进行相应的处理,全链路追踪都发挥着至关重要的作用。


希望本文能帮助大家在使用 OceanBase 时,更加得心应手地解决各种问题,提升系统的性能和稳定性,为业务的顺利开展提供有力的保障。在未来,随着 OceanBase 的不断发展,全链路追踪技术也将不断完善,为我们带来更多的便利和价值。

「喜欢这篇文章,您的关注和赞赏是给作者最好的鼓励」
关注作者
【版权声明】本文为墨天轮用户原创内容,转载时必须标注文章的来源(墨天轮),文章链接,文章作者等基本信息,否则作者和墨天轮有权追究责任。如果您发现墨天轮中有涉嫌抄袭或者侵权的内容,欢迎发送邮件至:contact@modb.pro进行举报,并提供相关证据,一经查实,墨天轮将立刻删除相关内容。

评论