【SOP 系列 10】物理备份恢复问题排查相关

写在前面

本文针对的群体,是已经对备份恢复的基本原理了解的用户群。笔者从内部使用,外部用户等渠道收集的相关备份和恢复过程比较常见的问题,进行了相关的排查经验梳理。对于刚接触备份恢复的用户,建议先去开源官网了解相关知识:OceanBase 备份与恢复

备份与恢复是数据库高可用中非常重要的环节之一, 也是 DBA 日常工作中基础的一环, 当应用业务逻辑发生错误, 产生大量脏数据时, 或者当 DBA 或应用误删数据时, 或者当需要将数据从一个集群迁移到另外一个集群式, 都可能需要使用上备份与恢复。在 OceanBase 中,备份与恢复是 OceanBase 数据高可靠的核心组件,通过纯 SQL 的命令就可以使用完整的备份和恢复功能。

排查思路

1)根据视图或内部表,找到关键信息,例如报错机器ip,错误码,备份状态,trace_id,事发时间戳等

2)利用关键信息,到对应机器上全局搜索并过滤日志,一般都能从日志中找到错误原因

3)如果上述两步不能解决,到 社区官网 或钉钉交流群 (ID:33254054) 求助

备份问题

关键内部表/视图

CDB_OB_BACKUP_PROGRESS 查看备份任务情况
__all_rootservice_event_history 查看RS历史任务(包括备份恢复)
__all_virtual_pg_backup_log_archive_status 查看分区级日志备份状态
__all_restore_info 查看恢复任务状态
__all_restore_history 查看恢复历史记录

查看最近的备份事件

select * from __all_rootservice_event_history where event like '%backup%' order by gmt_create desc limit 30;

查看分区的备份进度

select * from  __all_virtual_pg_backup_log_archive_status where table_id=xxx and partition_id=yyy;

查看单个 OBServer 上所有分区归档落后的日志总条数

select sum(max_log_id-log_archive_cur_log_id) from __all_virtual_pg_backup_log_archive_status where svr_ip="xxx" and svr_port=yyy;

查看某个分区归档是否在归档

select * from __all_virtual_pg_log_archive_stat where table_id=xxx and partition_id=yyy; // 查看是否有server在为该分区归档,以及实时的归档状态
select * from __all_virtual_clog_stat where table_id=xxx and partition_idx=yyy; // 查看分区是否为leader,以及分区所在机器ip地址

排查日志备份最慢的 pg

select usec_to_time(log_archive_cur_ts), * from __all_virtual_pg_backup_log_archive_status order by log_archive_cur_ts limit 10;

排查基线备份失败任务

通过过滤已经完成的备份事件的错误码来筛选出失败备份任务

select * from __all_rootservice_event_history where event like '%finish_backup%' and order by gmt_create desc and value4 not in (0, -4268, -4554) limit 30; // 其中value4为result字段,为备份任务的错误码信息 

排查最近的备份任务情况

select * from __all_rootservice_event_history where event like '%backup%' order by gmt_create desc limit 10;

排查单个 pg 的备份情况

select * from __all_rootservice_event_history where event like '%backup%' and value1 like 'xxx' // 其中xxx为table_id

执行备份后,备份路径下没有 data 文件

可能的原因是,集群中只有 sys 租户,没有新建其他租户,由于系统租户下的数据不备份,因此没有 data 文件是正常现象。

排查备份文件没有自动删除

首先,备份清理相关可参考:备份自动清理

其次,可以从两个角度排查

1)查系统变量确认自动删除开关是否打开(查看 “value” 字段是否为“true”)

show parameters like "%auto_delete_expired_backup%";

2)若上述确认自动开关已经打开后,可通过以下几步排查:

  1. 查看 CDB_OB_BACKUP_CLEAN_HISTORY 视图,确定上一次备份清理的时间点,假设为 t1
  2. 查看 CDB_OB_BACKUP_SET_DETAILS 视图,确认最近备份的开始时间点,假设为 t2
  3. 查看 backup_recovery_window 系统参数,默认为 7d(保留7天备份数据)
  4. 通过备份文件清理的时间点,结合系统参数 backup_recovery_window 的值,以及上一次备份文件的时间点,来判断哪些备份文件需要保留

我们不妨假设某个租户最近的备份时间 t2 为2022年2月13日20:00,上一次自动清理触发的时间 t1 为2022年2月20日18:00,根据当前自动清除的逻辑,会保留 backup_recovery_window(7天)内的备份数据,因此会保留2022年2月13日18:00 到2022年 2月20日18:00之间的备份数据,但由于2月13日的备份文件时间为20:00,因此会存在2月13日18:00到2月13日20:00两个小时的备份文件的空洞,为了保证恢复的完整性,此时会保留上上次的备份文件,也就是说备份文件之间存在对更早版本的依赖,即系统会保留2022年2月7号的备份文件,这就可能会让用户认为过期的备份文件没有删除。

排查日志备份断流

可以从两个角度看

1)OBServer 的 event 表,如果确认是 OBServer 报的断流,可以从这个表找到。

2)RootService 的 event 表,如果是 RS 触发的断流,可以从这个表找到。

排查 __all_server_event_history 表

select * from __all_server_event_history where event like '%mark_fatal_error%' order by gmt_create desc limit 30;

如果上述命令执行后,显示“event”一栏为“mark_fatal_error”,则查看该行对应的 svr_ip,最后从该 ip 机器的 log 日志搜错误打印;

排查 __all_rootservice_event_history 表

select * from __all_rootservice_event_history where module like '%archive%' order by gmt_create desc limit 30;

上述命令执行后,如果在“value1”一栏中出现关键字“INTERRUPTED”,则查看该行对应的 RS ip 地址,需要到对应的 OBServer 机器上查看 RS 的日志。下列为 RS 的错误日志打印示例:

[2020-06-01 22:24:25.476910] ERROR [SHARE] fetch_log_archive_backup_status_map_ (ob_log_archive_scheduler.cpp:1231) [8863][618]
[YB426458A15C-0005A704C89C96CD] [lt=3] [LOG_ARCHIVE] log archive status is interrupted, need human intervention(ret=-9027, addr="xxx", 
status={tenant_id:1003, start_ts:1591013841337584, checkpoint_ts:1591021437430755, status:5, incarnation:1, round:1, status_str:"INTERRUPTED"}) 

上述两种方法的思路是找到报错信息的机器,再根据错误码以及 trace_id(上述为YB426458A15C-0005A704C89C96CD)进行全日志搜索排查问题原因,一般可以从日志中找到问题根因。

排查日志备份卡在某个阶段

注意:以下 SQL 查询都使用 sys 租户登录集群

RootService 卡在 beginning 阶段

排查思路

1、确定该租户归档状态

a. 执行 SQL 语句 select * from CDB_OB_BACKUP_ARCHIVELOG; 确定 status 是 BEGINNING 状态

2、看哪个分区造成的落后

a. 执行 SQL 语句 select * from __all_virtual_pg_backup_log_archive_status order by log_archive_cur_ts limit 10;其中 log_archive_cur_ts 列表示该分区该副本当前归档进度,找到落后分区。log_archive_status为3表示doing,1 表示 stop,0 表示 invalid(初始状态)

b. 执行 SQL 语句 select * from __all_virtual_clog_stat where table_id=xxx and partition_idx=yyy; 查看该分区是否有 LEADER,如果无主是无法做归档的

c. 如果确定是有 leader 的,执行 SQL 语句 select * from __all_virtual_pg_log_archive_stat where table_id=xxx and partition_id=yyy; 可以看到该分区详细的归档各个环境的状态,其中 max_archived_checkpoint_ts 列等价于 a 表中 log_archive_cur_ts。

d. 如果在 c 表中没查到该分区,去 b 中 LEADER 机器 grep ARCHIVE observer.log | grep 该分区,看具体问题,必要情况下可能需要解析归档出去的数据,使用 ob_admin archive_tool 工具,有具体指导

3、如果在 2.d 中没有看到该分区,可能是备份 dest 问题(比如 NFS hang 等)

4、其他造成归档卡在 BEGINNING 的情况需要具体问题具体分析

RootService 卡在 stopping 状态

排查思路

  1. 确定是否在持续大量创建分区,如果有,那么通常 stop 需要一段时间
  2. 排查 __all_virtual_pg_backup_log_archive_status 表,确定是否所有 pg 的状态 log_archive_status 都是 1,执行如下 SQL 语句 select svr_ip, log_archive_status, count(*) from __all_virtual_pg_backup_log_archive_status group by svr_ip, log_archive_status;
  3. 如果有 pg 状态 log_archive_status 不是 1,通过 __all_virtual_partition_info 表找到 leader 所在 server,执行 grep ARCHIVE observer.log* | less 查看最新日志是否有 log archive stopped 打印,如果有那么等待一段时间,应该就进入 stop 状态;
  4. 如果等待 30s 依然卡在 stpping,进一步确定 __all_virtual_pg_backup_log_archive_status 表所有分区状态都是 1(R 类型副本除外),如果确定了分区所在 server 找了 log archive stopped 日志并且该 pg 还不是 stop,请联系社区值班群或到社区问答区提问;
  5. 排除以上情况,RS 还不是 stop,那么 grep log_archive_scheduler rootservice.log.* | less 看 RS 日志,OBServer 汇报的状态应该是 STOP,如果有 MIX 等状态,请联系社区值班群或到社区问答区提问。

RootService 在 doing 状态,但是出现落后

RS 处于该阶段,说明开启归档成功,当不断出现落后时,通常是由于某些分区异常或者某些机器异常。

排查思路一

  1. 首先看内部表 __all_virtual_pg_backup_log_archive_status 表(log_archive_cur_ts表示归档进度),执行 SQL 语句 select * from __all_virtual_pg_backup_log_archive_status order by log_archive_cur_ts limit 10;可以找到最落后分区以及归档进度 log_archive_cur_ts;
  2. 当出现某个分区所有副本落后时,在 1 中表里可以看到该分区全部副本都是落后的,尝试看表 __all_virtual_pg_log_archive_stat(max_archived_checkpoint_ts 表示归档进度), 执行 SQL 语句 select * from __all_virtual_pg_log_archive_stat where table_id=xxx and partition_id=yyy;可以看到实时的归档状态;
  3. 如果在 2 中表中能找到该分区,说明在为该分区服务,如果没有找到该分区,继续排查是否有 leader,执行 SQL 语句 select * from __all_virtual_clog_stat where table_id=xxx and partition_idx=yyy; 通过 role 列看是否有 leader
  4. 如果有 leader 但是在 2 中没有该分区,尝试以 svr_ip,svr_port 看 leader 所在机器在 __all_virtual_pg_log_archive_stat 是否有记录,排查是否是机器问题导致的该机器归档出现问题;
  5. 通过 grep ARCHIVE observer.log* | less 查看是否有报错,判断该机器是否出现问题。

另外,可能分区 leader 状态是正常的,但是 follower 归档进度落后。

排查思路二

  1. 如上,首先看内部表 __all_virtual_pg_backup_log_archive_status 表,执行 SQL 语句 select * from __all_virtual_pg_backup_log_archive_status order by log_archive_cur_ts desc limit 10; 可以找到最落后分区以及归档进度 log_archive_cur_ts;
  2. 看到非某个分区不是全部副本都是落后很多的,以 table_id=xxx and partition_id=yyy 过滤 1 中表,可以看到至少一个副本进度比其他副本快很多,大概率是 leader 归档进度快;
  3. 查看 __all_virtual_pg_log_archive_stat 表确认一下,如果存在则表示 leader 在归档;
  4. 大概率是 leader 向 follower 同步归档进度出现问题,看 leader 和 follower 日志打印,是否有 “ObLogArchiveAndRestoreDriver round_cost_time” 打印,以及以 CLOG 和 archive 关键字搜索出现的异常
  5. 另外在落后分区 leader 所在机器上搜索 ARCHIVE 和分区 id 相关日志,如果能发现诸如 start_archive_helper 日志可能是新 leader 上任开启归档遇到问题。

此外,还有可能是分区状态异常导致的归档状态落后,请咨询值班群或到社区官网提交问题。

另外,NFS 配置等,可能导致归档出问题,需要注意以下几点

  1. 一个集群归档必须独占一块(几块)盘,不能有一名用户多个集群或者多名用户共同使用一个盘作为归档目的端
  2. 作为 NFS 服务器的磁盘如 /data/1/,不能有本地读写,比如三个 OBServer,其中两台 server mount NFS盘如 /data/nfs/,写到 NFS 盘;另外一台 server 由于是 NFS 服务器,直接写到本地磁盘 /data/1/ 。这种情况也是必须避免的,NFS 的控制算法应该就失效了,会导致NFS卡住;
  3. NFS 配置推荐使用如下配置 mount -t nfs4 -o nolock,rw,noatime,nodiratime,sync,lookupcache=positive,timeo=100
  4. 需要确保使用的是 sync,而不是 async;timeo 设置为 100

恢复问题

排查发起恢复失败问题

  1. 找到 RS 机器,执行 grep “[RESTORE] physical restore tenant start” rootservice.log* | less
  2. 找到错误码,排查可能失败的原因如下:
错误码 可能的原因
-4179 1. 在备库上执行恢复命令
2. 在升级过程中执行恢复
3. 在主库接了备库时执行
4. 配置项 restore_concurrency = 0
-4023 restore_timestamp过小

排查恢复时间长问题

查看恢复各阶段开始时间

1、可以从内部表里查物理恢复各阶段的大致耗时

select * from __all_rootservice_event_history where module like "%physical_restore%" 
and value1 like "%job_id%" order by gmt_create desc limit 10;

2、可以进一步从 RS 机器上搜 rootservice.log 日志确定什么时候进入该阶段

  • 由于 RS 可能已经切主,可通过查 __all_rootservice_event_history 表大致确定当时 RS 的位置
  • 在事发 RS 机器上,执行 grep “[RESTORE] update job status(ret=0, job_id=job_id” rootservice.log

3、以上标红的 job_id,可从 __all_restore_info/__all_restore_history 表中根据恢复租户名获得

恢复各阶段解析

由于 __all_restore_info 是一张窄表,显示的是当前待调度的物理恢复任务内容,可能包含多个恢复任务的信息,可以根据 job_id/tenant_id/tenant_name 等定位到具体的物理恢复任务,并且查 __all_restore_info 表中的 status 字段判断目前处于物理恢复的哪个阶段。status 有如下取值:

执行顺序 流程状态 流程解析
1 CREATE_TENANT 创建待恢复租户&获取备份meta信息并持久化,不可重入,失败会退出物理恢复流程
2 RESTORE_SYS_REPLICA 恢复租户下系统表,可重入,遇到observer恢复错误才退出
3 UPGRADE_PRE 执行各版本PRE阶段升级动作,可重入,不退出
4 UPGRADE_POST 执行各版本POST阶段升级动作,可重入,不退出
5 MODIFY_SCHEMA 修正schema,可重入,不退出
6 CREATE_USER_PARTITIONS 创建用户表partition,不可重入,失败会退出
7 RESTORE_USER_REPLICA 恢复租户下用户表,可重入,遇到observer恢复错误才退出
8 REBUILD_INDEX 重建索引,可重入,不退出
9 POST_CHECK 等索引生效,可重入,不退出
10 RESTORE_SUCCESS 恢复成功
11 RESTORE_FAIL 恢复失败

需要注意的是:

  • 上述流程中,“不退出”指的是该阶段流程失败会在下一轮重试,直至能推进恢复状态。流程失败的话,内部表 __all_restore_info 会清恢复信息,相关恢复信息进入 __all_restore_history 表;
  • 若 __all_restore_info 为空,可根据 __all_restore_history 表的 info 字段拿到报错 mod 及 error_code。info 字段格式形如:ROOTSERVICE : OB_OP_NOT_ALLOW(-4179)。目前 mod 有 ROOTSERVICE、CLOG、STORAGE 这三种,错误信息里面记录了报错的 ip 和 trace_id;
  • 若问题没能解决,可求助开源值班群或者到社区官网提问。

排查基线任务恢复失败

select * from __all_rootservice_event_history where event like "%restore%" order by gmt_create desc limit 10;

如果有失败的,可以根据报错的内容找到对应的 pkey 和错误码,最后到对应的 OBServer 机器上搜索错误日志。

排查未恢复完成的副本

select tenant_id,table_id,partition_id,svr_ip,zone,role,is_restore,status  from __all_root_table where tenant_id=xxx and is_restore in (2,3);
select tenant_id,table_id,partition_id,svr_ip,zone,role,is_restore,status  from __all_virtual_meta_table where tenant_id=xxx and is_restore in (2,3);

排查 pg 的日志恢复状态

1)内部表方式

select svr_ip,table_id,partition_idx,role,status,leader,last_log_id,is_in_sync,start_id from __all_virtual_clog_stat where table_id=XXX and partition_idx=YYY;

2)日志方式

grep -rws 'set is_restore' observer.log* | less

关键日志

备份执行时相关日志

// 开始关键日志
grep -rws "backup replica batch"  observer.* | less 
// 结束关键日志
grep -rws "group migrate task" observer.* | grep "BACKUP_REPLICA_OP" | less

恢复执行时相关日志

1)leader 物理恢复

// 开始关键日志
grep "physical restore replica request"  observer.*
// 结束关键日志
grep "group migrate task" observer.* | grep "RESTORE_REPLICA_OP"

2)follower 物理恢复

// 开始关键日志
grep "receive copy sstable batch requestt"  observer.*
// 结束关键日志
grep "group migrate task" observer.* | fgrep "RESTORE_FOLLOWER_REPLICA_OP" 

注意:备份和恢复异常可以根据结束错误码向上追查

RS 调度恢复的日志

grep -E "start to physical restore replica|receive balance over"  rootservice.log*

备份恢复时一些容错的错误码

  • -4554 RS 调度可能的报错
  • -4017 OB_ENTRY_NOT_EXIST,备份时可能 sstable 备机还没刷到,可能会报错重试
  • -4017 OB_ENTRY_EXIST/-9019 OB_RESTORE_PARTITION_IS_COMPELETE,恢复已完成后重复调度可能的报错

非常好!收藏了。

1 个赞

有4.0版本的么。

学习到了:+1:t2::+1:t2::+1:t2:

mark…