【OceanBase诊断调优】—— 排查 IO 问题的方法

本文主要介绍 OceanBase 数据库 V4.x 版本中排查 IO 问题的方法以及 IO 相关的日志和视图。

IO 相关问题

-4013 内存爆、IoControl 模块内存泄漏

目前 IO 内存爆可能的原因如下，及相应的排查方法。

其他模块使用 IO 内存后未释放导致泄漏。
- 日志分析。
  
  通过关键词过滤日志信息，检查内存使用是否持续上升，命令如下。
```
grep MEMORY observer.log | grep IoControl
```
- 开启 memleak 诊断内存泄漏。
  
  若存在 IoControl 模块内存泄漏问题，在 OceanBase 数据库 V4.1 版本中可使用 memleak checker 检测内存泄漏，并通过查询 __all_virtual_mem_leak_checker_info 表的信息，执行语句如下。
```
select * from __all_virtual_mem_leak_checker_info order by alloc_size desc limit 5;
```
  如上图信息，查询结果按照 alloc_size 大小降序排列，可知 alloc_count 列和 back_trace 列信息，获取可能出问题的调用堆栈信息，一般来说存在泄露的调用堆栈计数 alloc_count 列值都很大（而且越来越大），将这样的调用堆栈利用 addr2line 打印出。排查堆栈打印出的 IO 模块的上层调用关系，确定 IoControl 模块内存泄漏问题。
- IO Tracer。
  1. 启用 io_tracer 追踪内存泄漏。
```
obclient> ALTER SYSTEM SET leak_mod_to_check = 'io_trace';
```
  2. 通过命令在日志中过滤关键词，查看 tracer 抓到的堆栈信息。
```
grep "IO STATUS SENDER"
```
    输出疑似泄漏路径 top 5 条日志信息。
达到租户内存上限。
- 目前，IO buf 内存分配由两部分构成，一部分是 IoControl 直接分配（如 log IO），还有一部分是由 IO Callback 分配，同时 IO buf 和 IORequest 内存强耦合，高峰状态可能被一起 hold 住，导致短时间内存爆，IOControl 模块目前内存上限就是租户 system_memory，因此如果在压力场景下出现内存打满可以考虑调大 system_memory（对于 deploy.py 的部署，可以修改 obi.py 里面的 system_memory 字段）然后重启。
- 租户资源相关的命令。
  - 查看集群中所有的资源单元配置。
```
SELECT * FROM oceanbase.DBA_OB_UNIT_CONFIGS\G;
```
  - 修改 Unit 的资源规格。
    
    示例代码。
```
ALTER RESOURCE UNIT unitname  MAX_CPU [=] cpunum,  [MIN_CPU [=] cpunum,] MEMORY_SIZE [=] memsize,  [MAX_IOPS [=] iopsnum, MIN_IOPS [=] iopsnum,IOPS_WEIGHT [=]iopsweight,] [LOG_DISK_SIZE [=] logdisksize];
```
- 查看资源池。
```
SELECT * FROM oceanbase.DBA_OB_RESOURCE_POOLS\G;
```
- 查看集群内各 Server 的资源分配情况。
```
SELECT * FROM oceanbase.GV$OB_SERVERS\G;
```
- 查看租户资源。
```
SELECT * FROM oceanbase.DBA_OB_UNITS\G;
```
- 查看集群内所有租户的资源分配情况。
```
SELECT * FROM oceanbase.GV$OB_UNITS\G;
```
达到 IOPS 配置上限。

当 IO 内存爆的原因是达到 IOPS 配置上限，解决方法如下。
1. 查询资源单元的配置信息。
```
select * from __all_unit_config;
```
2. 修改 Unit 的资源规格中的 IOPS 值。
```
alter resource unit box1 max_iops = 20000;
```

-4012 IO 超时

IO 报 -4012 超时场景比较多，包括 IO 超时设置错误、sender 队列卡住等。此外，IO 超时还可能导致其他问题，如 OB_IO_ERROR -4009。

以下是一些常见的排查方法。

通过命令在日志中过滤关键词，查看 IO 超时报错信息。
```
grep "IO wait timeout"
```
在 OceanBase 数据库 V4.2 及以下版本，日志里的 timeout_ms_ 代表着 IO 超时时间；在 OceanBase 数据库 V4.3 及以上版本，日志里的 result_-> timeout_us_ 代表着 IO 超时时间。

若 IO 超时时间为 0，可能调用层设置错误，另外一种可能是因为前面的 RPC 把时间耗光了。
sender 队列卡住。

通过命令在日志中过滤关键词，查看 IO 请求调度信息。
```
grep "IO SENDER STATUS"
```
sender 队列卡住的问题，可以参考 IO 调度队列卡 这一节内容，目前看来这种错误在磁盘状态差的情况下比较容易出，定位到 io_prepare 阶段分内存耗时过久。

-4392 OB_DISK_HUNG 磁盘故障、快速拒绝

通过日志确定磁盘 hung。

报出 -4392 前日志中一般会出现 xxx may be hung 类似的日志信息，在最开始报 -4392 的地方可使用命令 grep "may be hung" 搜索出相应的日志内容。可能的三种 OB_DISK_HUNG 磁盘故障事件。
通过系统性能工具排查 OB_DISK_HUNG 磁盘故障。

可能的三种 OB_DISK_HUNG 磁盘故障事件中，data 和 slog 会触发 IO 的快速拒绝，代表 IO 探测线程判断磁盘故障或 slog 判断写盘慢，有可能当时是磁盘真的有问题（如图 1），使用系统性能监控工具 tsar 或 vsar 查看磁盘的状态。

图 1。

也有可能是磁盘压力过大（util 90% 以上，如图 2）或者性能抖动，使用系统性能监控工具 tsar 展示的对应盘 util 使用率和 load 负载情况。

图 2。

排查 -4012 OB_IO_TIMEOUT 和 -4009 OB_IO_ERROR

针对 IO 探测线程检测到的磁盘问题，一般来说 IO 探测线程执行探测任务的触发条件有两种：-4012 OB_IO_TIMEOUT 和 -4009 OB_IO_ERROR，这两种故障码会触发探测线程执行重试 IO 请求，如果重试超时未完成就会判断磁盘故障，data 相关的磁盘故障有两种级别： data_storage_warn 和 data_storage_error，对应的默认探测超时时间分别为 5s 和 30s。
```
DEF_TIME(log_storage_warning_tolerance_time, OB_CLUSTER_PARAMETER, "5s",
DEF_TIME(data_storage_warning_tolerance_time, OB_CLUSTER_PARAMETER, "5s", "[1s,300s]",
DEF_TIME_WITH_CHECKER(data_storage_error_tolerance_time, OB_CLUSTER_PARAMETER, "300s", common::ObDataStorageErrorToleranceTimeChecker, "[10s,7200s]",
```
- 代码里针对 error 级别的错误，还会打印日志，可以使用 grep 命令搜索查看，是否存在磁盘探测触发的 -4392：
```
LOG_ERROR_RET(OB_IO_ERROR, "set_disk_error: attention!!!");
LOG_DBA_ERROR(OB_DISK_ERROR, "msg", "The disk may be corrupted");
```
- 针对 warn 级别的日志会打：
```
LOG_WARN_RET(OB_IO_ERROR, "disk maybe too slow");
```
  - 其中 data_storage_warning_tolerance_time=5s 这个时间相对比较严格，如果使用的机器磁盘性能一般的话建议调大这个值，避免误报。
    
    示例。
```
ALTER SYSTEM SET data_storage_warning_tolerance_time = 20s;
```
- 如果触发了 data_storage_warn，正常情况下会在 1 min 内洗白，即认为磁盘恢复正常，如果触发了 data_storage_error 则需要 DBA （数据库管理员）介入，如果确认磁盘没有问题，可以执行 ALTER SYSTEM SET disk valid server [=] 'ip:port'; 洗白。
- 如果触发了上述的两种磁盘故障级别，后续的 IO 请求都会直接报 -4392 OB_DISK_HUNG，直到磁盘洗白前 IO 请求都会直接被判断错误返回，不会往调度层和系统调用提交。根据上述描述，触发探测请求比较多的是 -4012 超时，因此 -4392 前面往往会先出现 -4012，-4012 可以参照上面一条排查。
- 如果是 slog 写盘慢认为 data 盘故障，可以在日志里搜 Slow write，同样会触发 -4392 快速拒绝机制，同样的，可以调整上面的 log_storage_warning_tolerance_time 如果怀疑 slog/clog 盘没有问题误报，可联系 OceanBase 技术支持确认。

IO 相关日志和视图

用于监控和诊断 IO 问题的各种日志和视图

IO 规格和流量

通过 __all_virtual_io_quota 表查看实时 IOPS，在有 IO 流量的情况下，每秒打印一次，如果开了 resource manager 资源隔离和限制，还可以显示指定的资源组 ID（默认为0）。

示例。
通过 grep 过滤关键词 IO STATUS 的命令 grep "IO STATUS" 查看 IO 的配置，主要用于查看 IO 压力大、流量打满的情况下是否满足资源隔离约束。如果在大压力场景 IO 慢则可能是给定的资源规格太小。

示例。

IO 调度队列卡住

通过 grep 过滤关键词 IO SENDER STATUS 的命令 grep "IO SENDER STATUS" 查看 IO 请求调度信息，包括所有调度线程中排队的 IO 请求数量和下一个请求发出时间（对应 __all_virtual_io_scheduler 表），每秒打印一次。主要用于查看 IO 超时、IO 调度队列卡住等问题，如果 sender 中 req_count 数量一段时间没有明显减少，则可能是卡住了，日志信息如下。

此时可以查看时间戳是否对得上（比如理论上发送时间 << 当前时间，则说明队列卡住），时间戳转换使用 date -d@ 命令。

示例。
```
$ date +%s
1709534153
$date -d@1709534153
Mon Mar  4 14:35:53 CST 2024。
```
若有 ObTimeGuard 日志超时打印，可进一步排查具体问题所在阶段。

针对调度队列卡住的问题，在 sender 中加入了 pop_phyqueue、submit_req prepare 三个 ObTimeGuard，超时时间均为 100ms，如果发现调度队列卡住可以先查看这几个 ObTimeGuard 是否打印出了相应日志，如下图显示在 prepare 阶段花费了太多时间。

IO 引用计数统计

通过 grep 过滤关键词 IO STATUR TRACER 的命令 grep "IO STATUS TRACER" 查看 IO 引用计数统计，用以排查内存泄漏问题（前提是开了 io_tracer 配置项），如果 req_count 持续上涨，那么可能存在有泄漏的问题，可以通过 backtrace 查看调用栈。