第一台日志 ``` [root@localhost log]# tail -f election.log|grep -v INFO [2024-10-30 14:29:20.352927] WDIAG [ELECT] operator() (election_acceptor.cpp:145) [573][T1001_Occam][T1001][Y0-0000000000000000-0-0] [lt=58][errcode=0] [LogPhase::RENEW_LEASE]lease expired(ret=0, ret="OB_SUCCESS", *this={ls_id:{id:1}, addr:"X.X.X.X:2882", ballot_number:5248, ballot_of_time_window:5249, lease:{owner:"X.X.X.X:2882", lease_end_ts:{span_from_now:-0.005s, expired_time_point:14:29:20.347}, ballot_number:5248}, is_time_window_opened:True, vote_reason:LOG TS, last_time_window_open_ts:2024-10-30 14:29:19.289769, highest_priority_prepare_req:{this:0x7f9291cbdab0, BASE:{msg_type:"Prepare Request", id:1, sender:"X.X.X.X:2882", receiver:"X.X.X.X:2882", restart_counter:1, ballot_number:5249, debug_ts:{src_construct_ts:"29:19.154046", src_serialize_ts:"29:19.154104", dest_deserialize_ts:"29:19.290173", dest_process_ts:"29:19.290177", process_delay:136131}, biggest_min_cluster_version_ever_seen:4.3.1.0}, role:"Follower", is_buffer_valid:true, inner_priority_seed:4096, membership_version:{proposal_id:383, config_seq:251}}, p_election:0x7f9291cbd230}) [2024-10-30 14:29:38.888455] WDIAG [ELECT] operator() (election_event_recorder.cpp:89) [168][Occam][T0][Y0-0000000000000000-0-0] [lt=6][errcode=-4012] [LogPhase::EVENT]fail to insert row(ret=-4012, ret="OB_TIMEOUT", retry_times=0, report_ts=1730233774645345, self_addr="X.X.X.X:2882", mtl_id=1002, obj_to_string(type)="vote", ls_id=1001, uniq_holder.get_ptr()=vote for "X.X.X.X:2882", reason:ZONE PRIORITY) [2024-10-30 14:29:51.839859] WDIAG [ELECT] print_debug_ts_if_reach_warn_threshold (election_message.cpp:76) [1056][T1_L0_G2][T1][YB420A130326-00062580F267CFA8-0-0] [lt=18][errcode=-4016] request deserialize in dest too delay(msg={msg_type:"Prepare Request", id:1, sender:"X.X.X.X:2882", receiver:"X.X.X.X:2882", restart_counter:1, ballot_number:5251, debug_ts:{src_construct_ts:"29:51.548290", src_serialize_ts:"29:51.548351", dest_deserialize_ts:"29:51.839856", dest_process_ts:"00:00.0", process_delay:-1730269791548290}, biggest_min_cluster_version_ever_seen:4.3.1.0}, req_debug_ts={src_construct_ts:"29:51.548290", src_serialize_ts:"29:51.548351", dest_deserialize_ts:"29:51.839856", dest_process_ts:"00:00.0", process_delay:-1730269791548290}, diff=291566, max_diff=291566, warn_threshold=200000, recaculated_warn_threshold=200000) [2024-10-30 14:29:51.839918] WDIAG [ELECT] print_debug_ts_if_reach_warn_threshold (election_message.cpp:76) [1056][T1_L0_G2][T1][YB420A130326-00062580F267CFA8-0-0] [lt=53][errcode=-4016] request deserialize in dest too delay(msg={msg_type:"Prepare Request", id:1, sender:"X.X.X.X:2882", receiver:"X.X.X.X:2882", restart_counter:1, ballot_number:5251, debug_ts:{src_construct_ts:"29:51.548290", src_serialize_ts:"29:51.548351", dest_deserialize_ts:"29:51.839856", dest_process_ts:"29:51.839917", process_delay:291627}, biggest_min_cluster_version_ever_seen:4.3.1.0}, req_debug_ts={src_construct_ts:"29:51.548290", src_serialize_ts:"29:51.548351", dest_deserialize_ts:"29:51.839856", dest_process_ts:"29:51.839917", process_delay:291627}, diff=291566, max_diff=291627, warn_threshold=200000, recaculated_warn_threshold=200000) [2024-10-30 14:30:08.957443] WDIAG [ELECT] operator() (election_event_recorder.cpp:89) [168][Occam][T0][Y0-0000000000000000-0-0] [lt=19][errcode=-4012] [LogPhase::EVENT]fail to insert row(ret=-4012, ret="OB_TIMEOUT", retry_times=0, report_ts=1730230759651135, self_addr="X.X.X.X:2882", mtl_id=1002, obj_to_string(type)="vote", ls_id=1, uniq_holder.get_ptr()=vote for "X.X.X.X:2882", reason:ZONE PRIORITY) [2024-10-30 14:30:08.957453] WDIAG [ELECT] ~ObOccamFastTimeGuard (ob_occam_time_guard.h:407) [168][Occam][T0][Y0-0000000000000000-0-0] [lt=8][errcode=0] cost too much time:election_event_recorder.cpp:auto oceanbase::palf::election::EventRecorder::report_event_(oceanbase::palf::election::ElectionEventType, const common::ObString &)::(anonymous class)::operator()(), (*this=|threshold=500.00ms|start at 14:30:08.957|88=1us|total=30.07s) [2024-10-30 14:30:18.131655] WDIAG [ELECT] operator() (election_acceptor.cpp:145) [573][T1001_Occam][T1001][Y0-0000000000000000-0-0] [lt=63][errcode=0] REACH SYSLOG RATE LIMIT [bandwidth] [2024-10-30 14:30:30.049790] WDIAG [ELECT] print_debug_ts_if_reach_warn_threshold (election_message.cpp:80) [750][T1002_Occam][T1002][Y0-0000000000000000-0-0] [lt=25][errcode=-4016] response construct in src too delay(msg={msg_type:"Prepare Response", id:1001, sender:"X.X.X.X:2882", receiver:"X.X.X.X:2882", restart_counter:1, ballot_number:-1, debug_ts:{src_construct_ts:"30:30.49789", src_serialize_ts:"00:00.0", dest_deserialize_ts:"00:00.0", dest_process_ts:"00:00.0", process_delay:-1730269830049789}, biggest_min_cluster_version_ever_seen:4.3.1.0}, req_debug_ts={src_construct_ts:"30:27.763491", src_serialize_ts:"30:27.763543", dest_deserialize_ts:"30:27.873604", dest_process_ts:"30:27.873608", process_delay:110117}, diff=2286298, max_diff=2286298, warn_threshold=200000, recaculated_warn_threshold=2200000) [2024-10-30 14:30:30.049898] WDIAG [ELECT] print_debug_ts_if_reach_warn_threshold (election_message.cpp:80) [750][T1002_Occam][T1002][Y0-0000000000000000-0-0] [lt=72][errcode=-4016] response construct in src too delay(msg={msg_type:"Prepare Response", id:1001, sender:"X.X.X.X:2882", receiver:"X.X.X.X:2882", restart_counter:1, ballot_number:5250, debug_ts:{src_construct_ts:"30:30.49789", src_serialize_ts:"30:30.49898", dest_deserialize_ts:"00:00.0", dest_process_ts:"00:00.0", process_delay:-1730269830049789}, biggest_min_cluster_version_ever_seen:4.3.1.0}, req_debug_ts={src_construct_ts:"30:27.763491", src_serialize_ts:"30:27.763543", dest_deserialize_ts:"30:27.873604", dest_process_ts:"30:27.873608", process_delay:110117}, diff=2286298, max_diff=2286407, warn_threshold=200000, recaculated_warn_threshold=2200000) [2024-10-30 14:30:31.307760] WDIAG [ELECT] operator() (election_acceptor.cpp:145) [344][T1_Occam][T1][Y0-0000000000000000-0-0] [lt=19][errcode=0] [LogPhase::RENEW_LEASE]lease expired(ret=0, ret="OB_SUCCESS", *this={ls_id:{id:1}, addr:"X.X.X.X:2882", ballot_number:5254, ballot_of_time_window:5255, lease:{owner:"X.X.X.X:2882", lease_end_ts:{span_from_now:-0.023s, expired_time_point:14:30:31.285}, ballot_number:5254}, is_time_window_opened:True, vote_reason:LOG TS, last_time_window_open_ts:2024-10-30 14:30:30.291111, highest_priority_prepare_req:{this:0x7f92aad35ab0, BASE:{msg_type:"Prepare Request", id:1, sender:"X.X.X.X:2882", receiver:"X.X.X.X:2882", restart_counter:1, ballot_number:5255, debug_ts:{src_construct_ts:"30:30.292307", src_serialize_ts:"30:30.292357", dest_deserialize_ts:"30:30.294138", dest_process_ts:"30:30.294140", process_delay:1833}, biggest_min_cluster_version_ever_seen:4.3.1.0}, role:"Follower", is_buffer_valid:true, inner_priority_seed:4096, membership_version:{proposal_id:437, config_seq:313}}, p_election:0x7f92aad35230}) [2024-10-30 14:30:39.030563] WDIAG [ELECT] operator() (election_event_recorder.cpp:89) [168][Occam][T0][Y0-0000000000000000-0-0] [lt=5][errcode=-4012] [LogPhase::EVENT]fail to insert row(ret=-4012, ret="OB_TIMEOUT", retry_times=0, report_ts=1730223529656971, self_addr="X.X.X.X:2882", mtl_id=1002, obj_to_string(type)="lease expired", ls_id=1001, uniq_holder.get_ptr()=owner:"X.X.X.X:2882", expired time:01:38:49.630400, ballot number:536) [2024-10-30 14:30:39.030573] WDIAG [ELECT] ~ObOccamFastTimeGuard (ob_occam_time_guard.h:407) [168][Occam][T0][Y0-0000000000000000-0-0] [lt=8][errcode=0] cost too much time:election_event_recorder.cpp:auto oceanbase::palf::election::EventRecorder::report_event_(oceanbase::palf::election::ElectionEventType, const common::ObString &)::(anonymous class)::operator()(), (*this=|threshold=500.00ms|start at 14:30:39.305|88=1us|total=30.07s) [2024-10-30 14:30:42.728629] WDIAG [ELECT] print_debug_ts_if_reach_warn_threshold (election_message.cpp:76) [997][T1002_L0_G2][T1002][YB420A130326-00062581043F419B-0-0] [lt=17][errcode=-4016] request deserialize in dest too delay(msg={msg_type:"Prepare Request", id:1, sender:"X.X.X.X:2882", receiver:"X.X.X.X:2882", restart_counter:1, ballot_number:5260, debug_ts:{src_construct_ts:"30:42.195549", src_serialize_ts:"30:42.195616", dest_deserialize_ts:"30:42.728628", dest_process_ts:"00:00.0", process_delay:-1730269842195549}, biggest_min_cluster_version_ever_seen:4.3.1.0}, req_debug_ts={src_construct_ts:"30:42.195549", src_serialize_ts:"30:42.195616", dest_deserialize_ts:"30:42.728628", dest_process_ts:"00:00.0", process_delay:-1730269842195549}, diff=533079, max_diff=533079, warn_threshold=200000, recaculated_warn_threshold=200000) [2024-10-30 14:30:42.728680] WDIAG [ELECT] print_debug_ts_if_reach_warn_threshold (election_message.cpp:76) [997][T1002_L0_G2][T1002][YB420A130326-00062581043F419B-0-0] [lt=45][errcode=-4016] request deserialize in dest too delay(msg={msg_type:"Prepare Request", id:1, sender:"X.X.X.X:2882", receiver:"X.X.X.X:2882", restart_counter:1, ballot_number:5260, debug_ts:{src_construct_ts:"30:42.195549", src_serialize_ts:"30:42.195616", dest_deserialize_ts:"30:42.728628", dest_process_ts:"30:42.728679", process_delay:533130}, biggest_min_cluster_version_ever_seen:4.3.1.0}, req_debug_ts={src_construct_ts:"30:42.195549", src_serialize_ts:"30:42.195616", dest_deserialize_ts:"30:42.728628", dest_process_ts:"30:42.728679", process_delay:533130}, diff=533079, max_diff=533130, warn_threshold=200000, recaculated_warn_threshold=200000) observer.log [2024-10-30 14:32:28.417364] WDIAG [OCCAM] push_task (ob_occam_thread_pool.h:473) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=0][errcode=-4024] queue is full(ret=-4024, head=3568, tail=4592, lbt()="0x17a30451 0x867b6a2 0x6007a04 0x6006fa0 0x6006348 0x600547e 0x6004f89 0x17b1be21 0x17b18187 0x7f92d86081cf 0x7f92d8239dd3") [2024-10-30 14:32:28.417367] WDIAG [OCCAM] commit_task (ob_occam_thread_pool.h:341) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=3][errcode=-4024] push task failed(ret=-4024) [2024-10-30 14:32:28.417369] WDIAG [OCCAM] commit_task_to_thread_pool_ (ob_occam_timer.h:290) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=1][errcode=-4024] commit task to thread pool failed(ret=-4024, *this={this:0x7f90fb6ae030, caller:election_event_recorder.cpp:report_event_:100, function_type:ZN9oceanbase4palf8election13EventRecorder13report_event_ENS1_17ElectionEventTypeERKNS_6common8ObStringEE5$_167, timer_running_flag:1, total_running_count:34820, func_shared_ptr_.ptr:0x7f91bed0ccf0, time_wheel:0x7f92bc9f5ce0, thread_pool:0x7f92bc9f5540, is_running:1, time_interval:15.00s, expected_run_time:04:01:58.406, task_priority:1, with_handle_protected:0}) [2024-10-30 14:32:28.417373] WDIAG [OCCAM] runTimerTask (ob_occam_timer.h:204) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=4][errcode=-4024] fail to commit task to thread pool(ret=-4024, ret="OB_BUF_NOT_ENOUGH", *this={this:0x7f90fb6ae030, caller:election_event_recorder.cpp:report_event_:100, function_type:ZN9oceanbase4palf8election13EventRecorder13report_event_ENS1_17ElectionEventTypeERKNS_6common8ObStringEE5$_167, timer_running_flag:1, total_running_count:34820, func_shared_ptr_.ptr:0x7f91bed0ccf0, time_wheel:0x7f92bc9f5ce0, thread_pool:0x7f92bc9f5540, is_running:1, time_interval:15.00s, expected_run_time:04:01:58.406, task_priority:1, with_handle_protected:0}) [2024-10-30 14:32:28.417382] WDIAG [OCCAM] push_task (ob_occam_thread_pool.h:473) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=1][errcode=-4024] queue is full(ret=-4024, head=3568, tail=4592, lbt()="0x17a30451 0x867b6a2 0x6007a04 0x6006fa0 0x6006348 0x600547e 0x6004f89 0x17b1be21 0x17b18187 0x7f92d86081cf 0x7f92d8239dd3") [2024-10-30 14:32:28.417384] WDIAG [OCCAM] commit_task (ob_occam_thread_pool.h:341) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=2][errcode=-4024] push task failed(ret=-4024) [2024-10-30 14:32:28.417386] WDIAG [OCCAM] commit_task_to_thread_pool_ (ob_occam_timer.h:290) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=2][errcode=-4024] commit task to thread pool failed(ret=-4024, *this={this:0x7f90388f1ab0, caller:election_event_recorder.cpp:report_event_:100, function_type:ZN9oceanbase4palf8election13EventRecorder13report_event_ENS1_17ElectionEventTypeERKNS_6common8ObStringEE5$_167, timer_running_flag:1, total_running_count:34820, func_shared_ptr_.ptr:0x7f90388f1d10, time_wheel:0x7f92bc9f5ce0, thread_pool:0x7f92bc9f5540, is_running:1, time_interval:15.00s, expected_run_time:04:00:58.408, task_priority:1, with_handle_protected:0}) [2024-10-30 14:32:28.417390] WDIAG [OCCAM] runTimerTask (ob_occam_timer.h:204) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=4][errcode=-4024] fail to commit task to thread pool(ret=-4024, ret="OB_BUF_NOT_ENOUGH", *this={this:0x7f90388f1ab0, caller:election_event_recorder.cpp:report_event_:100, function_type:ZN9oceanbase4palf8election13EventRecorder13report_event_ENS1_17ElectionEventTypeERKNS_6common8ObStringEE5$_167, timer_running_flag:1, total_running_count:34820, func_shared_ptr_.ptr:0x7f90388f1d10, time_wheel:0x7f92bc9f5ce0, thread_pool:0x7f92bc9f5540, is_running:1, time_interval:15.00s, expected_run_time:04:00:58.408, task_priority:1, with_handle_protected:0}) [2024-10-30 14:32:28.417399] WDIAG [OCCAM] push_task (ob_occam_thread_pool.h:473) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=1][errcode=-4024] queue is full(ret=-4024, head=3568, tail=4592, lbt()="0x17a30451 0x867b6a2 0x6007a04 0x6006fa0 0x6006348 0x600547e 0x6004f89 0x17b1be21 0x17b18187 0x7f92d86081cf 0x7f92d8239dd3") [2024-10-30 14:32:28.417401] WDIAG [OCCAM] commit_task (ob_occam_thread_pool.h:341) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=2][errcode=-4024] push task failed(ret=-4024) [2024-10-30 14:32:28.417403] WDIAG [OCCAM] commit_task_to_thread_pool_ (ob_occam_timer.h:290) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=2][errcode=-4024] commit task to thread pool failed(ret=-4024, *this={this:0x7f90fb7628d0, caller:election_event_recorder.cpp:report_event_:100, function_type:ZN9oceanbase4palf8election13EventRecorder13report_event_ENS1_17ElectionEventTypeERKNS_6common8ObStringEE5$_167, timer_running_flag:1, total_running_count:34820, func_shared_ptr_.ptr:0x7f90fb762b30, time_wheel:0x7f92bc9f5ce0, thread_pool:0x7f92bc9f5540, is_running:1, time_interval:15.00s, expected_run_time:03:58:58.404, task_priority:1, with_handle_protected:0}) [2024-10-30 14:32:28.417407] WDIAG [OCCAM] runTimerTask (ob_occam_timer.h:204) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=4][errcode=-4024] fail to commit task to thread pool(ret=-4024, ret="OB_BUF_NOT_ENOUGH", *this={this:0x7f90fb7628d0, caller:election_event_recorder.cpp:report_event_:100, function_type:ZN9oceanbase4palf8election13EventRecorder13report_event_ENS1_17ElectionEventTypeERKNS_6common8ObStringEE5$_167, timer_running_flag:1, total_running_count:34820, func_shared_ptr_.ptr:0x7f90fb762b30, time_wheel:0x7f92bc9f5ce0, thread_pool:0x7f92bc9f5540, is_running:1, time_interval:15.00s, expected_run_time:03:58:58.404, task_priority:1, with_handle_protected:0}) [2024-10-30 14:32:28.417416] WDIAG [OCCAM] push_task (ob_occam_thread_pool.h:473) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=0][errcode=-4024] queue is full(ret=-4024, head=3568, tail=4592, lbt()="0x17a30451 0x867b6a2 0x6007a04 0x6006fa0 0x6006348 0x600547e 0x6004f89 0x17b1be21 0x17b18187 0x7f92d86081cf 0x7f92d8239dd3") [2024-10-30 14:32:28.417418] WDIAG [OCCAM] commit_task (ob_occam_thread_pool.h:341) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=2][errcode=-4024] push task failed(ret=-4024) [2024-10-30 14:32:28.417420] WDIAG [OCCAM] commit_task_to_thread_pool_ (ob_occam_timer.h:290) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=2][errcode=-4024] commit task to thread pool failed(ret=-4024, *this={this:0x7f90fb61dab0, caller:election_event_recorder.cpp:report_event_:100, function_type:ZN9oceanbase4palf8election13EventRecorder13report_event_ENS1_17ElectionEventTypeERKNS_6common8ObStringEE5$_167, timer_running_flag:1, total_running_count:34820, func_shared_ptr_.ptr:0x7f90fb61dd10, time_wheel:0x7f92bc9f5ce0, thread_pool:0x7f92bc9f5540, is_running:1, time_interval:15.00s, expected_run_time:03:58:28.409, task_priority:1, with_handle_protected:0}) [2024-10-30 14:32:28.417425] WDIAG [OCCAM] runTimerTask (ob_occam_timer.h:204) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=4][errcode=-4024] fail to commit task to thread pool(ret=-4024, ret="OB_BUF_NOT_ENOUGH", *this={this:0x7f90fb61dab0, caller:election_event_recorder.cpp:report_event_:100, function_type:ZN9oceanbase4palf8election13EventRecorder13report_event_ENS1_17ElectionEventTypeERKNS_6common8ObStringEE5$_167, timer_running_flag:1, total_running_count:34820, func_shared_ptr_.ptr:0x7f90fb61dd10, time_wheel:0x7f92bc9f5ce0, thread_pool:0x7f92bc9f5540, is_running:1, time_interval:15.00s, expected_run_time:03:58:28.409, task_priority:1, with_handle_protected:0}) [2024-10-30 14:32:28.417433] WDIAG [OCCAM] push_task (ob_occam_thread_pool.h:473) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=0][errcode=-4024] queue is full(ret=-4024, head=3568, tail=4592, lbt()="0x17a30451 0x867b6a2 0x6007a04 0x6006fa0 0x6006348 0x600547e 0x6004f89 0x17b1be21 0x17b18187 0x7f92d86081cf 0x7f92d8239dd3") [2024-10-30 14:32:28.417435] WDIAG [OCCAM] commit_task (ob_occam_thread_pool.h:341) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=2][errcode=-4024] push task failed(ret=-4024) ``` 第二台日志,第三台机器硬件坏了,无法登录 ``` [root@localhost log]# tail -f election.log|grep -v INFO [2024-10-30 14:36:36.539937] WDIAG [ELECT] operator() (election_event_recorder.cpp:89) [168][Occam][T0][Y0-0000000000000000-0-0] [lt=19][errcode=-4012] [LogPhase::EVENT]fail to insert row(ret=-4012, ret="OB_TIMEOUT", retry_times=0, report_ts=1730229191413948, self_addr="X.X.X.X8:2882", mtl_id=1002, obj_to_string(type)="lease expired", ls_id=1, uniq_holder.get_ptr()=owner:"X.X.X.X8:2882", expired time:03:13:11.390649, ballot number:1127) [2024-10-30 14:36:44.973248] WDIAG [ELECT] print_debug_ts_if_reach_warn_threshold (election_message.cpp:84) [1035][T1001_L0_G2][T1001][YB420A130327-00062580F39328A1-0-0] [lt=37][errcode=-4016] response deserialize in dest too delay(msg={msg_type:"Prepare Response", id:1, sender:"X.X.X.X9:2882", receiver:"X.X.X.X8:2882", restart_counter:1, ballot_number:5294, debug_ts:{src_construct_ts:"36:41.253695", src_serialize_ts:"36:41.253727", dest_deserialize_ts:"36:44.973247", dest_process_ts:"00:00.0", process_delay:-1730270201253695}, biggest_min_cluster_version_ever_seen:4.3.1.0}, req_debug_ts={src_construct_ts:"36:39.244083", src_serialize_ts:"36:39.244117", dest_deserialize_ts:"36:39.245232", dest_process_ts:"36:39.245238", process_delay:1155}, diff=5729164, max_diff=5729164, warn_threshold=200000, recaculated_warn_threshold=2200000) [2024-10-30 14:36:44.973279] WDIAG [ELECT] print_debug_ts_if_reach_warn_threshold (election_message.cpp:84) [1035][T1001_L0_G2][T1001][YB420A130327-00062580F39328A1-0-0] [lt=27][errcode=-4016] response deserialize in dest too delay(msg={msg_type:"Prepare Response", id:1, sender:"X.X.X.X9:2882", receiver:"X.X.X.X8:2882", restart_counter:1, ballot_number:5294, debug_ts:{src_construct_ts:"36:41.253695", src_serialize_ts:"36:41.253727", dest_deserialize_ts:"36:44.973247", dest_process_ts:"36:44.973279", process_delay:3719584}, biggest_min_cluster_version_ever_seen:4.3.1.0}, req_debug_ts={src_construct_ts:"36:39.244083", src_serialize_ts:"36:39.244117", dest_deserialize_ts:"36:39.245232", dest_process_ts:"36:39.245238", process_delay:1155}, diff=5729164, max_diff=5729196, warn_threshold=200000, recaculated_warn_threshold=2200000) [2024-10-30 14:36:45.184789] WDIAG [ELECT] print_debug_ts_if_reach_warn_threshold (election_message.cpp:84) [739][T1_L0_G2][T1][YB420A130327-00062580F29DDB2C-0-0] [lt=26][errcode=-4016] response deserialize in dest too delay(msg={msg_type:"Prepare Response", id:1, sender:"X.X.X.X9:2882", receiver:"X.X.X.X8:2882", restart_counter:1, ballot_number:5292, debug_ts:{src_construct_ts:"36:41.212932", src_serialize_ts:"36:41.212966", dest_deserialize_ts:"36:45.184787", dest_process_ts:"00:00.0", process_delay:-1730270201212932}, biggest_min_cluster_version_ever_seen:4.3.1.0}, req_debug_ts={src_construct_ts:"36:39.195400", src_serialize_ts:"36:39.195457", dest_deserialize_ts:"36:39.230292", dest_process_ts:"36:39.230298", process_delay:34898}, diff=5989387, max_diff=5989387, warn_threshold=200000, recaculated_warn_threshold=2200000) [2024-10-30 14:36:45.184878] WDIAG [ELECT] print_debug_ts_if_reach_warn_threshold (election_message.cpp:84) [739][T1_L0_G2][T1][YB420A130327-00062580F29DDB2C-0-0] [lt=80][errcode=-4016] response deserialize in dest too delay(msg={msg_type:"Prepare Response", id:1, sender:"X.X.X.X9:2882", receiver:"X.X.X.X8:2882", restart_counter:1, ballot_number:5292, debug_ts:{src_construct_ts:"36:41.212932", src_serialize_ts:"36:41.212966", dest_deserialize_ts:"36:45.184787", dest_process_ts:"36:45.184877", process_delay:3971945}, biggest_min_cluster_version_ever_seen:4.3.1.0}, req_debug_ts={src_construct_ts:"36:39.195400", src_serialize_ts:"36:39.195457", dest_deserialize_ts:"36:39.230292", dest_process_ts:"36:39.230298", process_delay:34898}, diff=5989387, max_diff=5989477, warn_threshold=200000, recaculated_warn_threshold=2200000) [2024-10-30 14:36:48.993758] WDIAG [ELECT] operator() (election_acceptor.cpp:145) [573][T1001_Occam][T1001][Y0-0000000000000000-0-0] [lt=18][errcode=0] [LogPhase::RENEW_LEASE]lease expired(ret=0, ret="OB_SUCCESS", *this={ls_id:{id:1}, addr:"X.X.X.X8:2882", ballot_number:5294, ballot_of_time_window:5295, lease:{owner:"X.X.X.X8:2882", lease_end_ts:{span_from_now:-0.020s, expired_time_point:14:36:48.973}, ballot_number:5294}, is_time_window_opened:True, vote_reason:the only request, last_time_window_open_ts:2024-10-30 14:36:47.988255, highest_priority_prepare_req:{this:0x7f8dc94bdab0, BASE:{msg_type:"Prepare Request", id:1, sender:"X.X.X.X8:2882", receiver:"X.X.X.X8:2882", restart_counter:1, ballot_number:5295, debug_ts:{src_construct_ts:"36:47.988472", src_serialize_ts:"36:47.988501", dest_deserialize_ts:"36:47.988779", dest_process_ts:"36:47.988786", process_delay:314}, biggest_min_cluster_version_ever_seen:4.3.1.0}, role:"Follower", is_buffer_valid:true, inner_priority_seed:4096, membership_version:{proposal_id:383, config_seq:251}}, p_election:0x7f8dc94bd230}) [2024-10-30 14:36:49.206496] WDIAG [ELECT] operator() (election_acceptor.cpp:145) [344][T1_Occam][T1][Y0-0000000000000000-0-0] [lt=55][errcode=0] REACH SYSLOG RATE LIMIT [bandwidth] [2024-10-30 14:37:05.077144] WDIAG [ELECT] print_debug_ts_if_reach_warn_threshold (election_message.cpp:84) [741][T1_L0_G2][T1][YB420A130327-00062580F29DDB32-0-0] [lt=18][errcode=-4016] response deserialize in dest too delay(msg={msg_type:"Prepare Response", id:1, sender:"X.X.X.X9:2882", receiver:"X.X.X.X8:2882", restart_counter:1, ballot_number:5294, debug_ts:{src_construct_ts:"37:00.207438", src_serialize_ts:"37:00.207506", dest_deserialize_ts:"37:05.77141", dest_process_ts:"00:00.0", process_delay:-1730270220207438}, biggest_min_cluster_version_ever_seen:4.3.1.0}, req_debug_ts={src_construct_ts:"36:58.200074", src_serialize_ts:"36:58.200130", dest_deserialize_ts:"36:58.214314", dest_process_ts:"36:58.214323", process_delay:14249}, diff=6877067, max_diff=6877067, warn_threshold=200000, recaculated_warn_threshold=2200000) [2024-10-30 14:37:05.077501] WDIAG [ELECT] print_debug_ts_if_reach_warn_threshold (election_message.cpp:84) [741][T1_L0_G2][T1][YB420A130327-00062580F29DDB32-0-0] [lt=344][errcode=-4016] response deserialize in dest too delay(msg={msg_type:"Prepare Response", id:1, sender:"X.X.X.X9:2882", receiver:"X.X.X.X8:2882", restart_counter:1, ballot_number:5294, debug_ts:{src_construct_ts:"37:00.207438", src_serialize_ts:"37:00.207506", dest_deserialize_ts:"37:05.77141", dest_process_ts:"37:05.77500", process_delay:4870062}, biggest_min_cluster_version_ever_seen:4.3.1.0}, req_debug_ts={src_construct_ts:"36:58.200074", src_serialize_ts:"36:58.200130", dest_deserialize_ts:"36:58.214314", dest_process_ts:"36:58.214323", process_delay:14249}, diff=6877067, max_diff=6877426, warn_threshold=200000, recaculated_warn_threshold=2200000) observer.log [2024-10-30 14:38:17.503674] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [843][T1002_TntTransf][T1002][YB420A130326-00062580FA07B972-0-0] [lt=48][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.503676] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [897][T1002_ArcSrv][T1001][YB420A130326-00062580F5B77EB9-0-0] [lt=12][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.503680] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [845][T1002_TntTransf][T1002][YB420A130326-00062580F9E7B971-0-0] [lt=0][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.503682] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [162][LocltyRefTask][T1][YB420A130326-00062580F987B995-0-0] [lt=1][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.503688] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [673][T1001_DupTbLeas][T1][YB420A130326-00062580F437AEE5-0-0] [lt=0][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.503689] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [431][T1_HBService][T1][YB420A130326-0006258105A78722-0-0] [lt=6][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.503690] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [874][T1002_LSMetaCh][T1001][YB420A130326-00062580F6498C39-0-0] [lt=8][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.503789] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [145][UserLocAsyncUp1][T1001][YB420A130326-00062580F4C85FF9-0-0] [lt=0][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.503762] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [687][T1001_LSMetaCh][T1][YB420A130326-00062580F38982AE-0-0] [lt=39][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504055] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [441][T1_DupTbLease][T1][YB420A130326-00062580F3F7AEE5-0-0] [lt=0][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504066] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [841][T1002_FreInfoRe][T1002][YB420A130326-00062580F83BD8FF-0-0] [lt=0][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504072] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [842][T1002_TntTransf][T1002][YB420A130326-00062580FA17B973-0-0] [lt=0][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504078] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [434][T1_TntSharedTim][T1][YB420A130326-00062580FBF982C9-0-0] [lt=0][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504083] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [844][T1002_TntTransf][T1002][YB420A130326-00062580F9F7B972-0-0] [lt=3][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504081] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [143][MetaLocAsyncUp0][T1][YB420A130326-00062580F3085C43-0-0] [lt=12][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504101] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [666][T1001_TntShared][T1001][YB420A130326-00062580FC898E02-0-0] [lt=0][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504103] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [862][T1002_CdcSrv][T1001][YB420A130326-00062580F447B962-0-0] [lt=4][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504113] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [657][T1001_FreInfoRe][T1001][YB420A130326-00062580F84B3478-0-0] [lt=1][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504129] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [772][T1002_PLSSer][T1001][YB420A130326-00062580FD1985A8-0-0] [lt=6][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504154] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [569][T1001_Occam][T1][YB420A130326-00062580F3BA5F6D-0-0] [lt=24][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504183] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [359][T1_COMMONLSSe][T1][YB420A130326-0006258105F7894B-0-0] [lt=12][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504182] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [746][T1002_Occam][T1][YB420A130326-00062580F68A5F13-0-0] [lt=6][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504199] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [850][T1002_TntShared][T1][YB420A130326-00062580FBC9B3C4-0-0] [lt=6][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504198] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [1022][BlackListServic][T1][YB420A130326-00062580F7E841C1-0-0] [lt=4][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504191] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [289][OmtNodeBalancer][T1][YB420A130326-00062580F187B62A-0-0] [lt=13][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504227] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [588][T1001_COMMONLSS][T1001][YB420A130326-00062580FC797196-0-0] [lt=4][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504213] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [340][T1_Occam][T1][YB420A130326-00062580F2B9F73C-0-0] [lt=7][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504240] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [866][T1002_GCCollect][T1001][YB420A130326-00062580F8A88A5D-0-0] [lt=4][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504241] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [456][T1_LSMetaCh][T1][YB420A130326-00062580F2797A7D-0-0] [lt=0][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504253] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [857][T1002_DupTbLeas][T1001][YB420A130326-00062580F6D7AEE8-0-0] [lt=5][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504254] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [773][T1002_BalanceEx][T1002][YB420A130326-00062580FD398C36-0-0] [lt=5][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504261] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [843][T1002_TntTransf][T1002][YB420A130326-00062580FA07B972-0-0] [lt=4][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504263] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [1072][TimezoneMgr][T1][YB420A130326-00062580FC08BB1A-0-0] [lt=1][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504279] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [897][T1002_ArcSrv][T1001][YB420A130326-00062580F5B77EB9-0-0] [lt=4][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504292] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [673][T1001_DupTbLeas][T1][YB420A130326-00062580F437AEE5-0-0] [lt=3][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504486] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [145][UserLocAsyncUp1][T1001][YB420A130326-00062580F4C85FF9-0-0] [lt=3][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504555] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [431][T1_HBService][T1][YB420A130326-0006258105A78722-0-0] [lt=3][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.504568] WDIAG [STORAGE.TRANS] get_gts_from_local_timestamp_service_ (ob_gts_source.cpp:294) [767][T1002_TenantInf][T1001][YB420A130326-00062580F54D8876-0-0] [lt=4][errcode=-4038] global_timestamp_service get gts fail(leader="X.X.X.X8:2882", tmp_gts=0, ret=-4038, ret="OB_NOT_MASTER") [2024-10-30 14:38:17.506576] WDIAG [SERVER] after_func (ob_query_retry_ctrl.cpp:986) [118][LSUserTblUp2][T1001][YB420A130326-00062580F4B7945C-0-0] [lt=7][errcode=-4383] REACH SYSLOG RATE LIMIT [bandwidth] [2024-10-30 14:38:17.509033] WDIAG [STORAGE.TRANS] acquire_global_snapshot__ (ob_trans_service_v4.cpp:1824) [162][LocltyRefTask][T1][YB420A130326-00062580F987B995-0-0] [lt=0][errcode=-4012] get gts fail(ret=-4012, timeout_us=1000000, request_time=[mts=1730270296509101]) [2024-10-30 14:38:17.509027] EDIAG [OCCAM] runTimerTask (ob_occam_timer.h:224) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=0][errcode=-4024] fail to register next timer task(temp_ret=0, ret=-4024, ret="OB_BUF_NOT_ENOUGH", *this={this:0x7f8c1bb27050, caller:election_event_recorder.cpp:report_event_:100, function_type:ZN9oceanbase4palf8election13EventRecorder13report_event_ENS1_17ElectionEventTypeERKNS_6common8ObStringEE5$_167, timer_running_flag:1, total_running_count:35079, func_shared_ptr_.ptr:0x7f8c1bb272b0, time_wheel:0x7f8df3fff890, thread_pool:0x7f8df3fff0f0, is_running:1, time_interval:15.00s, expected_run_time:09:33:47.492, task_priority:1, with_handle_protected:0}) BACKTRACE:0x17a30451 0x5e19845 0x6081b19 0x608158f 0x60814ca 0x60813ec 0x8677745 0x60059f8 0x6004f89 0x17b1be21 0x17b18187 0x7f8e0fc081cf 0x7f8e0f839dd3 [2024-10-30 14:38:17.509059] WDIAG [STORAGE.TRANS] acquire_global_snapshot__ (ob_trans_service_v4.cpp:1836) [162][LocltyRefTask][T1][YB420A130326-00062580F987B995-0-0] [lt=25][errcode=-4283] acquire global snapshot fail(ret=-4283, gts_ahead=0, expire_ts=1730270322428662, request_time=[mts=1730270296509101]) [2024-10-30 14:38:17.509060] EDIAG [OCCAM] runTimerTask (ob_occam_timer.h:224) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=0][errcode=-4024] fail to register next timer task(temp_ret=0, ret=-4024, ret="OB_BUF_NOT_ENOUGH", *this={this:0x7f8c1bb27330, caller:election_event_recorder.cpp:report_event_:100, function_type:ZN9oceanbase4palf8election13EventRecorder13report_event_ENS1_17ElectionEventTypeERKNS_6common8ObStringEE5$_167, timer_running_flag:1, total_running_count:35079, func_shared_ptr_.ptr:0x7f8c1bb27590, time_wheel:0x7f8df3fff890, thread_pool:0x7f8df3fff0f0, is_running:1, time_interval:15.00s, expected_run_time:09:33:47.492, task_priority:1, with_handle_protected:0}) BACKTRACE:0x17a30451 0x5e19845 0x6081b19 0x608158f 0x60814ca 0x60813ec 0x8677745 0x60059f8 0x6004f89 0x17b1be21 0x17b18187 0x7f8e0fc081cf 0x7f8e0f839dd3 [2024-10-30 14:38:17.509077] EDIAG [OCCAM] runTimerTask (ob_occam_timer.h:224) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=1][errcode=-4024] fail to register next timer task(temp_ret=0, ret=-4024, ret="OB_BUF_NOT_ENOUGH", *this={this:0x7f8d5ad45690, caller:election_event_recorder.cpp:report_event_:100, function_type:ZN9oceanbase4palf8election13EventRecorder13report_event_ENS1_17ElectionEventTypeERKNS_6common8ObStringEE5$_167, timer_running_flag:1, total_running_count:35079, func_shared_ptr_.ptr:0x7f8d5ad458f0, time_wheel:0x7f8df3fff890, thread_pool:0x7f8df3fff0f0, is_running:1, time_interval:15.00s, expected_run_time:07:28:47.497, task_priority:1, with_handle_protected:0}) BACKTRACE:0x17a30451 0x5e19845 0x6081b19 0x608158f 0x60814ca 0x60813ec 0x8677745 0x60059f8 0x6004f89 0x17b1be21 0x17b18187 0x7f8e0fc081cf 0x7f8e0f839dd3 [2024-10-30 14:38:17.509068] WDIAG [STORAGE.TRANS] get_read_snapshot (ob_tx_api.cpp:657) [162][LocltyRefTask][T1][YB420A130326-00062580F987B995-0-0] [lt=8][errcode=-4283] acquire global snapshot fail(ret=-4283, tx={this:0x7f8d4c58ff50, tx_id:{txid:0}, state:1, addr:"X.X.X.X8:2882", tenant_id:1, session_id:1, assoc_session_id: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:1730270296508049, 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:17180066048, seq_base:1730270296506553, flags_.SHADOW:true, flags_.INTERRUPTED:false, flags_.BLOCK:false, flags_.REPLICA:false, can_elr:false, cflict_txs:[], abort_cause:0, commit_expire_ts:-1, commit_task_.is_registered():false, ref:1}) [2024-10-30 14:38:17.509092] EDIAG [OCCAM] runTimerTask (ob_occam_timer.h:224) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=0][errcode=-4024] fail to register next timer task(temp_ret=0, ret=-4024, ret="OB_BUF_NOT_ENOUGH", *this={this:0x7f8d5ad45970, caller:election_event_recorder.cpp:report_event_:100, function_type:ZN9oceanbase4palf8election13EventRecorder13report_event_ENS1_17ElectionEventTypeERKNS_6common8ObStringEE5$_167, timer_running_flag:1, total_running_count:35079, func_shared_ptr_.ptr:0x7f8d5ad45bd0, time_wheel:0x7f8df3fff890, thread_pool:0x7f8df3fff0f0, is_running:1, time_interval:15.00s, expected_run_time:07:28:47.498, task_priority:1, with_handle_protected:0}) BACKTRACE:0x17a30451 0x5e19845 0x6081b19 0x608158f 0x60814ca 0x60813ec 0x8677745 0x60059f8 0x6004f89 0x17b1be21 0x17b18187 0x7f8e0fc081cf 0x7f8e0f839dd3 [2024-10-30 14:38:17.509093] WDIAG [SQL.EXE] stmt_setup_snapshot_ (ob_sql_trans_control.cpp:837) [162][LocltyRefTask][T1][YB420A130326-00062580F987B995-0-0] [lt=24][errcode=-4283] fail to get snapshot(ret=-4283, local_single_ls_plan=false, first_ls_id={id:1}, session={this:0x7f8d4c4f41f8, id:1, deser:false, 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:0x7f8d4c58ff50}) [2024-10-30 14:38:17.509108] EDIAG [OCCAM] runTimerTask (ob_occam_timer.h:224) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=1][errcode=-4024] fail to register next timer task(temp_ret=0, ret=-4024, ret="OB_BUF_NOT_ENOUGH", *this={this:0x7f8c12599d90, caller:election_event_recorder.cpp:report_event_:100, function_type:ZN9oceanbase4palf8election13EventRecorder13report_event_ENS1_17ElectionEventTypeERKNS_6common8ObStringEE5$_167, timer_running_flag:1, total_running_count:35079, func_shared_ptr_.ptr:0x7f8c1251ff10, time_wheel:0x7f8df3fff890, thread_pool:0x7f8df3fff0f0, is_running:1, time_interval:15.00s, expected_run_time:04:56:32.495, task_priority:1, with_handle_protected:0}) BACKTRACE:0x17a30451 0x5e19845 0x6081b19 0x608158f 0x60814ca 0x60813ec 0x8677745 0x60059f8 0x6004f89 0x17b1be21 0x17b18187 0x7f8e0fc081cf 0x7f8e0f839dd3 [2024-10-30 14:38:17.509106] WDIAG [SQL.EXE] start_stmt (ob_sql_trans_control.cpp:567) [162][LocltyRefTask][T1][YB420A130326-00062580F987B995-0-0] [lt=12][errcode=-4283] fail to exec stmt_setup_snapshot_(session, das_ctx, plan, plan_ctx, txs)(ret=-4283, session_id=1, *tx_desc={this:0x7f8d4c58ff50, tx_id:{txid:0}, state:1, addr:"X.X.X.X8:2882", tenant_id:1, session_id:1, assoc_session_id: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:1730270296508049, 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:17180066048, seq_base:1730270296506553, flags_.SHADOW:true, flags_.INTERRUPTED:false, flags_.BLOCK:false, flags_.REPLICA:false, can_elr:false, cflict_txs:[], abort_cause:0, commit_expire_ts:-1, commit_task_.is_registered():false, ref:1}) [2024-10-30 14:38:17.509123] EDIAG [OCCAM] runTimerTask (ob_occam_timer.h:224) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=0][errcode=-4024] fail to register next timer task(temp_ret=0, ret=-4024, ret="OB_BUF_NOT_ENOUGH", *this={this:0x7f8c12597ab0, caller:election_event_recorder.cpp:report_event_:100, function_type:ZN9oceanbase4palf8election13EventRecorder13report_event_ENS1_17ElectionEventTypeERKNS_6common8ObStringEE5$_167, timer_running_flag:1, total_running_count:35079, func_shared_ptr_.ptr:0x7f8c12597d10, time_wheel:0x7f8df3fff890, thread_pool:0x7f8df3fff0f0, is_running:1, time_interval:15.00s, expected_run_time:04:56:32.495, task_priority:1, with_handle_protected:0}) BACKTRACE:0x17a30451 0x5e19845 0x6081b19 0x608158f 0x60814ca 0x60813ec 0x8677745 0x60059f8 0x6004f89 0x17b1be21 0x17b18187 0x7f8e0fc081cf 0x7f8e0f839dd3 [2024-10-30 14:38:17.509135] EDIAG [OCCAM] runTimerTask (ob_occam_timer.h:224) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=0][errcode=-4024] fail to register next timer task(temp_ret=0, ret=-4024, ret="OB_BUF_NOT_ENOUGH", *this={this:0x7f8c124248d0, caller:election_event_recorder.cpp:report_event_:100, function_type:ZN9oceanbase4palf8election13EventRecorder13report_event_ENS1_17ElectionEventTypeERKNS_6common8ObStringEE5$_167, timer_running_flag:1, total_running_count:35079, func_shared_ptr_.ptr:0x7f8c12424b30, time_wheel:0x7f8df3fff890, thread_pool:0x7f8df3fff0f0, is_running:1, time_interval:15.00s, expected_run_time:04:25:47.492, task_priority:1, with_handle_protected:0}) BACKTRACE:0x17a30451 0x5e19845 0x6081b19 0x608158f 0x60814ca 0x60813ec 0x8677745 0x60059f8 0x6004f89 0x17b1be21 0x17b18187 0x7f8e0fc081cf 0x7f8e0f839dd3 [2024-10-30 14:38:17.509147] EDIAG [OCCAM] runTimerTask (ob_occam_timer.h:224) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=0][errcode=-4024] fail to register next timer task(temp_ret=0, ret=-4024, ret="OB_BUF_NOT_ENOUGH", *this={this:0x7f8c91016310, caller:election_event_recorder.cpp:report_event_:100, function_type:ZN9oceanbase4palf8election13EventRecorder13report_event_ENS1_17ElectionEventTypeERKNS_6common8ObStringEE5$_167, timer_running_flag:1, total_running_count:35079, func_shared_ptr_.ptr:0x7f8c91016570, time_wheel:0x7f8df3fff890, thread_pool:0x7f8df3fff0f0, is_running:1, time_interval:15.00s, expected_run_time:03:02:47.497, task_priority:1, with_handle_protected:0}) BACKTRACE:0x17a30451 0x5e19845 0x6081b19 0x608158f 0x60814ca 0x60813ec 0x8677745 0x60059f8 0x6004f89 0x17b1be21 0x17b18187 0x7f8e0fc081cf 0x7f8e0f839dd3 [2024-10-30 14:38:17.509148] WDIAG [SQL] start_stmt (ob_result_set.cpp:361) [162][LocltyRefTask][T1][YB420A130326-00062580F987B995-0-0] [lt=28][errcode=-4283] fail to start stmt(ret=-4283, phy_plan->get_dependency_table()=[cnt:2, {table_id:117, schema_version:1728980938782712, object_type:1, is_db_explicit:false, is_existed:true}, {table_id:116, schema_version:1728980938780728, object_type:1, is_db_explicit:false, is_existed:true}]) [2024-10-30 14:38:17.509159] WDIAG [SQL] do_open_plan (ob_result_set.cpp:583) [162][LocltyRefTask][T1][YB420A130326-00062580F987B995-0-0] [lt=10][errcode=-4283] fail start stmt(ret=-4283) [2024-10-30 14:38:17.509159] EDIAG [OCCAM] runTimerTask (ob_occam_timer.h:224) [169][GEleTimer][T0][Y0-0000000000000000-0-0] [lt=0][errcode=-4024] fail to register next timer task(temp_ret=0, ret=-4024, ret="OB_BUF_NOT_ENOUGH", *this={this:0x7f8c910165f0, caller:election_event_recorder.cpp:report_event_:100, function_type:ZN9oceanbase4palf8election13EventRecorder13report_event_ENS1_17ElectionEventTypeERKNS_6common8ObStringEE5$_167, timer_running_flag:1, total_running_count:35079, func_shared_ptr_.ptr:0x7f8c91016850, time_wheel:0x7f8df3fff890, thread_pool:0x7f8df3fff0f0, is_running:1, time_interval:15.00s, expected_run_time:03:02:47.498, task_priority:1, with_handle_protected:0}) BACKTRACE:0x17a30451 0x5e19845 0x6081b19 0x608158f 0x60814ca 0x60813ec 0x8677745 0x60059f8 0x6004f89 0x17b1be21 0x17b18187 0x7f8e0fc081cf 0x7f8e0f839dd3 [2024-10-30 14:38:17.509164] WDIAG [SQL] open (ob_result_set.cpp:161) [162][LocltyRefTask][T1][YB420A130326-00062580F987B995-0-0] [lt=4][errcode=-4283] execute plan failed(ret=-4283) [2024-10-30 14:38:17.509169] WDIAG [SERVER] open (ob_inner_sql_result.cpp:153) [162][LocltyRefTask][T1][YB420A130326-00062580F987B995-0-0] [lt=4][errcode=-4283] open result set failed(ret=-4283) ```