【 使用环境 】测试环境
【 OB or 其他组件 】
【 使用版本 】在线安装最新版本
【问题描述】如下表级恢复命令，执行后查询表级恢复进度，status一直处于recovering状态，对应的表数据量才1000条，只有一个字段。ALTER SYSTEM
RECOVER TABLE test.table1
TO TENANT tenant001
FROM ‘file:///nfsroot,file:///home/admin/archive’
WITH ‘pool_list=restore_pool’;
【复现路径】备份租户tenant001，查看备份结果表，直到可以看到对应备份completed。删除数据表test.table1，执行表级恢复命令
【附件及日志】无法上传，observe.log部分日志如下
[2025-07-16 14:55:39.377029] INFO [SERVER] sleep_before_local_retry (ob_query_retry_ctrl.cpp:88) [27589][T1022_TimerWK0_FreInfoReload][T1022][YB42AC12040A-000639F8E61C6331-0-0] [lt=1] will sleep(sleep_us=100000, remain_us=5627762, base_sleep_us=1000, retry_sleep_type=1, v.stmt_retry_times_=292, v.err_=-6231, timeout_timestamp=1752648945004790)
[2025-07-16 14:55:39.384586] INFO [SERVER] get_ls_replayed_scn (ob_service.cpp:3782) [4244][T1022_L0_G18][T1022][YB42AC12040A-000639F8E4FC88F0-0-0] [lt=82] start get_ls_replayed_scn(arg={tenant_id:1022, ls_id:{id:1}, all_replica:false})
[2025-07-16 14:55:39.384645] INFO [SERVER] get_ls_replayed_scn (ob_service.cpp:3865) [4244][T1022_L0_G18][T1022][YB42AC12040A-000639F8E4FC88F0-0-0] [lt=104] finish get_ls_replayed_scn(ret=0, ret=“OB_SUCCESS”, cur_readable_scn={val:1752647153539058000, v:0}, arg={tenant_id:1022, ls_id:{id:1}, all_replica:false}, result={tenant_id:1022, ls_id:{id:1}, cur_readable_scn:{val:1752647153539058000, v:0}, offline_scn:{val:18446744073709551615, v:3}, self_addr_:“172.18.4.10:2882”}, offline_scn={val:18446744073709551615, v:3})
[2025-07-16 14:55:39.385127] WDIAG [RPC] wait (ob_async_rpc_proxy.h:454) [27562][T1022_TeRec][T1022][YB42AC12040A-000639F8E4FC88F0-0-0] [lt=76][errcode=0] execute rpc failed(rc=-4109, server=“172.18.4.12:2882”, timeout=1999958, packet code=1859, arg={tenant_id:1022, ls_id:{id:1}, all_replica:false}, ret=0)
[2025-07-16 14:55:39.385218] WDIAG [STORAGE] update_ls_replayable_point (ob_ls_meta.cpp:550) [27562][T1022_TeRec][T1022][YB42AC12040A-000639F8E4FC88F0-0-0] [lt=67][errcode=-4002] replayable_point invalid(ret=-4002, replayable_point={val:1752647164112183000, v:0}, replayable_point_={val:1752647199464528000, v:0})
[2025-07-16 14:55:39.385459] INFO [SERVER] get_ls_replayed_scn (ob_service.cpp:3782) [4244][T1022_L0_G18][T1022][YB42AC12040A-000639F8E4FC88F0-0-0] [lt=114] start get_ls_replayed_scn(arg={tenant_id:1022, ls_id:{id:1001}, all_replica:false})
[2025-07-16 14:55:39.385489] INFO [SERVER] get_ls_replayed_scn (ob_service.cpp:3865) [4244][T1022_L0_G18][T1022][YB42AC12040A-000639F8E4FC88F0-0-0] [lt=56] finish get_ls_replayed_scn(ret=0, ret=“OB_SUCCESS”, cur_readable_scn={val:1752647201466375999, v:0}, arg={tenant_id:1022, ls_id:{id:1001}, all_replica:false}, result={tenant_id:1022, ls_id:{id:1001}, cur_readable_scn:{val:1752647201466375999, v:0}, offline_scn:{val:18446744073709551615, v:3}, self_addr_:“172.18.4.10:2882”}, offline_scn={val:18446744073709551615, v:3})
[2025-07-16 14:55:39.385946] WDIAG [RPC] wait (ob_async_rpc_proxy.h:454) [27562][T1022_TeRec][T1022][YB42AC12040A-000639F8E4FC88F0-0-0] [lt=315][errcode=0] execute rpc failed(rc=-4109, server=“172.18.4.12:2882”, timeout=1999974, packet code=1859, arg={tenant_id:1022, ls_id:{id:1001}, all_replica:false}, ret=0)
[2025-07-16 14:55:39.390226] INFO [PALF] get_log (palf_handle_impl.cpp:4116) [4199][T1022_L0_G1][T1022][YB42AC12040B-000639F58B9FDDE9-0-0] [lt=72] submit fetch log task success(ret=0, palf_id=1, server=“172.18.4.11:2882”, fetch_type=0, prev_lsn={lsn:0}, start_lsn={lsn:0}, fetch_log_size=41943040, fetch_log_count=2048, accepted_mode_pid=1)
[2025-07-16 14:55:39.390235] INFO [PALF] handle (fetch_log_engine.cpp:279) [27606][T1022_FetchLog0][T1022][Y0-0000000000000000-0-0] [lt=96] handle fetch_log_task(fetch_log_task={timestamp_us:1752648939390215, id:1, server:“172.18.4.11:2882”, fetch_type:“FETCH_LOG_FOLLOWER”, proposal_id:1, prev_lsn:{lsn:0}, start_lsn:{lsn:0}, log_size:41943040, log_count:2048, accepted_mode_pid:1})
[2025-07-16 14:55:39.390307] INFO [PALF] fetch_log_from_storage_ (palf_handle_impl.cpp:3703) [27606][T1022_FetchLog0][T1022][Y0-0000000000000000-0-0] [lt=176] no need fetch_log_from_storage(ret=0, this={palf_id:1, self:“172.18.4.10:2882”, has_set_deleted:false}, server=“172.18.4.11:2882”, fetch_start_lsn={lsn:0}, prev_lsn={lsn:0}, max_flushed_end_lsn={lsn:0}, access_mode=2)
[2025-07-16 14:55:39.390348] INFO [PALF] fetch_log_from_storage_ (palf_handle_impl.cpp:3827) [27606][T1022_FetchLog0][T1022][Y0-0000000000000000-0-0] [lt=104] fetch_log_from_storage_ finished(ret=0, this={palf_id:1, self:“172.18.4.10:2882”, has_set_deleted:false}, prev_lsn={lsn:0}, iterator={iterator_impl:{buf_:null, next_round_pread_size:0, curr_read_pos:0, curr_read_buf_start_pos:0, curr_read_buf_end_pos:0, log_storage_:NULL, curr_entry_is_raw_write:false, curr_entry_size:0, prev_entry_scn:{val:18446744073709551615, v:3}, curr_entry:{LogGroupEntryHeader:{magic:0, version:0, group_size:0, proposal_id:9223372036854775807, committed_lsn:{lsn:18446744073709551615}, max_scn:{val:18446744073709551615, v:3}, accumulated_checksum:0, log_id:0, flag:0}}, init_mode_version:0, accumulate_checksum:-1, curr_entry_is_padding:0, padding_entry_size:0, padding_entry_scn:{val:18446744073709551615, v:3}}, io_ctx:{user:“DEFAULT”, palf_id:0, iterator_info:{allow_filling_cache:true, hot_cache_stat:{hit_cnt:0, miss_cnt:0, cache_read_size:0, hit_ratio:“0.000000000000000000e+00”}, cold_cache_stat:{hit_cnt:0, miss_cnt:0, cache_read_size:0, hit_ratio:“0.000000000000000000e+00”}, read_io_cnt:0, read_io_size:0, read_disk_cost_ts:0, start_lsn:{lsn:18446744073709551615}}}}, fetch_log_count=2048, has_fetched_log_count=0)
[2025-07-16 14:55:39.390442] WDIAG [PALF] try_send_committed_info_ (palf_handle_impl.cpp:3626) [27606][T1022_FetchLog0][T1022][Y0-0000000000000000-0-0] [lt=247][errcode=-4002] invalid arguments(ret=-4002, this={palf_id:1, self:“172.18.4.10:2882”, has_set_deleted:false}, server=“172.18.4.11:2882”, log_lsn={lsn:0}, log_end_lsn={lsn:0}, log_proposal_id=9223372036854775807)
[2025-07-16 14:55:39.390498] INFO [PALF] submit_fetch_mode_meta_resp (log_mode_mgr.cpp:824) [27606][T1022_FetchLog0][T1022][Y0-0000000000000000-0-0] [lt=61] submit_change_mode_meta_req success(ret=0, palf_id=1, server=“172.18.4.11:2882”, mode_meta={version:1, proposal_id:1, mode_version:0, access_mode:2, ref_scn:{val:1, v:0}}, accepted_mode_pid=1)
[2025-07-16 14:55:39.390528] INFO [PALF] fetch_log_from_storage (palf_handle_impl.cpp:3609) [27606][T1022_FetchLog0][T1022][Y0-0000000000000000-0-0] [lt=76] [PALF STAT FETCH LOG SIZE](this={palf_id:1, self:“172.18.4.10:2882”, has_set_deleted:false}, accum_size=83886080)
[2025-07-16 14:55:39.390555] INFO [PALF] handle (fetch_log_engine.cpp:316) [27606][T1022_FetchLog0][T1022][Y0-0000000000000000-0-0] [lt=65] handle fetch log task(ret=0, palf_id=1, handle_cost_time_us=322, fetch_log_task={timestamp_us:1752648939390215, id:1, server:“172.18.4.11:2882”, fetch_type:“FETCH_LOG_FOLLOWER”, proposal_id:1, prev_lsn:{lsn:0}, start_lsn:{lsn:0}, log_size:41943040, log_count:2048, accepted_mode_pid:1}, fetch_stat={total_size:0, group_log_cnt:0, read_cost:0, get_cost:0, send_cost:0})
[2025-07-16 14:55:39.390908] INFO [PALF] read (log_cache.cpp:101) [27723][T1021_LogShared][T1021][Y0-0000000000000000-0-0] [lt=86] [PALF STAT HOT CACHE HIT RATE](palf_id=1, read_size=13748, hit_cnt=27, read_cnt=27, hit rate=1.000000000000000000e+00)
[2025-07-16 14:55:39.392940] WDIAG [PALF] next (log_iterator_impl.h:707) [27609][T1022_ReplaySrv][T1022][Y0-0000000000000000-0-0] [lt=341][errcode=-4008] there is no readable log, set next_min_scn to OB_INVALID_TIMESTAMP(ret=-4008, this={buf_:null, next_round_pread_size:3678208, curr_read_pos:0, curr_read_buf_start_pos:0, curr_read_buf_end_pos:0, log_storage_:{start_lsn:{lsn:0}, end_lsn:{lsn:0}, read_buf:{buf_len_:0, buf_:null}, block_size:67104768, log_storage_:0x7fbae2917bf0, log_storage_:{log_tail:{lsn:0}, readable_log_tail:{lsn:0}, log_block_header:{magic:18754, version:1, min_lsn:{lsn:18446744073709551615}, min_scn:{val:18446744073709551615, v:3}, curr_block_id:274894685184, palf_id:-1}, block_mgr:{log_dir:"/home/admin/data/clog/tenant_1022/1001/log", dir_fd:200, min_block_id:0, max_block_id:0, curr_writable_block_id:274894685184}, logical_block_size_:67104768, curr_block_writable_size_:0, block_header_serialize_buf_:0x7fbae29188b8, flashback_version:0}, storage_type:“DISK_STORAGE”}, curr_entry_is_raw_write:false, curr_entry_size:0, prev_entry_scn:{val:18446744073709551615, v:3}, curr_entry:{LogEntryHeader:{magic:0, version:0, log_size:-1, scn_:{val:18446744073709551615, v:3}, data_checksum:0, flag:0}}, init_mode_version:0, accumulate_checksum:-1, curr_entry_is_padding:0, padding_entry_size:0, padding_entry_scn:{val:18446744073709551615, v:3}}, info={reason:2, log_scn:{val:18446744073709551615, v:3}}, replayable_point_scn={val:1752647167112183000, v:0})
[2025-07-16 14:55:39.392939] WDIAG [PALF] next (log_iterator_impl.h:707) [27647][T1022_ReplaySrv][T1022][Y0-0000000000000000-0-0] [lt=236][errcode=-4008] there is no readable log, set next_min_scn to OB_INVALID_TIMESTAMP(ret=-4008, this={buf_:null, next_round_pread_size:3678208, curr_read_pos:0, curr_read_buf_start_pos:0, curr_read_buf_end_pos:0, log_storage_:{start_lsn:{lsn:0}, end_lsn:{lsn:0}, read_buf:{buf_len_:0, buf_:null}, block_size:67104768, log_storage_:0x7fba0aac1bf0, log_storage_:{log_tail:{lsn:0}, readable_log_tail:{lsn:0}, log_block_header:{magic:18754, version:1, min_lsn:{lsn:18446744073709551615}, min_scn:{val:18446744073709551615, v:3}, curr_block_id:274894685184, palf_id:-1}, block_mgr:{log_dir:"/home/admin/data/clog/tenant_1022/1/log", dir_fd:192, min_block_id:0, max_block_id:0, curr_writable_block_id:274894685184}, logical_block_size_:67104768, curr_block_writable_size_:0, block_header_serialize_buf_:0x7fba0aac28b8, flashback_version:0}, storage_type:“DISK_STORAGE”}, curr_entry_is_raw_write:false, curr_entry_size:0, prev_entry_scn:{val:18446744073709551615, v:3}, curr_entry:{LogEntryHeader:{magic:0, version:0, log_size:-1, scn_:{val:18446744073709551615, v:3}, data_checksum:0, flag:0}}, init_mode_version:0, accumulate_checksum:-1, curr_entry_is_padding:0, padding_entry_size:0, padding_entry_scn:{val:18446744073709551615, v:3}}, info={reason:2, log_scn:{val:18446744073709551615, v:3}}, replayable_point_scn={val:1752647167112183000, v:0})
[2025-07-16 14:55:39.393034] INFO [CLOG] next_log (ob_replay_status.cpp:258) [27609][T1022_ReplaySrv][T1022][Y0-0000000000000000-0-0] [lt=242] next_min_scn is invalid(type_=1, replayable_point={val:1752647167112183000, v:0}, next_min_scn={val:18446744073709551615, v:3}, next_to_submit_scn_={val:0, v:0}, ret=0, iterator_={iterator_impl:{buf_:null, next_round_pread_size:3678208, curr_read_pos:0, curr_read_buf_start_pos:0, curr_read_buf_end_pos:0, log_storage_:{start_lsn:{lsn:0}, end_lsn:{lsn:0}, read_buf:{buf_len_:0, buf_:null}, block_size:67104768, log_storage_:0x7fbae2917bf0, log_storage_:{log_tail:{lsn:0}, readable_log_tail:{lsn:0}, log_block_header:{magic:18754, version:1, min_lsn:{lsn:18446744073709551615}, min_scn:{val:18446744073709551615, v:3}, curr_block_id:274894685184, palf_id:-1}, block_mgr:{log_dir:"/home/admin/data/clog/tenant_1022/1001/log", dir_fd:200, min_block_id:0, max_block_id:0, curr_writable_block_id:274894685184}, logical_block_size_:67104768, curr_block_writable_size_:0, block_header_serialize_buf_:0x7fbae29188b8, flashback_version:0}, storage_type:“DISK_STORAGE”}, curr_entry_is_raw_write:false, curr_entry_size:0, prev_entry_scn:{val:18446744073709551615, v:3}, curr_entry:{LogEntryHeader:{magic:0, version:0, log_size:-1, scn_:{val:18446744073709551615, v:3}, data_checksum:0, flag:0}}, init_mode_version:0, accumulate_checksum:-1, curr_entry_is_padding:0, padding_entry_size:0, padding_entry_scn:{val:18446744073709551615, v:3}}, io_ctx:{user:“REPLAY”, palf_id:1001, iterator_info:{allow_filling_cache:false, hot_cache_stat:{hit_cnt:0, miss_cnt:0, cache_read_size:0, hit_ratio:“0.000000000000000000e+00”}, cold_cache_stat:{hit_cnt:0, miss_cnt:0, cache_read_size:0, hit_ratio:“0.000000000000000000e+00”}, read_io_cnt:0, read_io_size:0, read_disk_cost_ts:0, start_lsn:{lsn:0}}}})
[2025-07-16 14:55:39.393036] INFO [CLOG] next_log (ob_replay_status.cpp:258) [27647][T1022_ReplaySrv][T1022][Y0-0000000000000000-0-0] [lt=252] next_min_scn is invalid(type_=1, replayable_point={val:1752647167112183000, v:0}, next_min_scn={val:18446744073709551615, v:3}, next_to_submit_scn_={val:0, v:0}, ret=0, iterator_={iterator_impl:{buf_:null, next_round_pread_size:3678208, curr_read_pos:0, curr_read_buf_start_pos:0, curr_read_buf_end_pos:0, log_storage_:{start_lsn:{lsn:0}, end_lsn:{lsn:0}, read_buf:{buf_len_:0, buf_:null}, block_size:67104768, log_storage_:0x7fba0aac1bf0, log_storage_:{log_tail:{lsn:0}, readable_log_tail:{lsn:0}, log_block_header:{magic:18754, version:1, min_lsn:{lsn:18446744073709551615}, min_scn:{val:18446744073709551615, v:3}, curr_block_id:274894685184, palf_id:-1}, block_mgr:{log_dir:"/home/admin/data/clog/tenant_1022/1/log", dir_fd:192, min_block_id:0, max_block_id:0, curr_writable_block_id:274894685184}, logical_block_size_:67104768, curr_block_writable_size_:0, block_header_serialize_buf_:0x7fba0aac28b8, flashback_version:0}, storage_type:“DISK_STORAGE”}, curr_entry_is_raw_write:false, curr_entry_size:0, prev_entry_scn:{val:18446744073709551615, v:3}, curr_entry:{LogEntryHeader:{magic:0, version:0, log_size:-1, scn_:{val:18446744073709551615, v:3}, data_checksum:0, flag:0}}, init_mode_version:0, accumulate_checksum:-1, curr_entry_is_padding:0, padding_entry_size:0, padding_entry_scn:{val:18446744073709551615, v:3}}, io_ctx:{user:“REPLAY”, palf_id:1, iterator_info:{allow_filling_cache:false, hot_cache_stat:{hit_cnt:0, miss_cnt:0, cache_read_size:0, hit_ratio:“0.000000000000000000e+00”}, cold_cache_stat:{hit_cnt:0, miss_cnt:0, cache_read_size:0, hit_ratio:“0.000000000000000000e+00”}, read_io_cnt:0, read_io_size:0, read_disk_cost_ts:0, start_lsn:{lsn:0}}}})
[2025-07-16 14:55:39.397231] INFO [STORAGE.TRANS] check_all_readonly_tx_clean_up (ob_ls_tx_service.cpp:356) [19294][T1020_TxLoopWor][T1020][Y0-0000000000000000-0-0] [lt=56] wait_all_readonly_tx_cleaned_up cleaned up success(ls_id={id:1})
[2025-07-16 14:55:39.397298] INFO [STORAGE.TRANS] check_all_readonly_tx_clean_up (ob_ls_tx_service.cpp:356) [19294][T1020_TxLoopWor][T1020][Y0-0000000000000000-0-0] [lt=65] wait_all_readonly_tx_cleaned_up cleaned up success(ls_id={id:1001})
[2025-07-16 14:55:39.397589] WDIAG [STORAGE.TRANS] run1 (ob_standby_timestamp_service.cpp:141) [19285][T1020_STSWorker][T1020][Y0-0000000000000000-0-0] [lt=35][errcode=-4076] query and update last id fail(ret=-4076, ret=“OB_NEED_WAIT”)
[2025-07-16 14:55:39.398779] WDIAG pop_task (ob_timer_service.cpp:565) [9052][TimerSvr][T0][Y0-0000000000000000-0-0] [lt=67][errcode=-4389] timer task too much delay because the same timer has another running task(token={this:0x7fbb8376a3b8, timer:0x7fbb836e6f80, task:0x55cc1e8bfc48, task_type:“N9oceanbase5share17ObServerTraceTaskE”, scheduled_time:1752648938361575, pushed_time:0, delay:8000000}, running_task_token={this:0x7fbb8376ab98, timer:0x7fbb836e6f80, task:0x55cc1e8c1868, task_type:“N9oceanbase8observer16ObTenantDutyTaskE”, scheduled_time:1752648938208740, pushed_time:1752648938208777, delay:10000000}, total_delay=1037203, threashold=1000000, tenant_id=500)
[2025-07-16 14:55:39.399075] INFO [COMMON] compute_tenant_wash_size (ob_kvcache_store.cpp:1464) [9051][TimerWK3_KVCacheWash][T0][Y0-0000000000000000-0-0] [lt=127] Wash compute wash size(is_wash_valid=false, sys_total_wash_size=-2064404480, global_cache_size=1539768320, tenant_max_wash_size=0, tenant_min_wash_size=0, tenant_ids_=[500, 508, 509, 1, 1019, 1020, 1021, 1022])
[2025-07-16 14:55:39.399372] INFO [COMMON] wash (ob_kvcache_hazard_domain.h:326) [9051][TimerWK3_KVCacheWash][T0][Y0-0000000000000000-0-0] [lt=109] allocator wash time (wash_time_us=16, freed_blocks_num=0, memory_efficiency=9.849866445611126231e-01)
[2025-07-16 14:55:39.400862] INFO [SQL.EXE] end_stmt (ob_sql_trans_control.cpp:1531) [9050][TimerWK2_SqlMemTimer][T1022][YB42AC12040A-000639F43D7ED9A1-0-0] [lt=4] end stmt(ret=0, tx_id=0, plain_select=true, stmt_type=1, savepoint=0, tx_desc={this:0x7fbb17f0ba60, tx_id:{txid:0}, state:1, addr:“172.18.4.10:2882”, tenant_id:1022, session_id:3221575605, assoc_session_id:3221575605, client_sid:3221575605, xid:NULL, xa_mode:"", xa_start_addr:“0.0.0.0:0”, access_mode:-1, tx_consistency_type:0, isolation:-1, snapshot_version:{val:18446744073709551615, v:3}, snapshot_scn:0, active_scn:0, op_sn:1, alloc_ts:1752648939365604, active_ts:-1, commit_ts:-1, finish_ts:-1, timeout_us:-1, lock_timeout_us:-1, expire_ts:9223372036854775807, coord_id:{id:-1}, parts:[], exec_info_reap_ts:0, commit_version:{val:18446744073709551615, v:3}, commit_times:0, commit_cb:null, cluster_id:-1, cluster_version:17180067074, seq_base:1752648939365603, flags_.SHADOW:true, flags_.INTERRUPTED:false, flags_.BLOCK:false, flags_.REPLICA:false, conflict_txs:[], abort_cause:0, commit_expire_ts:-1, commit_task_.is_registered():false, modified_tables:[], last_rc_snapshot_version:{val:0, v:0}, ref:1}, trans_result={incomplete:false, parts:[], touched_ls_list:[], conflict_txs:[]}, rollback=true, need_rollback=true, session={this:0x7fbad14b7338, id:3221575605, deser:false, tenant:“sys”, tenant_id:1, effective_tenant:“sys”, effective_tenant_id:1022, database:“oceanbase”, user:“root@%”, consistency_level:3, session_state:2, autocommit:true, tx:0x7fbb17f0ba60}, exec_ctx.get_errcode()=-6231)
[2025-07-16 14:55:39.401268] INFO [SERVER] sleep_before_local_retry (ob_query_retry_ctrl.cpp:88) [9050][TimerWK2_SqlMemTimer][T1022][YB42AC12040A-000639F43D7ED9A1-0-0] [lt=1] will sleep(sleep_us=35000, remain_us=1378766, base_sleep_us=1000, retry_sleep_type=1, v.stmt_retry_times_=35, v.err_=-6231, timeout_timestamp=1752648940780033)
[2025-07-16 14:55:39.404778] INFO [PALF] handle (fetch_log_engine.cpp:279) [27606][T1022_FetchLog0][T1022][Y0-0000000000000000-0-0] [lt=82] handle fetch_log_task(fetch_log_task={timestamp_us:1752648939404762, id:1, server:“172.18.4.12:2882”, fetch_type:“FETCH_LOG_FOLLOWER”, proposal_id:1, prev_lsn:{lsn:0}, start_lsn:{lsn:0}, log_size:41943040, log_count:2048, accepted_mode_pid:1})
[2025-07-16 14:55:39.404772] INFO [PALF] get_log (palf_handle_impl.cpp:4116) [4199][T1022_L0_G1][T1022][YB42AC12040C-000639F557B3366A-0-0] [lt=172] submit fetch log task success(ret=0, palf_id=1, server=“172.18.4.12:2882”, fetch_type=0, prev_lsn={lsn:0}, start_lsn={lsn:0}, fetch_log_size=41943040, fetch_log_count=2048, accepted_mode_pid=1)
[2025-07-16 14:55:39.404829] INFO [PALF] fetch_log_from_storage_ (palf_handle_impl.cpp:3703) [27606][T1022_FetchLog0][T1022][Y0-0000000000000000-0-0] [lt=115] no need fetch_log_from_storage(ret=0, this={palf_id:1, self:“172.18.4.10:2882”, has_set_deleted:false}, server=“172.18.4.12:2882”, fetch_start_lsn={lsn:0}, prev_lsn={lsn:0}, max_flushed_end_lsn={lsn:0}, access_mode=2)
[2025-07-16 14:55:39.404869] INFO [PALF] fetch_log_from_storage_ (palf_handle_impl.cpp:3827) [27606][T1022_FetchLog0][T1022][Y0-0000000000000000-0-0] [lt=102] fetch_log_from_storage_ finished(ret=0, this={palf_id:1, self:“172.18.4.10:2882”, has_set_deleted:false}, prev_lsn={lsn:0}, iterator={iterator_impl:{buf_:null, next_round_pread_size:0, curr_read_pos:0, curr_read_buf_start_pos:0, curr_read_buf_end_pos:0, log_storage_:NULL, curr_entry_is_raw_write:false, curr_entry_size:0, prev_entry_scn:{val:18446744073709551615, v:3}, curr_entry:{LogGroupEntryHeader:{magic:0, version:0, group_size:0, proposal_id:9223372036854775807, committed_lsn:{lsn:18446744073709551615}, max_scn:{val:18446744073709551615, v:3}, accumulated_checksum:0, log_id:0, flag:0}}, init_mode_version:0, accumulate_checksum:-1, curr_entry_is_padding:0, padding_entry_size:0, padding_entry_scn:{val:18446744073709551615, v:3}}, io_ctx:{user:“DEFAULT”, palf_id:0, iterator_info:{allow_filling_cache:true, hot_cache_stat:{hit_cnt:0, miss_cnt:0, cache_read_size:0, hit_ratio:“0.000000000000000000e+00”}, cold_cache_stat:{hit_cnt:0, miss_cnt:0, cache_read_size:0, hit_ratio:“0.000000000000000000e+00”}, read_io_cnt:0, read_io_size:0, read_disk_cost_ts:0, start_lsn:{lsn:18446744073709551615}}}}, fetch_log_count=2048, has_fetched_log_count=0)
[2025-07-16 14:55:39.404951] WDIAG [PALF] try_send_committed_info_ (palf_handle_impl.cpp:3626) [27606][T1022_FetchLog0][T1022][Y0-0000000000000000-0-0] [lt=214][errcode=-4002] invalid arguments(ret=-4002, this={palf_id:1, self:“172.18.4.10:2882”, has_set_deleted:false}, server=“172.18.4.12:2882”, log_lsn={lsn:0}, log_end_lsn={lsn:0}, log_proposal_id=9223372036854775807)
[2025-07-16 14:55:39.405007] INFO [PALF] submit_fetch_mode_meta_resp (log_mode_mgr.cpp:824) [27606][T1022_FetchLog0][T1022][Y0-0000000000000000-0-0] [lt=70] submit_change_mode_meta_req success(ret=0, palf_id=1, server=“172.18.4.12:2882”, mode_meta={version:1, proposal_id:1, mode_version:0, access_mode:2, ref_scn:{val:1, v:0}}, accepted_mode_pid=1)
[2025-07-16 14:55:39.405985] INFO [SQL.EXE] end_stmt (ob_sql_trans_control.cpp:1531) [4294][T1022_TimerWK4_ReqMemEvict][T1022][YB42AC12040A-000639F8FD0C6036-0-0] [lt=6] end stmt(ret=0, tx_id=0, plain_select=true, stmt_type=1, savepoint=0, tx_desc={this:0x7fbb400eb460, tx_id:{txid:0}, state:1, addr:“172.18.4.10:2882”, tenant_id:1022, session_id:3221575422, assoc_session_id:3221575422, client_sid:3221575422, xid:NULL, xa_mode:"", xa_start_addr:“0.0.0.0:0”, access_mode:-1, tx_consistency_type:0, isolation:-1, snapshot_version:{val:18446744073709551615, v:3}, snapshot_scn:0, active_scn:0, op_sn:1, alloc_ts:1752648939356067, active_ts:-1, commit_ts:-1, finish_ts:-1, timeout_us:-1, lock_timeout_us:-1, expire_ts:9223372036854775807, coord_id:{id:-1}, parts:[], exec_info_reap_ts:0, commit_version:{val:18446744073709551615, v:3}, commit_times:0, commit_cb:null, cluster_id:-1, cluster_version:17180067074, seq_base:1752648939356068, flags_.SHADOW:true, flags_.INTERRUPTED:false, flags_.BLOCK:false, flags_.REPLICA:false, conflict_txs:[], abort_cause:0, commit_expire_ts:-1, commit_task_.is_registered():false, modified_tables:[], last_rc_snapshot_version:{val:0, v:0}, ref:1}, trans_result={incomplete:false, parts:[], touched_ls_list:[], conflict_txs:[]}, rollback=true, need_rollback=true, session={this:0x7fbad14a41f8, id:3221575422, deser:false, tenant:“sys”, tenant_id:1, effective_tenant:“sys”, effective_tenant_id:1022, database:“oceanbase”, user:“root@%”, consistency_level:3, session_state:2, autocommit:true, tx:0x7fbb400eb460}, exec_ctx.get_errcode()=-6231)
[2025-07-16 14:55:39.406219] INFO [SERVER] runTimerTask (ob_eliminate_task.cpp:225) [27712][T1021_TimerWK2_ReqMemEvict][T1021][Y0-0000000000000000-0-0] [lt=95] sql audit evict task end(request_manager_->get_tenant_id()=1021, evict_high_mem_level=16106127, evict_high_size_level=471859, evict_batch_count=0, elapse_time=0, size_used=0, mem_used=12478464)
[2025-07-16 14:55:39.406304] INFO [SERVER] prepare_alloc_queue (ob_dl_queue.cpp:92) [27713][T1021_TimerWK3_ReqMemEvict][T1021][Y0-0000000000000000-0-0] [lt=94] Construct Queue Num(construct_num=0, get_push_idx()=11, get_cur_idx()=3, get_pop_idx()=3)
[2025-07-16 14:55:39.406433] INFO [SERVER] sleep_before_local_retry (ob_query_retry_ctrl.cpp:88) [4294][T1022_TimerWK4_ReqMemEvict][T1022][YB42AC12040A-000639F8FD0C6036-0-0] [lt=1] will sleep(sleep_us=50000, remain_us=737432, base_sleep_us=1000, retry_sleep_type=1, v.stmt_retry_times_=50, v.err_=-6231, timeout_timestamp=1752648940143863)
[2025-07-16 14:55:39.409485] INFO [COMMON] replace_map (ob_kv_storecache.cpp:694) [9049][TimerWK1_KVCacheRep][T0][Y0-0000000000000000-0-0] [lt=96] replace map num details(ret=0, replace_node_count=0, map_once_replace_num_=31457, map_replace_skip_count_=4)
[2025-07-16 14:55:39.419610] INFO [STORAGE.BLKMGR] runTimerTask (ob_block_manager.cpp:1649) [9051][TimerWK3_BlkMgr][T0][Y0-0000000000000000-0-0] [lt=100] skip inspect bad block(last_check_time=1752570997962348, last_macro_idx=-1)
[2025-07-16 14:55:39.423126] INFO [CLOG] run1 (ob_garbage_collector.cpp:1449) [27732][T1021_GCCollect][T1021][Y0-0000000000000000-0-0] [lt=58] Garbage Collector is running(seq_=113, gc_interval=10000000)
[2025-07-16 14:55:39.423180] INFO [CLOG] construct_server_ls_map_for_member_list_ (ob_garbage_collector.cpp:1584) [27732][T1021_GCCollect][T1021][Y0-0000000000000000-0-0] [lt=85] self is leader, skip it(ls->get_ls_id()={id:1})
[2025-07-16 14:55:39.423212] INFO [CLOG] gc_check_member_list_ (ob_garbage_collector.cpp:1542) [27732][T1021_GCCollect][T1021][Y0-0000000000000000-0-0] [lt=55] gc_check_member_list_ cost time(ret=0, time_us=54)
[2025-07-16 14:55:39.423236] INFO [CLOG] execute_gc_ (ob_garbage_collector.cpp:1854) [27732][T1021_GCCollect][T1021][Y0-0000000000000000-0-0] [lt=47] execute_gc cost time(ret=0, time_us=1)
[2025-07-16 14:55:39.423244] INFO [SQL.EXE] end_stmt (ob_sql_trans_control.cpp:1531) [9048][TimerWK0_ServerGTimer][T1022][YB42AC12040A-000639F43CEECB64-0-0] [lt=4] end stmt(ret=0, tx_id=0, plain_select=true, stmt_type=1, savepoint=0, tx_desc={this:0x7fbb3ae08a60, tx_id:{txid:0}, state:1, addr:“172.18.4.10:2882”, tenant_id:1022, session_id:1, assoc_session_id:1, client_sid:1, xid:NULL, xa_mode:"", xa_start_addr:“0.0.0.0:0”, access_mode:-1, tx_consistency_type:0, isolation:-1, snapshot_version:{val:18446744073709551615, v:3}, snapshot_scn:0, active_scn:0, op_sn:1, alloc_ts:1752648939374042, active_ts:-1, commit_ts:-1, finish_ts:-1, timeout_us:-1, lock_timeout_us:-1, expire_ts:9223372036854775807, coord_id:{id:-1}, parts:[], exec_info_reap_ts:0, commit_version:{val:18446744073709551615, v:3}, commit_times:0, commit_cb:null, cluster_id:-1, cluster_version:17180067074, seq_base:1752648939374041, flags_.SHADOW:true, flags_.INTERRUPTED:false, flags_.BLOCK:false, flags_.REPLICA:false, conflict_txs:[], abort_cause:0, commit_expire_ts:-1, commit_task_.is_registered():false, modified_tables:[], last_rc_snapshot_version:{val:0, v:0}, ref:1}, trans_result={incomplete:false, parts:[], touched_ls_list:[], conflict_txs:[]}, rollback=true, need_rollback=true, session={this:0x7fbb0be54038, id:1, deser:false, tenant:“sys”, tenant_id:1, effective_tenant:“sys”, effective_tenant_id:1022, database:“oceanbase”, user:“root@%”, consistency_level:3, session_state:0, autocommit:true, tx:0x7fbb3ae08a60}, exec_ctx.get_errcode()=-6231)
[2025-07-16 14:55:39.423396] INFO [STORAGE.TRANS] check_all_readonly_tx_clean_up (ob_ls_tx_service.cpp:356) [9363][T1_TxLoopWorker][T1][Y0-0000000000000000-0-0] [lt=87] wait_all_readonly_tx_cleaned_up cleaned up success(ls_id={id:1})
[2025-07-16 14:55:39.423604] INFO [SERVER] sleep_before_local_retry (ob_query_retry_ctrl.cpp:88) [9048][TimerWK0_ServerGTimer][T1022][YB42AC12040A-000639F43CEECB64-0-0] [lt=2] will sleep(sleep_us=49000, remain_us=785692, base_sleep_us=1000, retry_sleep_type=1, v.stmt_retry_times_=49, v.err_=-6231, timeout_timestamp=1752648940209295)
[2025-07-16 14:55:39.425931] INFO [CLOG] gc_check_ls_status_ (ob_garbage_collector.cpp:1776) [27732][T1021_GCCollect][T1021][Y0-0000000000000000-0-0] [lt=31] gc_candidates push_back success(ret=0, candidate={ls_id_:{id:1}, ls_status_:1, gc_reason_:0})
[2025-07-16 14:55:39.425974] INFO [CLOG] execute_gc_ (ob_garbage_collector.cpp:1798) [27732][T1021_GCCollect][T1021][Y0-0000000000000000-0-0] [lt=93] ls status is normal, skip(id={id:1}, gc_candidates=[{ls_id_:{id:1}, ls_status_:1, gc_reason_:0}])
[2025-07-16 14:55:39.425997] INFO [CLOG] execute_gc_ (ob_garbage_collector.cpp:1854) [27732][T1021_GCCollect][T1021][Y0-0000000000000000-0-0] [lt=56] execute_gc cost time(ret=0, time_us=25)
[2025-07-16 14:55:39.426020] INFO [SERVER] handle (ob_safe_destroy_handler.cpp:240) [27732][T1021_GCCollect][T1021][Y0-0000000000000000-0-0] [lt=53] ObSafeDestroyHandler start process
[2025-07-16 14:55:39.426653] INFO [STORAGE] gc_tables_in_queue (ob_tenant_meta_mem_mgr.cpp:613) [19366][T1019_TimerWK1_TenantMetaMemMg][T1019][Y0-0000000000000000-0-0] [lt=99] gc tables in queue: recycle 0 table(ret=0, tablet_buffer_pool_={typeid(T).name():“N9oceanbase7storage15ObMetaObjBufferINS0_8ObTabletELl3784EEE”, sizeof(T):3816, used_obj_cnt:946, free_obj_hold_cnt:90, allocator used:3978240, allocator total:4243200}, large_tablet_buffer_pool_={typeid(T).name():“N9oceanbase7storage15ObMetaObjBufferINS0_8ObTabletELl65448EEE”, sizeof(T):65480, used_obj_cnt:90, free_obj_hold_cnt:1, allocator used:5968781, allocator total:5968781}, full_tablet_creator_={tiny_allocator_.used():0, tiny_allocator_.total():186496, full allocator used:1664, full allocator total:252032}, tablets_mem=10464013, tablets_mem_limit=214748360, ddl_kv_pool_={typeid(T).name():“N9oceanbase7storage7ObDDLKVE”, sizeof(T):1024, used_obj_cnt:0, free_obj_hold_cnt:0, allocator used:0, allocator total:0}, memtable_pool_={typeid(T).name():“N9oceanbase8memtable10ObMemtableE”, sizeof(T):1984, used_obj_cnt:31, free_obj_hold_cnt:64, allocator used:194560, allocator total:261120}, pending_cnt=0, wait_gc_count=0, tablet count=1036)
有大佬帮忙看看吗
表级恢复的流程是数据库先创建一个辅助租户把源租户的所有对象恢复到辅助租户中，当辅助租户恢复完成之后，会把对应表的数据导出，然后导入到真正要恢复的租户中，最终辅助租户会被删除，如果源租户的数据量很大的话，这个恢复过程是很慢的
我昨天5点左右也同样执行过一次表级恢复，也是1000条数据的小表，到第二天9点多，仍然没有恢复完成
你的辅助租户还没恢复完成呢，需要等待辅助租户恢复完成，可以尝试恢复整个租户的数据，恢复的时候给的资源稍微大一点，这样更节省时间
租户级恢复也尝试过，也是一直卡着，这个租户的数据量不大，因为我才刚建出来，备份整个租户的话用时4分钟左右。
如果是租户级别的恢复 查询这个视图 CDB_OB_RESTORE_PROGRESS 如果是表级别恢复查询下这个视图CDB_OB_RECOVER_TABLE_JOBS，看下查询结果是什么
[2025-07-16 14:55:39.385127] WDIAG [RPC] wait (ob_async_rpc_proxy.h:454) [27562][T1022_TeRec][T1022][YB42AC12040A-000639F8E4FC88F0-0-0] [lt=76][errcode=0] execute rpc failed(rc=-4109, server=“172.18.4.12:2882”, timeout=1999958, packet code=1859, arg={tenant_id:1022, ls_id:{id:1}, all_replica:false}, ret=0)
这个也查询下
SELECT * FROM oceanbase.CDB_OB_IMPORT_TABLE_JOBS\G;
SELECT * FROM oceanbase.CDB_OB_RECOVER_TABLE_JOB_HISTORY\G;
SELECT * FROM oceanbase.CDB_OB_RESTORE_HISTORY order by START_TIMESTAMP\G;
SELECT * FROM oceanbase.CDB_OB_IMPORT_TABLE_JOB_HISTORY\G;
SELECT * FROM oceanbase.CDB_OB_IMPORT_TABLE_TASK_HISTORY\G;