2024-12-06 17:36:47.871375] ERROR handle_timeout (ob_trans_part_ctx.cpp:530) [67014][T1002_TransTime][T1002][YB420AC99C37-00060590F00840E2-0-0] [lt=40][errcode=-6281] Transaction commit cost too much(msg="transaction commit cost too much time", ret=-6281, *this={this:0x7fd98b440050, trans_id:{txid:917977065}, tenant_id:1002, is_exiting:false, trans_expired_time:1732047851456372, cluster_version:17180000256, trans_need_wait_wrap:{receive_gts_ts_:[mts=0], need_wait_interval_us:0}, stc:[mts=1732047251460550], ctx_create_time:1732047251456372}{ls_id:{id:1001}, session_id:3221997806, part_trans_action:3, pending_write:0, exec_info:{state:10, upstream:{id:1001}, participants:[{id:1001}, {id:1003}, {id:1002}], incremental_participants:[], prev_record_lsn:{lsn:18446744073709551615}, redo_lsns:[{lsn:432925964585}], redo_log_no:1, multi_data_source:[], scheduler:"10.201.156.55:2882", prepare_version:{val:18446744073709551615, v:3}, trans_type:2, next_log_entry_no:1, max_applied_log_ts:{val:18446744073709551615, v:3}, max_applying_log_ts:{val:18446744073709551615, v:3}, max_applying_part_log_no:9223372036854775807, max_submitted_seq_no:1732047251457508, checksum:0, checksum_scn:{val:0, v:0}, max_durable_lsn:{lsn:18446744073709551615}, data_complete:false, is_dup_tx:false, prepare_log_info_arr:[], xid:{gtrid_str:"", bqual_str:"", format_id:1, gtrid_str_.ptr():"data_size:0, data:", bqual_str_.ptr():"data_size:0, data:", g_hv:0, b_hv:0}, need_checksum:true, is_sub2pc:false}, sub_state:{flag:4}, is_leaf():false, is_root():true, busy_cbs_.get_size():1, final_log_cb_:{ObTxBaseLogCb:{log_ts:{val:18446744073709551615, v:3}, lsn:{lsn:18446744073709551615}, submit_ts:0}, this:0x7fd98b442e60, is_inited_:true, trans_id:{txid:917977065}, ls_id:{id:1001}, ctx:0x7fd98b440050, tx_data_guard:{tx_data:NULL}, is_callbacked_:false, is_dynamic_:false, mds_range_:{range_array_.count():0, range_array_:[]}, cb_arg_array_:[], first_part_scn_:{val:18446744073709551615, v:3}}, ctx_tx_data_:{ctx_mgr_:0x7fd97de86030, tx_data_guard_:{tx_data:{tx_id:{txid:917977065}, ref_cnt:1, state:"RUNNING", commit_version:{val:18446744073709551615, v:3}, start_scn:{val:1732025981932801105, v:0}, end_scn:{val:18446744073709551615, v:3}, undo_status_list:{head:null, undo_node_cnt:0{}}}}, read_only_:false}, role_state_:0, start_replay_ts_:{val:18446744073709551615, v:3}, start_recover_ts_:{val:18446744073709551615, v:3}, is_incomplete_replay_ctx_:false, mt_ctx_:{ObIMvccCtx={alloc_type=0 ctx_descriptor=0 min_table_version=0 max_table_version=1732018598571640 trans_version={val:4611686018427387903, v:0} commit_version={val:0, v:0} lock_wait_start_ts=0 replay_compact_version={val:0, v:0}} end_code=0 tx_status=0 is_readonly=false ref=0 trans_id={txid:917977065} ls_id=1001 callback_alloc_count=323 callback_free_count=0 checksum=0 tmp_checksum=0 checksum_scn={val:0, v:0} redo_filled_count=195 redo_sync_succ_count=0 redo_sync_fail_count=0 main_list_length=333 unsynced_cnt=323 unsubmitted_cnt_=132 cb_statistics:[main=333, slave=0, merge=0, tx_end=0, rollback_to=0, fast_commit=0, remove_memtable=0]}, coord_prepare_info_arr_:[], upstream_state:30, retain_cause:-1, 2pc_role:0, collected:[], ref:4, rec_log_ts:{val:1732025981932801105, v:0}, prev_rec_log_ts:{val:18446744073709551615, v:3}, lastest_snapshot:{val:18446744073709551615, v:3}, state_info_array:[], last_request_ts:1732047251459538}) [2024-12-06 17:36:47.871424] ERROR handle_timeout (ob_trans_part_ctx.cpp:530) [67014][T1002_TransTime][T1002][YB420AC99C37-00060590F00840E2-0-0] [lt=43][errcode=-6281] Transaction commit cost too much(msg="transaction commit cost too much time", ret=-6281, *this={this:0x7fd9201a2050, trans_id:{txid:915829280}, tenant_id:1002, is_exiting:false, trans_expired_time:1732039154784800, cluster_version:17180000256, trans_need_wait_wrap:{receive_gts_ts_:[mts=0], need_wait_interval_us:0}, stc:[mts=1732038554786238], ctx_create_time:1732038554784800}{ls_id:{id:1001}, session_id:3221883625, part_trans_action:3, pending_write:0, exec_info:{state:10, upstream:{id:1001}, participants:[{id:1001}, {id:1002}, {id:1003}], incremental_participants:[], prev_record_lsn:{lsn:18446744073709551615}, redo_lsns:[], redo_log_no:0, multi_data_source:[], scheduler:"10.201.156.55:2882", prepare_version:{val:18446744073709551615, v:3}, trans_type:2, next_log_entry_no:0, max_applied_log_ts:{val:18446744073709551615, v:3}, max_applying_log_ts:{val:18446744073709551615, v:3}, max_applying_part_log_no:9223372036854775807, max_submitted_seq_no:0, checksum:0, checksum_scn:{val:0, v:0}, max_durable_lsn:{lsn:18446744073709551615}, data_complete:false, is_dup_tx:false, prepare_log_info_arr:[], xid:{gtrid_str:"", bqual_str:"", format_id:1, gtrid_str_.ptr():"data_size:0, data:", bqual_str_.ptr():"data_size:0, data:", g_hv:0, b_hv:0}, need_checksum:true, is_sub2pc:false}, sub_state:{flag:4}, is_leaf():false, is_root():true, busy_cbs_.get_size():0, final_log_cb_:{ObTxBaseLogCb:{log_ts:{val:18446744073709551615, v:3}, lsn:{lsn:18446744073709551615}, submit_ts:0}, this:0x7fd9201a4e60, is_inited_:true, trans_id:{txid:915829280}, ls_id:{id:1001}, ctx:0x7fd9201a2050, tx_data_guard:{tx_data:NULL}, is_callbacked_:false, is_dynamic_:false, mds_range_:{range_array_.count():0, range_array_:[]}, cb_arg_array_:[], first_part_scn_:{val:18446744073709551615, v:3}}, ctx_tx_data_:{ctx_mgr_:0x7fd97de86030, tx_data_guard_:{tx_data:{tx_id:{txid:915829280}, ref_cnt:1, state:"RUNNING", commit_version:{val:18446744073709551615, v:3}, start_scn:{val:18446744073709551615, v:3}, end_scn:{val:18446744073709551615, v:3}, undo_status_list:{head:null, undo_node_cnt:0{}}}}, read_only_:false}, role_state_:0, start_replay_ts_:{val:18446744073709551615, v:3}, start_recover_ts_:{val:18446744073709551615, v:3}, is_incomplete_replay_ctx_:false, mt_ctx_:{ObIMvccCtx={alloc_type=0 ctx_descriptor=0 min_table_version=0 max_table_version=1732018598571640 trans_version={val:4611686018427387903, v:0} commit_version={val:0, v:0} lock_wait_start_ts=0 replay_compact_version={val:0, v:0}} end_code=0 tx_status=0 is_readonly=false ref=0 trans_id={txid:915829280} ls_id=1001 callback_alloc_count=57 callback_free_count=0 checksum=0 tmp_checksum=0 checksum_scn={val:0, v:0} redo_filled_count=0 redo_sync_succ_count=0 redo_sync_fail_count=0 main_list_length=67 unsynced_cnt=57 unsubmitted_cnt_=57 cb_statistics:[main=67, slave=0, merge=0, tx_end=0, rollback_to=0, fast_commit=0, remove_memtable=0]}, coord_prepare_info_arr_:[], upstream_state:30, retain_cause:-1, 2pc_role:0, collected:[], ref:3, rec_log_ts:{val:18446744073709551615, v:3}, prev_rec_log_ts:{val:18446744073709551615, v:3}, lastest_snapshot:{val:18446744073709551615, v:3}, state_info_array:[], last_request_ts:1732038554785855}) [2024-12-06 17:36:47.871470] ERROR handle_timeout (ob_trans_part_ctx.cpp:530) [67014][T1002_TransTime][T1002][YB420AC99C37-00060590F00840E2-0-0] [lt=40][errcode=-6281] Transaction commit cost too much(msg="transaction commit cost too much time", ret=-6281, *this={this:0x7fd7472e6050, trans_id:{txid:917203437}, tenant_id:1002, is_exiting:false, trans_expired_time:1732042214678469, cluster_version:17180000256, trans_need_wait_wrap:{receive_gts_ts_:[mts=0], need_wait_interval_us:0}, stc:[mts=1732041614679741], ctx_create_time:1732041614678469}{ls_id:{id:1001}, session_id:3221968325, part_trans_action:3, pending_write:0, exec_info:{state:10, upstream:{id:1001}, participants:[{id:1001}, {id:1003}, {id:1002}], incremental_participants:[], prev_record_lsn:{lsn:18446744073709551615}, redo_lsns:[], redo_log_no:0, multi_data_source:[], scheduler:"10.201.156.55:2882", prepare_version:{val:18446744073709551615, v:3}, trans_type:2, next_log_entry_no:0, max_applied_log_ts:{val:18446744073709551615, v:3}, max_applying_log_ts:{val:18446744073709551615, v:3}, max_applying_part_log_no:9223372036854775807, max_submitted_seq_no:0, checksum:0, checksum_scn:{val:0, v:0}, max_durable_lsn:{lsn:18446744073709551615}, data_complete:false, is_dup_tx:false, prepare_log_info_arr:[], xid:{gtrid_str:"", bqual_str:"", format_id:1, gtrid_str_.ptr():"data_size:0, data:", bqual_str_.ptr():"data_size:0, data:", g_hv:0, b_hv:0}, need_checksum:true, is_sub2pc:false}, sub_state:{flag:4}, is_leaf():false, is_root():true, busy_cbs_.get_size():0, final_log_cb_:{ObTxBaseLogCb:{log_ts:{val:18446744073709551615, v:3}, lsn:{lsn:18446744073709551615}, submit_ts:0}, this:0x7fd7472e8e60, is_inited_:true, trans_id:{txid:917203437}, ls_id:{id:1001}, ctx:0x7fd7472e6050, tx_data_guard:{tx_data:NULL}, is_callbacked_:false, is_dynamic_:false, mds_range_:{range_array_.count():0, range_array_:[]}, cb_arg_array_:[], first_part_scn_:{val:18446744073709551615, v:3}}, ctx_tx_data_:{ctx_mgr_:0x7fd97de86030, tx_data_guard_:{tx_data:{tx_id:{txid:917203437}, ref_cnt:1, state:"RUNNING", commit_version:{val:18446744073709551615, v:3}, start_scn:{val:18446744073709551615, v:3}, end_scn:{val:18446744073709551615, v:3}, undo_status_list:{head:null, undo_node_cnt:0{}}}}, read_only_:false}, role_state_:0, start_replay_ts_:{val:18446744073709551615, v:3}, start_recover_ts_:{val:18446744073709551615, v:3}, is_incomplete_replay_ctx_:false, mt_ctx_:{ObIMvccCtx={alloc_type=0 ctx_descriptor=1918987881 min_table_version=0 max_table_version=1732018598571640 trans_version={val:4611686018427387903, v:0} commit_version={val:0, v:0} lock_wait_start_ts=0 replay_compact_version={val:0, v:0}} end_code=0 tx_status=0 is_readonly=false ref=0 trans_id={txid:917203437} ls_id=1001 callback_alloc_count=49 callback_free_count=0 checksum=0 tmp_checksum=0 checksum_scn={val:0, v:0} redo_filled_count=0 redo_sync_succ_count=0 redo_sync_fail_count=0 main_list_length=59 unsynced_cnt=49 unsubmitted_cnt_=49 cb_statistics:[main=59, slave=0, merge=0, tx_end=0, rollback_to=0, fast_commit=0, remove_memtable=0]}, coord_prepare_info_arr_:[], upstream_state:30, retain_cause:-1, 2pc_role:0, collected:[], ref:3, rec_log_ts:{val:18446744073709551615, v:3}, prev_rec_log_ts:{val:18446744073709551615, v:3}, lastest_snapshot:{val:18446744073709551615, v:3}, state_info_array:[], last_request_ts:1732041614679523}) [2024-12-06 17:36:47.871515] ERROR handle_timeout (ob_trans_part_ctx.cpp:530) [67014][T1002_TransTime][T1002][YB420AC99C37-00060590F00840E2-0-0] [lt=40][errcode=-6281] Transaction commit cost too much(msg="transaction commit cost too much time", ret=-6281, *this={this:0x7fd924bc2050, trans_id:{txid:914665077}, tenant_id:1002, is_exiting:false, trans_expired_time:1732030811302573, cluster_version:17180000256, trans_need_wait_wrap:{receive_gts_ts_:[mts=0], need_wait_interval_us:0}, stc:[mts=1732030211310247], ctx_create_time:1732030211302573}{ls_id:{id:1001}, session_id:3221820866, part_trans_action:3, pending_write:0, exec_info:{state:10, upstream:{id:1001}, participants:[{id:1001}, {id:1003}, {id:1002}], incremental_participants:[], prev_record_lsn:{lsn:18446744073709551615}, redo_lsns:[{lsn:432908868914}], redo_log_no:1, multi_data_source:[], scheduler:"10.201.156.55:2882", prepare_version:{val:1732025981797210317, v:0}, trans_type:2, next_log_entry_no:1, max_applied_log_ts:{val:18446744073709551615, v:3}, max_applying_log_ts:{val:18446744073709551615, v:3}, max_applying_part_log_no:9223372036854775807, max_submitted_seq_no:1732030211301527, checksum:0, checksum_scn:{val:0, v:0}, max_durable_lsn:{lsn:18446744073709551615}, data_complete:false, is_dup_tx:false, prepare_log_info_arr:[{id_:{id:1003}, offset_:{lsn:470053714108}}, {id_:{id:1002}, offset_:{lsn:495692340823}}], xid:{gtrid_str:"", bqual_str:"", format_id:1, gtrid_str_.ptr():"data_size:0, data:", bqual_str_.ptr():"data_size:0, data:", g_hv:0, b_hv:0}, need_checksum:true, is_sub2pc:false}, sub_state:{flag:4}, is_leaf():false, is_root():true, busy_cbs_.get_size():1, final_log_cb_:{ObTxBaseLogCb:{log_ts:{val:18446744073709551615, v:3}, lsn:{lsn:18446744073709551615}, submit_ts:0}, this:0x7fd924bc4e60, is_inited_:true, trans_id:{txid:914665077}, ls_id:{id:1001}, ctx:0x7fd924bc2050, tx_data_guard:{tx_data:NULL}, is_callbacked_:false, is_dynamic_:false, mds_range_:{range_array_.count():0, range_array_:[]}, cb_arg_array_:[], first_part_scn_:{val:18446744073709551615, v:3}}, ctx_tx_data_:{ctx_mgr_:0x7fd97de86030, tx_data_guard_:{tx_data:{tx_id:{txid:914665077}, ref_cnt:1, state:"RUNNING", commit_version:{val:18446744073709551615, v:3}, start_scn:{val:1732025981932800462, v:0}, end_scn:{val:18446744073709551615, v:3}, undo_status_list:{head:null, undo_node_cnt:0{}}}}, read_only_:false}, role_state_:0, start_replay_ts_:{val:18446744073709551615, v:3}, start_recover_ts_:{val:18446744073709551615, v:3}, is_incomplete_replay_ctx_:false, mt_ctx_:{ObIMvccCtx={alloc_type=0 ctx_descriptor=0 min_table_version=0 max_table_version=1732018598571640 trans_version={val:4611686018427387903, v:0} commit_version={val:0, v:0} lock_wait_start_ts=0 replay_compact_version={val:0, v:0}} end_code=0 tx_status=0 is_readonly=false ref=0 trans_id={txid:914665077} ls_id=1001 callback_alloc_count=332 callback_free_count=0 checksum=0 tmp_checksum=0 checksum_scn={val:0, v:0} redo_filled_count=197 redo_sync_succ_count=0 redo_sync_fail_count=0 main_list_length=342 unsynced_cnt=332 unsubmitted_cnt_=141 cb_statistics:[main=342, slave=0, merge=0, tx_end=0, rollback_to=0, fast_commit=0, remove_memtable=0]}, coord_prepare_info_arr_:[], upstream_state:30, retain_cause:-1, 2pc_role:0, collected:[6], ref:4, rec_log_ts:{val:1732025981932800462, v:0}, prev_rec_log_ts:{val:18446744073709551615, v:3}, lastest_snapshot:{val:18446744073709551615, v:3}, state_info_array:[], last_request_ts:1732030211309959}) [2024-12-06 17:36:47.871558] ERROR handle_timeout (ob_trans_part_ctx.cpp:530) [67014][T1002_TransTime][T1002][YB420AC99C37-00060590F00840E2-0-0] [lt=42][errcode=-6281] Transaction commit cost too much(msg="transaction commit cost too much time", ret=-6281, *this={this:0x7fd7fdfd8050, trans_id:{txid:917121114}, tenant_id:1002, is_exiting:false, trans_expired_time:1732041613306942, cluster_version:17180000256, trans_need_wait_wrap:{receive_gts_ts_:[mts=0], need_wait_interval_us:0}, stc:[mts=1732041013311060], ctx_create_time:1732041013306942}{ls_id:{id:1001}, session_id:3221973908, part_trans_action:3, pending_write:0, exec_info:{state:10, upstream:{id:1001}, participants:[{id:1001}, {id:1003}, {id:1002}], incremental_participants:[], prev_record_lsn:{lsn:18446744073709551615}, redo_lsns:[{lsn:432919784062}], redo_log_no:1, multi_data_source:[], scheduler:"10.201.156.55:2882", prepare_version:{val:18446744073709551615, v:3}, trans_type:2, next_log_entry_no:1, max_applied_log_ts:{val:18446744073709551615, v:3}, max_applying_log_ts:{val:18446744073709551615, v:3}, max_applying_part_log_no:9223372036854775807, max_submitted_seq_no:1732041013308556, checksum:0, checksum_scn:{val:0, v:0}, max_durable_lsn:{lsn:18446744073709551615}, data_complete:false, is_dup_tx:false, prepare_log_info_arr:[], xid:{gtrid_str:"", bqual_str:"", format_id:1, gtrid_str_.ptr():"data_size:0, data:", bqual_str_.ptr():"data_size:0, data:", g_hv:0, b_hv:0}, need_checksum:true, is_sub2pc:false}, sub_state:{flag:4}, is_leaf():false, is_root():true, busy_cbs_.get_size():1, final_log_cb_:{ObTxBaseLogCb:{log_ts:{val:18446744073709551615, v:3}, lsn:{lsn:18446744073709551615}, submit_ts:0}, this:0x7fd7fdfdae60, is_inited_:true, trans_id:{txid:917121114}, ls_id:{id:1001}, ctx:0x7fd7fdfd8050, tx_data_guard:{tx_data:NULL}, is_callbacked_:false, is_dynamic_:false, mds_range_:{range_array_.count():0, range_array_:[]}, cb_arg_array_:[], first_part_scn_:{val:18446744073709551615, v:3}}, ctx_tx_data_:{ctx_mgr_:0x7fd97de86030, tx_data_guard_:{tx_data:{tx_id:{txid:917121114}, ref_cnt:1, state:"RUNNING", commit_version:{val:18446744073709551615, v:3}, start_scn:{val:1732025981932800875, v:0}, end_scn:{val:18446744073709551615, v:3}, undo_status_list:{head:null, undo_node_cnt:0{}}}}, read_only_:false}, role_state_:0, start_replay_ts_:{val:18446744073709551615, v:3}, start_recover_ts_:{val:18446744073709551615, v:3}, is_incomplete_replay_ctx_:false, mt_ctx_:{ObIMvccCtx={alloc_type=0 ctx_descriptor=0 min_table_version=0 max_table_version=1732018598571640 trans_version={val:4611686018427387903, v:0} commit_version={val:0, v:0} lock_wait_start_ts=0 replay_compact_version={val:0, v:0}} end_code=0 tx_status=0 is_readonly=false ref=0 trans_id={txid:917121114} ls_id=1001 callback_alloc_count=330 callback_free_count=0 checksum=0 tmp_checksum=0 checksum_scn={val:0, v:0} redo_filled_count=197 redo_sync_succ_count=0 redo_sync_fail_count=0 main_list_length=340 unsynced_cnt=330 unsubmitted_cnt_=139 cb_statistics:[main=340, slave=0, merge=0, tx_end=0, rollback_to=0, fast_commit=0, remove_memtable=0]}, coord_prepare_info_arr_:[], upstream_state:30, retain_cause:-1, 2pc_role:0, collected:[], ref:4, rec_log_ts:{val:1732025981932800875, v:0}, prev_rec_log_ts:{val:18446744073709551615, v:3}, lastest_snapshot:{val:18446744073709551615, v:3}, state_info_array:[], last_request_ts:1732041013310104})