[root@dbatest-9-21 log]# cat observer.log | grep "YB42AC160915-0005FBC6D3865E0C-0-0" [root@dbatest-9-21 log]# cat observer.log | grep "YB42AC160915-0005FBC6D3865E3F-0-0" [2023-05-19 11:06:19.501284] INFO [COMMON] get_jobs (ob_physical_restore_table_operator.cpp:411) [85428][T1_REST_SER][T1][YB42AC160915-0005FBC6D3865E3F-0-0] [lt=18] [RESTORE] get restore jobs(ret=0, job_cnt=1) [2023-05-19 11:06:20.094654] INFO [SHARE] read_single_file (ob_backup_store.cpp:366) [85428][T1_REST_SER][T1][YB42AC160915-0005FBC6D3865E3F-0-0] [lt=15] succeed to read single file.(full_path=file:///backup/data/database_bak_DEMO_OMS_MYSQL_TENANT/backup_set_7_full/infos/meta_info/ls_meta_infos.obbak, serializer={ls_meta_packages:[{ls_meta:{tenant_id:1008, ls_id:{id:1}, replica_type:0, ls_create_status:1, clog_checkpoint_scn:{val:1684401715330590761}, clog_base_lsn:{lsn:469733376}, rebuild_seq:0, migration_status:0, gc_state_:1, offline_scn_:{val:18446744073709551615}, restore_status:{status:0}, replayable_point:{val:1684401718378307908}, tablet_change_checkpoint_scn:{val:1684366325810322695}, all_id_meta:{id_meta:[{limited_id:1684401732513447339, latest_log_ts:{val:1684401715866096996}}, {limited_id:3000001, latest_log_ts:{val:1684397280664370684}}, {limited_id:1, latest_log_ts:{val:18446744073709551615}}]}}, palf_meta:{prev_log_info:{log_id:1752840, lsn:{lsn:469722393}, scn:{val:1684390841573888781}, log_proposal_id:1, accum_checksum:381249287}, curr_lsn:{lsn:469733376}}}, {ls_meta:{tenant_id:1008, ls_id:{id:1001}, replica_type:0, ls_create_status:1, clog_checkpoint_scn:{val:1684401724643261976}, clog_base_lsn:{lsn:469733376}, rebuild_seq:0, migration_status:0, gc_state_:1, offline_scn_:{val:18446744073709551615}, restore_status:{status:0}, replayable_point:{val:1684401723517780288}, tablet_change_checkpoint_scn:{val:1684398780573606141}, all_id_meta:{id_meta:[{limited_id:1, latest_log_ts:{val:18446744073709551615}}, {limited_id:1, latest_log_ts:{val:18446744073709551615}}, {limited_id:1, latest_log_ts:{val:18446744073709551615}}]}}, palf_meta:{prev_log_info:{log_id:1597098, lsn:{lsn:469710288}, scn:{val:1684397320512374217}, log_proposal_id:1, accum_checksum:3773262736}, curr_lsn:{lsn:469733376}}}, {ls_meta:{tenant_id:1008, ls_id:{id:1002}, replica_type:0, ls_create_status:1, clog_checkpoint_scn:{val:1684401725678724663}, clog_base_lsn:{lsn:1878933504}, rebuild_seq:0, migration_status:0, gc_state_:1, offline_scn_:{val:18446744073709551615}, restore_status:{status:0}, replayable_point:{val:1684401726553162048}, tablet_change_checkpoint_scn:{val:1684398787107990748}, all_id_meta:{id_meta:[{limited_id:1, latest_log_ts:{val:18446744073709551615}}, {limited_id:1, latest_log_ts:{val:18446744073709551615}}, {limited_id:1, latest_log_ts:{val:18446744073709551615}}]}}, palf_meta:{prev_log_info:{log_id:1548241, lsn:{lsn:1876940066}, scn:{val:1684397462442462150}, log_proposal_id:1, accum_checksum:53310500}, curr_lsn:{lsn:1878933504}}}, {ls_meta:{tenant_id:1008, ls_id:{id:1003}, replica_type:0, ls_create_status:1, clog_checkpoint_scn:{val:1684401722457608479}, clog_base_lsn:{lsn:805257216}, rebuild_seq:0, migration_status:0, gc_state_:1, offline_scn_:{val:18446744073709551615}, restore_status:{status:0}, replayable_point:{val:1684401721458041239}, tablet_change_checkpoint_scn:{val:1684398760461431945}, all_id_meta:{id_meta:[{limited_id:1, latest_log_ts:{val:18446744073709551615}}, {limited_id:1, latest_log_ts:{val:18446744073709551615}}, {limited_id:1, latest_log_ts:{val:18446744073709551615}}]}}, palf_meta:{prev_log_info:{log_id:1831625, lsn:{lsn:805224741}, scn:{val:1684397350240536064}, log_proposal_id:1, accum_checksum:4035226127}, curr_lsn:{lsn:805257216}}}]}) [2023-05-19 11:06:20.094740] INFO [SHARE.SCHEMA] serialize_ (ob_schema_struct.cpp:1999) [85428][T1_REST_SER][T1][YB42AC160915-0005FBC6D3865E3F-0-0] [lt=10] serialize schema(tenant_id=18446744073709551615, schema_version=1, tenant_name=DEMO_OMS_MYSQL_TENANT, primary_zone=, locked=false, comment=, charset_type=2, collation_type=45, name_case_mode=-1, locality_str=, primary_zone_array=[], default_tablegroup_id=18446744073709551615, default_tablegroup_name=, drop_tenant_time=-1, in_recyclebin=false, arbitration_service_status={status:3}, ret=0) [2023-05-19 11:06:20.122390] WDIAG [RPC.OBRPC] rpc_call (ob_rpc_proxy.ipp:453) [85428][T1_REST_SER][T1][YB42AC160915-0005FBC6D3865E3F-0-0] [lt=15][errcode=-4626] execute rpc fail(ret=-4626, dst="172.22.9.21:2882") [2023-05-19 11:06:20.122407] WDIAG log_user_error_and_warn (ob_rpc_proxy.cpp:252) [85428][T1_REST_SER][T1][YB42AC160915-0005FBC6D3865E3F-0-0] [lt=17][errcode=-4626] resource pool 'DEMO_OMS_POOL' has already been granted to a tenant [2023-05-19 11:06:20.122978] INFO [STORAGE] add_memtable_ (ob_i_memtable_mgr.cpp:353) [85428][T1_REST_SER][T1][YB42AC160915-0005FBC6D3865E3F-0-0] [lt=32] succeed to add memtable(this=0x7f745c2a8480, get_memtable_count_()=1, memtable_handle={table:0x7f734d91a6d0, t3m_:0x7f74779e8030, allocator_:null, table_type_:0}) [2023-05-19 11:06:20.122998] INFO [STORAGE] create_memtable (ob_tablet_memtable_mgr.cpp:291) [85428][T1_REST_SER][T1][YB42AC160915-0005FBC6D3865E3F-0-0] [lt=20] succeed to create memtable(ret=0, ls_id={id:1}, memtable={ObITable:{this:0x7f734d91a6d0, key:{tablet_id:{id:158}, column_group_idx:0, table_type:"MEMTABLE", scn_range:{start_scn:{val:1684465545179977191}, end_scn:{val:4611686018427387903}}}, ref_cnt:2, upper_trans_version:9223372036854775807, timestamp:1684465580122976}, this:0x7f734d91a6d0, memtable_mgr:0x7f745c2a8480, timestamp:1684465580122976, state:0, freeze_clock:18, max_schema_version:0, write_ref_cnt:0, local_allocator:{ListHandle:{freeze_stat:0, id:-1, clock:9223372036854775807}, host:0x7f743e7fc030, arena_handle:{allocated:0}, last_freeze_timestamp:1684206122710034}, unsubmitted_cnt:0, unsynced_cnt:0, logging_blocked:false, unset_active_memtable_logging_blocked:false, resolve_active_memtable_left_boundary:true, contain_hotspot_row:false, max_end_scn:{val:0}, rec_scn:{val:4611686018427387903}, snapshot_version:{val:4611686018427387903}, migration_clog_checkpoint_scn:{val:0}, is_tablet_freeze:false, is_force_freeze:false, contain_hotspot_row:false, read_barrier:false, is_flushed:false, freeze_state:0, mt_stat_.frozen_time:0, mt_stat_.ready_for_flush_time:0, mt_stat_.create_flush_dag_time:0, mt_stat_.release_time:0, mt_stat_.last_print_time:0}) [2023-05-19 11:06:20.123027] INFO [STORAGE] inner_create_memtable (ob_tablet.cpp:1903) [85428][T1_REST_SER][T1][YB42AC160915-0005FBC6D3865E3F-0-0] [lt=27] succeeded to create memtable for tablet(ret=0, tablet_meta_={version:1, ls_id:{id:1}, tablet_id:{id:158}, data_tablet_id:{id:158}, ref_tablet_id:{id:0}, create_scn:{val:1683516541393675841}, start_scn:{val:1684346434461428776}, clog_checkpoint_scn:{val:1684465545179977191}, ddl_checkpoint_scn:{val:0}, snapshot_version:1684465545091903479, multi_version_start:1684463605405545066, autoinc_seq:{intervals:[]}, compat_mode:0, ha_status:{restore_status:0, data_status:0, expected_status:0, reserved:0}, report_status:{merge_snapshot_version:1684432803431405375, cur_report_version:1684432803431405375, data_checksum:0, row_count:0}, tx_data:{version:1, length:24, tx_id:{txid:0}, tx_scn:{val:1683516541509657094}, tablet_status:{status:1}, is_tx_end:false, unsynced_cnt_for_multi_data:0}, ddl_data:{redefined:false, snapshot_version:-1, schema_version:-1, data_tablet_id:{id:0}, hidden_tablet_ids:[], lob_meta_tablet_id:{id:50158}, lob_piece_tablet_id:{id:60158}, is_tx_end:false, unsynced_cnt_for_multi_data:0}, table_store_flag:{with_major_sstable:1}, ddl_start_scn:{val:0}, ddl_snapshot_version:0, max_sync_storage_schema_version:1683516542797424, max_serialized_medium_scn:1684432803431405375, ddl_execution_id:-1, ddl_data_format_version:0, ddl_commit_scn:{val:0}}, tablet_id={id:158}, clog_checkpoint_scn={val:1684465545179977191}, schema_version=0) [2023-05-19 11:06:20.123151] INFO [DETECT] maintain_deadlock_info_when_end_stmt (ob_trans_deadlock_adapter.cpp:644) [85428][T1_REST_SER][T1][YB42AC160915-0005FBC6D3865E3F-0-0] [lt=30] inner session no need register to deadlock(step=2, ret=0, ret="OB_SUCCESS", exec_ctx.get_errcode()=0, exec_ctx.get_errcode()="OB_SUCCESS", session={this:0x7f7434dd60d8, id:1, tenant:"sys", tenant_id:1, effective_tenant:"sys", effective_tenant_id:1, database:"oceanbase", user:"root@%", consistency_level:3, session_state:0, autocommit:true, tx:0x7f7392e36400}, desc=NULL, is_rollback=false, conflict_txs=[]) [2023-05-19 11:06:20.124673] INFO [SERVER] execute_write_inner (ob_inner_sql_connection.cpp:1915) [85428][T1_REST_SER][T1][YB42AC160915-0005FBC6D3865E3F-0-0] [lt=19] execute write sql(ret=0, tenant_id=1, affected_rows=1, sql=UPDATE __all_restore_job SET value = 'ROOTSERVICE : OB_RESOURCE_POOL_ALREADY_GRANTED(-4626) on "172.22.9.21:2882" with traceid YB42AC160915-0005FBC6D3865E3F-0-0' WHERE job_id = 10 AND name = 'comment') [2023-05-19 11:06:20.124715] INFO [COMMON] update_job_error_info (ob_physical_restore_table_operator.cpp:821) [85428][T1_REST_SER][T1][YB42AC160915-0005FBC6D3865E3F-0-0] [lt=15] [RESTORE] update job error info(ret=0, ret="OB_SUCCESS", job_id=10, return_ret=-4626, mod=0) [2023-05-19 11:06:20.125384] INFO [DETECT] maintain_deadlock_info_when_end_stmt (ob_trans_deadlock_adapter.cpp:644) [85428][T1_REST_SER][T1][YB42AC160915-0005FBC6D3865E3F-0-0] [lt=11] inner session no need register to deadlock(step=2, ret=0, ret="OB_SUCCESS", exec_ctx.get_errcode()=0, exec_ctx.get_errcode()="OB_SUCCESS", session={this:0x7f73c13f80d8, id:1, tenant:"sys", tenant_id:1, effective_tenant:"sys", effective_tenant_id:1, database:"oceanbase", user:"root@%", consistency_level:3, session_state:0, autocommit:true, tx:0x7f7392e954c0}, desc=NULL, is_rollback=false, conflict_txs=[]) [2023-05-19 11:06:20.126737] INFO [SERVER] execute_write_inner (ob_inner_sql_connection.cpp:1915) [85428][T1_REST_SER][T1][YB42AC160915-0005FBC6D3865E3F-0-0] [lt=26] execute write sql(ret=0, tenant_id=1, affected_rows=1, sql=UPDATE __all_restore_job SET value = 'RESTORE_FAIL' WHERE job_id = 10 AND name = 'status' AND value != 'RESTORE_FAIL') [2023-05-19 11:06:20.126779] INFO [COMMON] update_job_status (ob_physical_restore_table_operator.cpp:856) [85428][T1_REST_SER][T1][YB42AC160915-0005FBC6D3865E3F-0-0] [lt=17] [RESTORE] update job status(ret=0, job_id=10, status=7) [2023-05-19 11:06:20.126836] INFO [SHARE] add_event (ob_event_history_table_operator.h:268) [85428][T1_REST_SER][T1][YB42AC160915-0005FBC6D3865E3F-0-0] [lt=26] event table add task(ret=0, event_table_name="__all_rootservice_event_history", sql=INSERT INTO __all_rootservice_event_history (gmt_create, module, event, name1, value1, name2, value2, name3, value3, rs_svr_ip, rs_svr_port) VALUES (usec_to_time(1684465580126816), 'physical_restore', 'change_restore_status', 'job_id', 10, 'tenant', 'DEMO_OMS_MYSQL_TENANT', 'status', 'RESTORE_FAIL', '172.22.9.21', 2882)) [2023-05-19 11:06:20.128241] INFO [SERVER] execute_write_inner (ob_inner_sql_connection.cpp:1915) [85428][T1_REST_SER][T1][YB42AC160915-0005FBC6D3865E40-0-0] [lt=14] execute write sql(ret=0, tenant_id=1, affected_rows=1, sql=INSERT INTO __all_restore_job_history (tenant_id, job_id, start_time, finish_time, initiator_job_id, initiator_tenant_id, restore_type, restore_tenant_name, backup_tenant_name, backup_cluster_name, restore_tenant_id, backup_tenant_id, backup_dest, restore_scn, restore_option, table_list, remap_table_list, database_list, remap_database_list, backup_piece_list, backup_set_list, backup_cluster_version, ls_count, finish_ls_count, tablet_count, finish_tablet_count, total_bytes, finish_bytes, status, description, comment) VALUES (1, 10, usec_to_time(1684465540471411), usec_to_time(1684465580127637), -1, 1, '{type:2}', 'DEMO_OMS_MYSQL_TENANT', 'DEMO_OMS_MYSQL_TENANT', 'obcluster', 0, 1008, 'file:///backup/data/database_bak_DEMO_OMS_MYSQL_TENANT,file:///backup/data/archive_DEMO_OMS_MYSQL_TENANT', 1684461049592943425, 'pool_list=DEMO_OMS_POOL', NULL, NULL, NULL, NULL, 'file:///backup/data/archive_DEMO_OMS_MYSQL_TENANT/piece_d1005r3p3', 'file:///backup/data/database_bak_DEMO_OMS_MYSQL_TENANT/backup_set_7_full', 17179934720, 0, 0, 0, 0, 0, 0, 'FAIL', NULL, 'ROOTSERVICE : OB_RESOURCE_POOL_ALREADY_GRANTED(-4626) on "172.22.9.21:2882" with traceid YB42AC160915-0005FBC6D3865E3F-0-0')) [2023-05-19 11:06:20.128253] INFO [SHARE] do_insert_row_ (ob_inner_table_operator.cpp:648) [85428][T1_REST_SER][T1][YB42AC160915-0005FBC6D3865E40-0-0] [lt=7] insert one row(row={key:{tenant_id:1, job_id:10}, start_time:1684465540471411, finish_time:1684465580127637, restore_type:{type:2}, restore_tenant_name:"DEMO_OMS_MYSQL_TENANT", restore_tenant_id:0, backup_tenant_id:1008, backup_dest:file:///backup/data/database_bak_DEMO_OMS_MYSQL_TENANT,file:///backup/data/archive_DEMO_OMS_MYSQL_TENANT, restore_scn:{val:1684461049592943425}, restore_option:pool_list=DEMO_OMS_POOL, table_list:, remap_table_list:, database_list:, remap_database_list:, backup_piece_list:file:///backup/data/archive_DEMO_OMS_MYSQL_TENANT/piece_d1005r3p3, backup_set_list:file:///backup/data/database_bak_DEMO_OMS_MYSQL_TENANT/backup_set_7_full, backup_cluster_version:17179934720, ls_count:0, finish_ls_count:0, tablet_count:0, finish_tablet_count:0, total_bytes:0, finish_bytes:0, status:1, description:, comment:ROOTSERVICE : OB_RESOURCE_POOL_ALREADY_GRANTED(-4626) on "172.22.9.21:2882" with traceid YB42AC160915-0005FBC6D3865E3F-0-0, initiator_job_id:-1, initiator_tenant_id:1}, affected_rows=1, sql=INSERT INTO __all_restore_job_history (tenant_id, job_id, start_time, finish_time, initiator_job_id, initiator_tenant_id, restore_type, restore_tenant_name, backup_tenant_name, backup_cluster_name, restore_tenant_id, backup_tenant_id, backup_dest, restore_scn, restore_option, table_list, remap_table_list, database_list, remap_database_list, backup_piece_list, backup_set_list, backup_cluster_version, ls_count, finish_ls_count, tablet_count, finish_tablet_count, total_bytes, finish_bytes, status, description, comment) VALUES (1, 10, usec_to_time(1684465540471411), usec_to_time(1684465580127637), -1, 1, '{type:2}', 'DEMO_OMS_MYSQL_TENANT', 'DEMO_OMS_MYSQL_TENANT', 'obcluster', 0, 1008, 'file:///backup/data/database_bak_DEMO_OMS_MYSQL_TENANT,file:///backup/data/archive_DEMO_OMS_MYSQL_TENANT', 1684461049592943425, 'pool_list=DEMO_OMS_POOL', NULL, NULL, NULL, NULL, 'file:///backup/data/archive_DEMO_OMS_MYSQL_TENANT/piece_d1005r3p3', 'file:///backup/data/database_bak_DEMO_OMS_MYSQL_TENANT/backup_set_7_full', 17179934720, 0, 0, 0, 0, 0, 0, 'FAIL', NULL, 'ROOTSERVICE : OB_RESOURCE_POOL_ALREADY_GRANTED(-4626) on "172.22.9.21:2882" with traceid YB42AC160915-0005FBC6D3865E3F-0-0')) [root@dbatest-9-21 log]# [root@dbatest-9-21 log]# [root@dbatest-9-21 log]# [root@dbatest-9-21 log]#