OB 運維 | OceanBase 備份清理任務卡死之謎

作者：何文超 2025-02-07 11:08:03

運維系統運維

客戶 OceanBase 集群的備份策略是每天全備，備份文件最近保留 4 天。經過觀察，實際保留的備份文件多達 13 個，導致磁盤空間占用較高。

一、問題背景

客戶 OceanBase 集群的備份策略是每天全備，備份文件最近保留 4 天。經過觀察，實際保留的備份文件多達 13 個，導致磁盤空間占用較高。

二、問題排查

正常情況下，會有一個備份文件清理任務定期執行。備份文件超過了預設數量，猜測可能是文件清理任務出現問題。

1. 備份文件的清理任務

先看一下自動清理時間間隔的計算公式：

自動清理的時間間隔 = min(recovery_window/2, 1d)

故正常每天會發起一次備份文件的清理任務。

注意：對于 oceanbase-3.1.2-20211230114204 之前的版本（不含該版本），自動清理的時間間隔為 recovery_window/2。

備份文件的清理任務卡住了！

信息采集時間為 22 日。

發現 19 日發起備份清理任務，22 日還未完成，判斷為清理任務卡住了。

MySQL [oceanbase]> select * from __all_tenant_backup_clean_info;
+----------------------------+----------------------------+-----------+--------+----------------------------+----------------------------+-------------+------------------------+--------+------------------+-----------+---------+------------------+--------+---------+
| gmt_create                 | gmt_modified               | tenant_id | job_id | start_time                 | end_time                   | incarnation | type                   | status | parameter        | error_msg | comment | clog_gc_snapshot | result | copy_id |
+----------------------------+----------------------------+-----------+--------+----------------------------+----------------------------+-------------+------------------------+--------+------------------+-----------+---------+------------------+--------+---------+
| 2021-03-19 14:18:50.841475 | 2024-10-19 00:28:50.021733 |         1 |   1187 | 2024-10-19 00:28:49.998736 | 2024-10-19 00:27:09.663132 |           1 | DELETE OBSOLETE BACKUP | DOING  | 1728923329993025 |           |         | 1728845993342237 |      0 |       0 |
| 2024-10-19 00:28:50.030195 | 2024-10-19 00:28:50.030195 |      1001 |   1187 | 2024-10-19 00:28:49.998736 | 2024-10-19 00:27:09.663132 |           1 | DELETE OBSOLETE BACKUP | DOING  | 1728923329993025 |           |         | 1728845993342237 |      0 |       0 |
+----------------------------+----------------------------+-----------+--------+----------------------------+----------------------------+-------------+------------------------+--------+------------------+-----------+---------+------------------+--------+---------+
2 rows in set (0.01 sec)

集群備份清理有關的歷史事件信息。

MySQL [oceanbase]> select * from __all_rootservice_event_history where module='backup_clean';
+----------------------------+--------------+------------+-----------+--------+---------------+--------+---------+--------+----------+-------------------------------+-------+--------+-------+--------+------------+----------------+-------------+
| gmt_create                 | module       | event      | name1     | value1 | name2         | value2 | name3   | value3 | name4    | value4                        | name5 | value5 | name6 | value6 | extra_info | rs_svr_ip      | rs_svr_port |
+----------------------------+--------------+------------+-----------+--------+---------------+--------+---------+--------+----------+-------------------------------+-------+--------+-------+--------+------------+----------------+-------------+
| 2024-04-16 18:55:49.799602 | backup_clean | backup_set | tenant_id | 1      | backup_set_id | 1099   | copy_id | 0      | trace_id | YB42B6B49660-0005E8F1C2B2E2CD |       |        |       |        |            | 182.180.150.96 |        2882 |
-----------
輸出信息過多,省略部分信息
-----------
| 2024-10-19 00:28:50.010504 | backup_clean | backup_set | tenant_id | 1      | backup_set_id | 1288   | copy_id | 0      | trace_id | YB42B6B49660-0005E8F1C2B2E845 |       |        |       |        |            | 182.180.150.96 |        2882 |
| 2024-10-19 00:28:50.010521 | backup_clean | backup_set | tenant_id | 1      | backup_set_id | 1289   | copy_id | 0      | trace_id | YB42B6B49660-0005E8F1C2B2E845 |       |        |       |        |            | 182.180.150.96 |        2882 |
+----------------------------+--------------+------------+-----------+--------+---------------+--------+---------+--------+----------+-------------------------------+-------+--------+-------+--------+------------+----------------+-------------+
191 rows in set (29.60 sec)

2. 查看日志

2.1 備份清理調度任務失敗

[root@hwc-ocp RS_cl_bigdata]# grep "ob_backup_data_clean" rootservice.log.20241022040332 ｜ grep WARN
rootservice.log.20241022040332:[2024-10-22 03:48:55.440734] INFO  [RS] ob_backup_data_clean_scheduler.cpp:71 [101273][788][YB42B6B49660-0005E8CB48709532] [lt=7] [dc=0] backup data scheduler init(arg={type:12, value:1729194535439601, copy_id:0})
rootservice.log.20241022040332:[2024-10-22 03:48:55.445090] WARN  [RS] schedule_sys_tenant_backup_data_clean (ob_backup_data_clean_scheduler.cpp:352) [101273][788][YB42B6B49660-0005E8CB48709532] [lt=6] [dc=0] sys tenant clean info status is not stop, can do scheduler(ret=-9044, clean_info={tenant_id:1, job_id:1187, start_time:1729268929998736, end_time:1729268829663132, incarnation:1, copy_id:0, type:1, status:2, expired_time:1728923329993025, backup_set_id:0, error_msg:"", comment:"", clog_gc_snapshot:1728845993342237, result:0, backup_piece_id:0, backup_round_id:0})
rootservice.log.20241022040332:[2024-10-22 03:48:55.445176] WARN  [RS] schedule_backup_data_clean (ob_backup_data_clean_scheduler.cpp:275) [101273][788][YB42B6B49660-0005E8CB48709532] [lt=12] [dc=0] failed to schedule sys tenant backup(ret=-9044)
rootservice.log.20241022040332:[2024-10-22 03:48:55.445187] WARN  [RS] start_schedule_backup_data_clean (ob_backup_data_clean_scheduler.cpp:89) [101273][788][YB42B6B49660-0005E8CB48709532] [lt=8] [dc=0] failed to schedule backup data clean(ret=-9044, tenant_ids=[1, 1003, 1004])
rootservice.log.20241022040332:[2024-10-22 03:53:55.447033] INFO  [RS] ob_backup_data_clean_scheduler.cpp:71 [101273][788][YB42B6B49660-0005E8CB48709532] [lt=15] [dc=0] backup data scheduler init(arg={type:12, value:1729194835445853, copy_id:0})

判斷關鍵字：sys tenant clean info status is not stop, can do scheduler

查看日志可推斷 sys 租戶備份清理任務狀態不是 stop 的狀態，故備份清理調度任務失敗。

與上文中 __all_tenant_backup_clean_info 視圖表查詢結果形成呼應，判定為備份清理任務異常。

清理任務失敗原因：上一次的備份清理任務狀態一直為 doing。

2.2 無法識別到路徑

通過備份清理任務的 trace_id

[root@hwc-ocp RS_cl_bigdata]# grep "YB42B6B49660-0005E8F1C2B2E845" rootservice.log.20241022001100 |grep WARN
[2024-10-21 23:37:26.194250] WARN  [ARCHIVE] get_file_id_range_ (ob_archive_log_file_store.cpp:501) [101266][774][YB42B6B49660-0005E8F1C2B2E845] [lt=9] [dc=0] failed get_file_range(uri=file:///obbak_bigdata/cl_bigdata_new/cl_bigdata/2/incarnation_1/1003/clog/13/index/1102810163026406/13, ret=-4018, pg_key={tid:1102810163026406, partition_id:13, part_cnt:0})
[2024-10-21 23:37:26.194257] WARN  [ARCHIVE] get_index_file_id_range (ob_archive_log_file_store.cpp:281) [101266][774][YB42B6B49660-0005E8F1C2B2E845] [lt=5] [dc=0] failed to get_index_file_id_range(ret=-4018, pg_key={tid:1102810163026406, partition_id:13, part_cnt:0})
[2024-10-21 23:37:26.194264] WARN  [ARCHIVE] locate_file_by_log_ts_for_clear (ob_archive_log_file_store.cpp:252) [101266][774][YB42B6B49660-0005E8F1C2B2E845] [lt=5] [dc=0] get_index_file_id_range fail(ret=-4018, pg_key={tid:1102810163026406, partition_id:13, part_cnt:0})
[2024-10-21 23:37:26.217948] WARN  [ARCHIVE] get_file_id_range_ (ob_archive_log_file_store.cpp:501) [101266][774][YB42B6B49660-0005E8F1C2B2E845] [lt=8] [dc=0] failed get_file_range(uri=file:///obbak_bigdata/cl_bigdata_new/cl_bigdata/2/incarnation_1/1003/clog/13/index/1102810163026406/216, ret=-4018, pg_key={tid:1102810163026406, partition_id:216, part_cnt:0})

判斷關鍵字：failed get_file_range

2.3 IO 調用異常

繼續排查，發現通過該 trace_id

[root@hwc-ocp RS_cl_bigdata]# grep "access storage" rootservice.log.20241022040332 ｜ grep "YB42B6B49660-0005E8F1C2B2E845"
rootservice.log.20241022040332:[2024-10-22 04:02:23.121397] WARN  [STORAGE] print_access_storage_log (ob_storage.cpp:39) [101266][774][YB42B6B49660-0005E8F1C2B2E845] [lt=10] [dc=0] access storage op=list_files uri=file:///obbak_bigdata/cl_bigdata_new/cl_bigdata/2/incarnation_1/1003/clog/13/index/1102810162740407/88 size=0 Byte cost_ts=2129326 us speed=0.00 MB/s
rootservice.log.20241022040332:[2024-10-22 04:02:24.660028] WARN  [STORAGE] print_access_storage_log (ob_storage.cpp:39) [101266][774][YB42B6B49660-0005E8F1C2B2E845] [lt=9] [dc=0] access storage op=list_files uri=file:///obbak_bigdata/cl_bigdata_new/cl_bigdata/2/incarnation_1/1003/clog/13/index/1102810162744871/4 size=0 Byte cost_ts=1537551 us speed=0.00 MB/s
rootservice.log.20241022040332:[2024-10-22 04:02:33.558367] WARN  [STORAGE] print_access_storage_log (ob_storage.cpp:39) [101266][774][YB42B6B49660-0005E8F1C2B2E845] [lt=13] [dc=0] access storage op=storage reader uri=file:///obbak_bigdata/cl_bigdata_new/cl_bigdata/2/incarnation_1/1003/clog/13/index/1102810162738281/141/2 size=144 Byte cost_ts=1243114 us speed=0.00 MB/s
rootservice.log.20241022040332:[2024-10-22 04:02:38.908843] WARN  [STORAGE] print_access_storage_log (ob_storage.cpp:39) [101263][768][YB42B6B49660-0005E8CB48109532] [lt=9] [dc=0] access storage op=get_file_length uri=file:///obbak_bigdata/cl_bigdata_new/cl_bigdata/2/incarnation_1/cluster_clog_backup_info size=0 Byte cost_ts=1176124 us speed=0.00 MB/s

判斷關鍵詞：access storage，us speed=0.00 MB/s

3. 檢查 NFS

[admin@x-shhp-oceanbase-db-p02:~]$ mount |grep nfs
2.4.8.124:/obbak_bigdata on /obbak_bigdata type nfs (rw,relatime,vers=3,rsize=1048576,wsize=1048576,namlen=255,hard,proto=tcp,timeo=600,retrans=2,sec=sys,mountaddr=2.4.8.124,mountvers=3,mountport=2050,mountproto=tcp,local_lock=none,addr=2.4.8.124)

生產環境的 NFS 版本為 3.x，原來 3 版本為 OB 側非標部署[1]。

結論：生產未嚴格按官方文檔的要求配置 NFS，可能存在很多異常問題，包括備份清理問題。

三、優化建議

嚴格按官方文檔的要求配置 NFS，修改 NFS 版本為 4.x，備份卡住的問題得到解決。

參考資料

[1]OceanBase NFS 部署建議: https://www.oceanbase.com/docs/enterprise-oceanbase-database-cn-10000000000360550

作者：何文超，愛可生南區交付服務部 DBA 團隊成員。主要負責 MySQL 故障處理，MySQL 高可用架構改造，OceanBase 相關技術支持。愛好足球，羽毛球。

責任編輯：武曉燕來源：愛可生開源社區

OceanBase 集群 NFS