老师好帮忙分析个备份异常的问题
【 使用环境 】POC验证环境
【 OB or 其他组件 】OB
【 使用版本 】4.3.5.1
【问题描述】
1.现象:执行物理全备报错如下命令
obclient(root@bk_test)[(none)]> alter system backup database plus archivelog;
ERROR 9040 (HY000): backup can not start, because log archive status is not doing.
obclient(root@bk_test)[(none)]> select last_trace_id();
±------------------------------------+
| last_trace_id() |
±------------------------------------+
| Y10B420A100B03-0006337D267562EA-0-0 |
±------------------------------------+
1 row in set (0.001 sec)
obclient(root@bk_test)[(none)]>
2.Y10B420A100B03-0006337D267562EA-0-0 相关日志:
[admin@obdemo2 log]$ grep Y10B420A100B03-0006337D267562EA-0-0 *.log
observer.log:[2025-08-13 11:25:26.284992] INFO [SQL.ENG] execute (ob_alter_system_executor.cpp:2387) [82744][T1006_L0_G0][T1006][Y10B 420A100B03-0006337D267562EA-0-0] [lt=19] no backup encryption mode is specified(stmt={stmt_type:204, tenant_id:1006, incremental:false , backup_tenant_ids:[], backup_description:"", compl_log:true, backup_dest:""})
observer.log:[2025-08-13 11:25:26.285062] INFO [SQL.ENG] execute (ob_alter_system_executor.cpp:2416) [82744][T1006_L0_G0][T1006][Y10B 420A100B03-0006337D267562EA-0-0] [lt=53] ObBackupDatabaseExecutor::execute(stmt={stmt_type:204, tenant_id:1006, incremental:false, bac kup_tenant_ids:[], backup_description:"", compl_log:true, backup_dest:""}, arg={tenant_id:1006, initiator_tenant_id:1006, initiator_jo b_id:0, backup_tenant_ids:[], is_incremental:false, backup_dest:"", backup_description:"", is_compl_log:true, encryption_mode:0, passw d:""}, ctx=)
observer.log:[2025-08-13 11:25:26.334288] WDIAG [RPC] send (ob_poc_rpc_proxy.h:176) [82744][T1006_L0_G0][T1006][Y10B420A100B03-0006337 D267562EA-0-0] [lt=48][errcode=-9040] execute rpc fail(addr=“10.16.11.2:2882”, pcode=5123, ret=-9040, timeout=599999741)
observer.log:[2025-08-13 11:25:26.334357] WDIAG log_user_error_and_warn (ob_poc_rpc_proxy.cpp:247) [82744][T1006_L0_G0][T1006][Y10B420 A100B03-0006337D267562EA-0-0] [lt=51][errcode=-9040] backup can not start, because log archive status is not doing.
observer.log:[2025-08-13 11:25:26.334403] WDIAG [SQL.ENG] execute (ob_alter_system_executor.cpp:2431) [82744][T1006_L0_G0][T1006][Y10B 420A100B03-0006337D267562EA-0-0] [lt=26][errcode=-9040] backup_database rpc failed(ret=-9040, arg={tenant_id:1006, initiator_tenant_id :1006, initiator_job_id:0, backup_tenant_ids:[], is_incremental:false, backup_dest:"", backup_description:"", is_compl_log:true, encry ption_mode:0, passwd:""}, dst=“10.16.11.2:2882”)
observer.log:[2025-08-13 11:25:26.334553] INFO [SHARE] add_event (ob_event_history_table_operator.h:266) [82744][T1006_L0_G0][T1006][ Y10B420A100B03-0006337D267562EA-0-0] [lt=43] event table add task(ret=0, event_table_name="__all_server_event_history", sql=INSERT INT O all_server_event_history (gmt_create, module, event, name1, value1, name2, value2, name3, value3, name4, value4, value5, value6, s vr_ip, svr_port) VALUES (usec_to_time(1755055526334461), ‘sql’, ‘execute_cmd’, ‘cmd_type’, 204, ‘sql_text’, X’616C7465722073797374656D 206261636B757020646174616261736520706C757320617263686976656C6F67’, ‘return_code’, -9040, ‘tenant_id’, 1006, ‘’, ‘’, ‘10.16.11.3’, 2882 ))
observer.log:[2025-08-13 11:25:26.334592] WDIAG [SQL] open_cmd (ob_result_set.cpp:68) [82744][T1006_L0_G0][T1006][Y10B420A100B03-00063 37D267562EA-0-0] [lt=28][errcode=-9040] execute cmd failed(ret=-9040)
observer.log:[2025-08-13 11:25:26.334623] WDIAG [SQL] open (ob_result_set.cpp:127) [82744][T1006_L0_G0][T1006][Y10B420A100B03-0006337D 267562EA-0-0] [lt=22][errcode=-9040] execute plan failed(ret=-9040)
observer.log:[2025-08-13 11:25:26.334653] WDIAG [SERVER] response_result (ob_sync_cmd_driver.cpp:139) [82744][T1006_L0_G0][T1006][Y10B 420A100B03-0006337D267562EA-0-0] [lt=20][errcode=-9040] close result set fail(cret=-9040)
observer.log:[2025-08-13 11:25:26.334683] WDIAG [SERVER] after_func (ob_query_retry_ctrl.cpp:1068) [82744][T1006_L0_G0][T1006][Y10B420 A100B03-0006337D267562EA-0-0] [lt=20][errcode=-9040] [RETRY] check if need retry(v={force_local_retry:false, stmt_retry_times:0, local retry_times:0, err:-9040, err:“OB_BACKUP_CAN_NOT_START”, retry_type:0, client_ret:-9040}, need_retry=false)
observer.log:[2025-08-13 11:25:26.334739] WDIAG [SERVER] response_result (ob_sync_cmd_driver.cpp:145) [82744][T1006_L0_G0][T1006][Y10B 420A100B03-0006337D267562EA-0-0] [lt=43][errcode=-9040] result set open failed, check if need retry(ret=-9040, cli_ret=-9040, retry_ct rl.need_retry()=0)
observer.log:[2025-08-13 11:25:26.334776] INFO [SERVER] send_error_packet (obmp_packet_sender.cpp:373) [82744][T1006_L0_G0][T1006][Y1 0B420A100B03-0006337D267562EA-0-0] [lt=16] sending error packet(ob_error=-9040, client error=-9040, extra_err_info=NULL, lbt()=“0x9525 fb6 0x10ec8790 0x10e73236 0x9016b00 0x8c6ffbe 0x8c5e4bc 0x8c57866 0x8c5586d 0x8c442cd 0x11090f79 0x22df655e 0x7fa6e0a45ea5 0x7fa6e076e b0d”)
observer.log:[2025-08-13 11:25:26.334851] INFO [SERVER] send_error_packet (obmp_packet_sender.cpp:576) [82744][T1006_L0_G0][T1006][Y1 0B420A100B03-0006337D267562EA-0-0] [lt=25] dump txn free route audit_record(value=0, session->get_sessid()=3221786036, session->get_pr oxy_sessid()=725091647708399672)
observer.log:[2025-08-13 11:25:26.334886] WDIAG [SERVER] do_process (obmp_query.cpp:1121) [82744][T1006_L0_G0][T1006][Y10B420A100B03-0 006337D267562EA-0-0] [lt=23][errcode=-9040] execute query fail(ret=-9040, timeout_timestamp=1755056126284727)
observer.log:[2025-08-13 11:25:26.335266] WDIAG [SERVER.OMT] process_one (ob_worker_processor.cpp:81) [82744][T1006_L0_G0][T1006][Y10B 420A100B03-0006337D267562EA-0-0] [lt=22][errcode=-9040] process request fail(ret=-9040)
observer.log:[2025-08-13 11:25:26.335298] WDIAG [SERVER.OMT] process (ob_worker_processor.cpp:149) [82744][T1006_L0_G0][T1006][Y10B420 A100B03-0006337D267562EA-0-0] [lt=23][errcode=-9040] process request fail(ret=-9040)
trace.log:[2025-08-13 11:25:26.334969] [82744][T1006_L0_G0][T1006][Y10B420A100B03-0006337D267562EA-0-0] {“trace_id”:“00063c36-b534-8d0 4-666f-e8fcc7194ea7”,“name”:“close”,“id”:“00063c36-b535-50bb-7ba1-b76bcc23d085”,“start_ts”:1755055526334651,“end_ts”:1755055526334652, “parent_id”:“00063c36-b534-8eb0-fc5a-6324fb9b1f83”,“is_follow”:false}
trace.log:[2025-08-13 11:25:26.335005] [82744][T1006_L0_G0][T1006][Y10B420A100B03-0006337D267562EA-0-0] {“trace_id”:“00063c36-b534-8d0 4-666f-e8fcc7194ea7”,“name”:“cmd_open”,“id”:“00063c36-b534-8eb4-20af-bcadc577c2fa”,“start_ts”:1755055526284980,“end_ts”:17550555263346 21,“parent_id”:“00063c36-b534-8eb2-d7a0-320bb42eb6f0”,“is_follow”:false}
trace.log:[2025-08-13 11:25:26.335023] [82744][T1006_L0_G0][T1006][Y10B420A100B03-0006337D267562EA-0-0] {“trace_id”:“00063c36-b534-8d0 4-666f-e8fcc7194ea7”,“name”:“open”,“id”:“00063c36-b534-8eb2-d7a0-320bb42eb6f0”,“start_ts”:1755055526284978,“end_ts”:1755055526334649," parent_id":“00063c36-b534-8eb0-fc5a-6324fb9b1f83”,“is_follow”:false}
trace.log:[2025-08-13 11:25:26.335048] [82744][T1006_L0_G0][T1006][Y10B420A100B03-0006337D267562EA-0-0] {“trace_id”:“00063c36-b534-8d0 4-666f-e8fcc7194ea7”,“name”:“sql_execute”,“id”:“00063c36-b534-8eb0-fc5a-6324fb9b1f83”,“start_ts”:1755055526284976,“end_ts”:17550555263 34884,“parent_id”:“00063c36-b534-8df3-7426-91d51deda424”,“is_follow”:false}
trace.log:[2025-08-13 11:25:26.335065] [82744][T1006_L0_G0][T1006][Y10B420A100B03-0006337D267562EA-0-0] {“trace_id”:“00063c36-b534-8d0 4-666f-e8fcc7194ea7”,“name”:“resolve”,“id”:“00063c36-b534-8e5b-ad70-1e737bc25a82”,“start_ts”:1755055526284891,“end_ts”:175505552628495 1,“parent_id”:“00063c36-b534-8e1c-80f6-c57a455862eb”,“is_follow”:false}
trace.log:[2025-08-13 11:25:26.335089] [82744][T1006_L0_G0][T1006][Y10B420A100B03-0006337D267562EA-0-0] {“trace_id”:“00063c36-b534-8d0 4-666f-e8fcc7194ea7”,“name”:“parse”,“id”:“00063c36-b534-8e1c-aebe-58ccddaa6405”,“start_ts”:1755055526284828,“end_ts”:1755055526284881, “parent_id”:“00063c36-b534-8e1c-80f6-c57a455862eb”,“is_follow”:false}
trace.log:[2025-08-13 11:25:26.335106] [82744][T1006_L0_G0][T1006][Y10B420A100B03-0006337D267562EA-0-0] {“trace_id”:“00063c36-b534-8d0 4-666f-e8fcc7194ea7”,“name”:“hard_parse”,“id”:“00063c36-b534-8e1c-80f6-c57a455862eb”,“start_ts”:1755055526284828,“end_ts”:175505552628 4973,“parent_id”:“00063c36-b534-8e04-1d56-9ea88e890243”,“is_follow”:false}
trace.log:[2025-08-13 11:25:26.335134] [82744][T1006_L0_G0][T1006][Y10B420A100B03-0006337D267562EA-0-0] {“trace_id”:“00063c36-b534-8d0 4-666f-e8fcc7194ea7”,“name”:“pc_get_plan”,“id”:“00063c36-b534-8e0d-03b7-9c7c3437e27b”,“start_ts”:1755055526284813,“end_ts”:17550555262 84825,“parent_id”:“00063c36-b534-8e04-1d56-9ea88e890243”,“is_follow”:false}
trace.log:[2025-08-13 11:25:26.335182] [82744][T1006_L0_G0][T1006][Y10B420A100B03-0006337D267562EA-0-0] {“trace_id”:“00063c36-b534-8d0 4-666f-e8fcc7194ea7”,“name”:“sql_compile”,“id”:“00063c36-b534-8e04-1d56-9ea88e890243”,“start_ts”:1755055526284804,“end_ts”:17550555262 84975,“parent_id”:“00063c36-b534-8df3-7426-91d51deda424”,“is_follow”:false,“tags”:[{“sql_id”:“3730E3422DAF4713BA298B3D27F16301”},{“dat abase_id”:18446744073709551615},{“sql_text”:“alter system backup database plus archivelog”},{“hit_plan”:false}]}
trace.log:[2025-08-13 11:25:26.335209] [82744][T1006_L0_G0][T1006][Y10B420A100B03-0006337D267562EA-0-0] {“trace_id”:“00063c36-b534-8d0 4-666f-e8fcc7194ea7”,“name”:“mpquery_single_stmt”,“id”:“00063c36-b534-8df3-7426-91d51deda424”,“start_ts”:1755055526284787,“end_ts”:175 5055526334949,“parent_id”:“00063c36-b534-8de6-1843-e61e8ec5b830”,“is_follow”:false}
trace.log:[2025-08-13 11:25:26.335237] [82744][T1006_L0_G0][T1006][Y10B420A100B03-0006337D267562EA-0-0] {“trace_id”:“00063c36-b534-8d0 4-666f-e8fcc7194ea7”,“name”:“com_query_process”,“id”:“00063c36-b534-8de6-1843-e61e8ec5b830”,“start_ts”:1755055526284774,“end_ts”:17550 55526334951,“parent_id”:“00000000-0000-0000-0000-000000000000”,“is_follow”:false,“tags”:[{“err_code”:-9040},{“sess_id”:3221786036},{“a ction_name”:""},{“module_name”:""},{“client_info”:""},{“receive_ts”:1755055526284727},{“log_trace_id”:“YB420A100B03-0006337D267562EA-0 -0”}]}
[admin@obdemo2 log]$
3.相关备份配置
obclient(root@bk_test)[(none)]> SELECT * FROM oceanbase.dba_OB_ARCHIVELOG\G
*************************** 1. row ***************************
DEST_ID: 1005
ROUND_ID: 4
INCARNATION: 1
DEST_NO: 0
STATUS: STOP
START_SCN: 1750410603314797000
START_SCN_DISPLAY: 2025-06-20 17:10:03.314797
CHECKPOINT_SCN: 1751970028892849002
CHECKPOINT_SCN_DISPLAY: 2025-07-08 18:20:28.892849
COMPATIBLE: 1
BASE_PIECE_ID: 12
USED_PIECE_ID: 30
PIECE_SWITCH_INTERVAL: 86400000000
UNIT_SIZE: 1
COMPRESSION: none
INPUT_BYTES: 9894687298
INPUT_BYTES_DISPLAY: 9.22GB
OUTPUT_BYTES: 9894687298
OUTPUT_BYTES_DISPLAY: 9.22GB
COMPRESSION_RATIO: 1.00
DELETED_INPUT_BYTES: 0
DELETED_INPUT_BYTES_DISPLAY: 0.00MB
DELETED_OUTPUT_BYTES: 0
DELETED_OUTPUT_BYTES_DISPLAY: 0.00MB
COMMENT:
PATH: file:///backupnfs/myobdemo/1744871768/tenant_incarnation_1/1006/clog
1 row in set (0.007 sec)
obclient(root@bk_test)[(none)]> SELECT * FROM oceanbase.dba_OB_ARCHIVE_DEST;
±--------±----------------------±---------------------------------------------------------------------+
| DEST_NO | NAME | VALUE |
±--------±----------------------±---------------------------------------------------------------------+
| 0 | binding | OPTIONAL |
| 0 | dest_id | 1005 |
| 0 | path | file:///backupnfs/myobdemo/1744871768/tenant_incarnation_1/1006/clog |
| 0 | piece_switch_interval | 1d |
| 0 | state | ENABLE |
±--------±----------------------±---------------------------------------------------------------------+
5 rows in set (0.006 sec)
obclient(root@bk_test)[(none)]> select * from oceanbase.DBA_OB_BACKUP_PARAMETER;
±-----------------±---------------------------------------------------------------------+
| NAME | VALUE |
±-----------------±---------------------------------------------------------------------+
| data_backup_dest | file:///backupnfs/myobdemo/1744871768/tenant_incarnation_1/1006/data |
±-----------------±---------------------------------------------------------------------+
1 row in set (0.011 sec)
【复现路径】问题出现前后相关操作
【附件及日志】推荐使用OceanBase敏捷诊断工具obdiag收集诊断信息,详情参见链接(右键跳转查看):
【备注】基于 LLM 和开源文档 RAG 的论坛小助手已开放测试,在发帖时输入 [@论坛小助手] 即可召唤小助手,欢迎试用!