OceanBase 数据库 V4.x 版本中排查 IO 问题的方法以及 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 查看调用栈。

适用版本

OceanBase 数据库 V4.x 版本。