【 使用环境 】生产环境
【 obbinlog-ce-4.2.0-100000152024122710.el7.x86_64 】
【问题描述】
DROP了INSTANCES之后重新进行创建发现 convert_running 一直是NO,对应租户下进行 SHOW MASTER STATUS 也没有增长。
创建INSTANCES命令如下:
CREATE BINLOG FOR TENANT `eastgarden_ob1`.`ob_eastgarden_prod`
TO USER `root` PASSWORD `********`
WITH CLUSTER URL `http://10.0.202.93:8080/services?Action=ObRootServiceInfo&User_ID=alibaba&UID=ocpmaster&ObRegion=eastgarden_ob1`
, REPLICATE NUM 2;
也看了相关的帖子,相关错误“request start lsn from all server fail” 与“start lsn locate fail” 但是我是重建binlog实例,默认从当前时间开始;
实例日志如下:
446744073709551615}, start_log_tstamp=-1, start_tstamp_ns=1745424024150276000, delta=-1745424024150276001, rpc_err="OB_SUCCESS", svr_err="OB_SUCCESS", ls_err="OB_ERR_OUT_OF_LOWER_BOUND", cur_max_start_lsn_={lsn:18446744073709551615}, cur_max_start_log_tstamp_=-1, result_svr_list_idx_=-1, succ_locate_count_=0, svr_list_consumed=1, svr_cnt=3)
[2025-07-31 16:32:52.028900] INFO [TLOG] req_start_lsn_by_tstamp (ob_log_rpc.cpp:107) [1186048][][T0][Y17CE0A00CA61-000000000070093F-0-0] [lt=36] rpc: request start LSN by tstamp(ret=0, ret="OB_SUCCESS", tenant_id=1012, svr="10.0.202.94:2882", timeout=60000000, req={rpc_ver:1, param_count:1, params:[{ls_id:{id:1}, start_ts_ns:1745424024150276000}], client_id:{client_addr:"10.0.202.97:1185742", client_pid:1185742}, flag:0}, resp={rpc_ver:1, err:0, result_count:1, result:[{err:-4233, start_lsn:{lsn:18446744073709551615}, start_ts_ns:-1}]})
[2025-07-31 16:32:52.028991] INFO [TLOG.FETCHER] set_result (ob_log_start_lsn_locator.cpp:894) [1186048][][T0][Y17CE0A00CA61-000000000070093F-0-0] [lt=86] start lsn locate request of one server is done(ret=0, ret="OB_SUCCESS", tls_id={tenant_id:1012, ls_id:{id:1}}, svr_identity="10.0.202.94:2882", start_lsn={lsn:18446744073709551615}, start_log_tstamp=-1, start_tstamp_ns=1745424024150276000, delta=-1745424024150276001, rpc_err="OB_SUCCESS", svr_err="OB_SUCCESS", ls_err="OB_ERR_OUT_OF_LOWER_BOUND", cur_max_start_lsn_={lsn:18446744073709551615}, cur_max_start_log_tstamp_=-1, result_svr_list_idx_=-1, succ_locate_count_=0, svr_list_consumed=2, svr_cnt=3)
[2025-07-31 16:32:52.098889] INFO [TLOG] req_start_lsn_by_tstamp (ob_log_rpc.cpp:107) [1186049][][T0][Y17CE0A00CA61-000000000080093F-0-0] [lt=43] rpc: request start LSN by tstamp(ret=0, ret="OB_SUCCESS", tenant_id=1012, svr="10.0.202.95:2882", timeout=60000000, req={rpc_ver:1, param_count:1, params:[{ls_id:{id:1}, start_ts_ns:1745424024150276000}], client_id:{client_addr:"10.0.202.97:1185742", client_pid:1185742}, flag:0}, resp={rpc_ver:1, err:0, result_count:1, result:[{err:-4233, start_lsn:{lsn:18446744073709551615}, start_ts_ns:-1}]})
[2025-07-31 16:32:52.098986] INFO [TLOG.FETCHER] set_result (ob_log_start_lsn_locator.cpp:894) [1186049][][T0][Y17CE0A00CA61-000000000080093F-0-0] [lt=92] start lsn locate request of one server is done(ret=0, ret="OB_SUCCESS", tls_id={tenant_id:1012, ls_id:{id:1}}, svr_identity="10.0.202.95:2882", start_lsn={lsn:18446744073709551615}, start_log_tstamp=-1, start_tstamp_ns=1745424024150276000, delta=-1745424024150276001, rpc_err="OB_SUCCESS", svr_err="OB_SUCCESS", ls_err="OB_ERR_OUT_OF_LOWER_BOUND", cur_max_start_lsn_={lsn:18446744073709551615}, cur_max_start_log_tstamp_=-1, result_svr_list_idx_=-1, succ_locate_count_=0, svr_list_consumed=3, svr_cnt=3)
[2025-07-31 16:32:52.148859] INFO [RPC.FRAME] mysql_easy_timer_cb (ob_net_easy.cpp:676) [1186007][MysqlIO][T0][Y0-0000000000000000-0-0] [lt=84] [MYSQL EASY STAT](log_str=conn count=0/0, request done=0/0, request doing=0/0)
[2025-07-31 16:32:52.150882] INFO [RPC.FRAME] batch_rpc_easy_timer_cb (ob_net_easy.cpp:641) [1186005][BatchIO][T0][Y0-0000000000000000-0-0] [lt=12] [BATCH_RPC EASY STAT](log_str=conn count=0/0, request done=0/0, request doing=0/0)
[2025-07-31 16:32:52.150925] INFO [RPC.FRAME] rpc_easy_timer_cb (ob_net_easy.cpp:603) [1186011][RpcUnix][T0][Y0-0000000000000000-0-0] [lt=54] [RPC EASY STAT](log_str=conn count=0/0, request done=0/0, request doing=0/0)
[2025-07-31 16:32:52.154239] INFO [RPC.FRAME] mysql_easy_timer_cb (ob_net_easy.cpp:676) [1186009][MysqlUnix][T0][Y0-0000000000000000-0-0] [lt=36] [MYSQL EASY STAT](log_str=conn count=0/0, request done=0/0, request doing=0/0)
[2025-07-31 16:32:52.193924] EDIAG [TLOG.FETCHER] get_result (ob_log_start_lsn_locator.cpp:928) [1186055][][T0][Y17CE0A00CA61-0000000000200001-0-0] [lt=29][errcode=-4016] request start lsn from all server fail(tls_id={tenant_id:1012, ls_id:{id:1}}, start_tstamp_ns=1745424024150276000, svr_cnt=3, svr_list_consumed=3, result_svr_list_idx=-1, svr_list=[{svr:"10.0.202.96:2882", rpc_executed:true, rpc_err:0, svr_err:0, ls_err:-4233, start_lsn:{lsn:18446744073709551615}, start_log_tstamp:18446744073709551615, trace_id:Y17CE0A00CA61-000000000060093F-0-0}, {svr:"10.0.202.94:2882", rpc_executed:true, rpc_err:0, svr_err:0, ls_err:-4233, start_lsn:{lsn:18446744073709551615}, start_log_tstamp:18446744073709551615, trace_id:Y17CE0A00CA61-000000000070093F-0-0}, {svr:"10.0.202.95:2882", rpc_executed:true, rpc_err:0, svr_err:0, ls_err:-4233, start_lsn:{lsn:18446744073709551615}, start_log_tstamp:18446744073709551615, trace_id:Y17CE0A00CA61-000000000080093F-0-0}]) BACKTRACE:0x1c10b636 0x1c0fdb11 0xcefb4c0 0xcefaf81 0xcefad84 0xcefab6b 0xd1ed800 0xd0ddbc4 0xd0dd638 0xcfb91b0 0xcfb85b3 0xcfb7998 0xd05c65f 0x7f74d6973ea5 0x7f74d4061b0d
[2025-07-31 16:32:52.194018] EDIAG [TLOG.FETCHER] locate_lsn_ (ob_log_ls_fetch_ctx.cpp:977) [1186055][][T0][Y17CE0A00CA61-0000000000200001-0-0] [lt=91][errcode=0] start lsn locate fail(start_lsn_locate_req={state:2, tls_id:{tenant_id:1012, ls_id:{id:1}}, start_tstamp_ns:1745424024150276000, svr_cnt:3, svr_list_consumed:3, result_svr_list_idx:-1, cur_max_start_lsn:{lsn:18446744073709551615}, cur_max_start_log_tstamp:-1, succ_locate_count:0, svr_list:[{svr:"10.0.202.96:2882", rpc_executed:true, rpc_err:0, svr_err:0, ls_err:-4233, start_lsn:{lsn:18446744073709551615}, start_log_tstamp:18446744073709551615, trace_id:Y17CE0A00CA61-000000000060093F-0-0}, {svr:"10.0.202.94:2882", rpc_executed:true, rpc_err:0, svr_err:0, ls_err:-4233, start_lsn:{lsn:18446744073709551615}, start_log_tstamp:18446744073709551615, trace_id:Y17CE0A00CA61-000000000070093F-0-0}, {svr:"10.0.202.95:2882", rpc_executed:true, rpc_err:0, svr_err:0, ls_err:-4233, start_lsn:{lsn:18446744073709551615}, start_log_tstamp:18446744073709551615, trace_id:Y17CE0A00CA61-000000000080093F-0-0}], fetching_mode:"Integrated Fetching Mode", archive_locate_rs:{start_lsn:{lsn:18446744073709551615}, loc_err:0}}) BACKTRACE:0x1c10b636 0x1c0fdb11 0xcd61d24 0xcf28591 0xcf283ba 0xce71777 0xd0df85b 0xd0ddbd9 0xd0dd638 0xcfb91b0 0xcfb85b3 0xcfb7998 0xd05c65f 0x7f74d6973ea5 0x7f74d4061b0d
[2025-07-31 16:32:52.207989] INFO [RPC.FRAME] rpc_easy_timer_cb (ob_net_easy.cpp:603) [1186032][RpcIO][T0][Y0-0000000000000000-0-0] [lt=43] [RPC EASY STAT](log_str=conn count=3/0, request done=1776/0, request doing=0/0)
[2025-07-31 16:32:52.208829] INFO [RPC.FRAME] rpc_easy_timer_cb (ob_net_easy.cpp:603) [1186033][RpcIO][T0][Y0-0000000000000000-0-0] [lt=52] [RPC EASY STAT](log_str=conn count=3/0, request done=1775/0, request doing=0/0)
[2025-07-31 16:32:52.209863] INFO [RPC.FRAME] rpc_easy_timer_cb (ob_net_easy.cpp:603) [1186034][RpcIO][T0][Y0-0000000000000000-0-0] [lt=53] [RPC EASY STAT](log_str=conn count=3/0, request done=1775/0, request doing=0/0)
[2025-07-31 16:32:52.209915] INFO [RPC.FRAME] mysql_easy_timer_cb (ob_net_easy.cpp:676) [1186039][MysqlIO][T0][Y0-0000000000000000-0-0] [lt=15] [MYSQL EASY STAT](log_str=conn count=0/0, request done=0/0, request doing=0/0)
[2025-07-31 16:32:52.212870] INFO [RPC.FRAME] batch_rpc_easy_timer_cb (ob_net_easy.cpp:641) [1186037][BatchIO][T0][Y0-0000000000000000-0-0] [lt=14] [BATCH_RPC EASY STAT](log_str=conn count=0/0, request done=0/0, request doing=0/0)
[2025-07-31 16:32:52.212919] INFO [RPC.FRAME] rpc_easy_timer_cb (ob_net_easy.cpp:603) [1186044][RpcUnix][T0][Y0-0000000000000000-0-0] [lt=43] [RPC EASY STAT](log_str=conn count=0/0, request done=0/0, request doing=0/0)
[2025-07-31 16:32:52.213901] INFO [RPC.FRAME] mysql_easy_timer_cb (ob_net_easy.cpp:676) [1186041][MysqlUnix][T0][Y0-0000000000000000-0-0] [lt=32] [MYSQL EASY STAT](log_str=conn count=0/0, request done=0/0, request doing=0/0)
[2025-07-31 16:32:52.214950] INFO [RPC.FRAME] rpc_easy_timer_cb (ob_net_easy.cpp:603) [1186035][RpcIO][T0][Y0-0000000000000000-0-0] [lt=22] [RPC EASY STAT](log_str=conn count=3/0, request done=1775/0, request doing=0/0)
[2025-07-31 16:32:52.294137] INFO [TLOG] get_server_array_for_locate_start_lsn (ob_log_route_service.cpp:628) [1186055][][T0][Y17CE0A00CA61-0000000000200001-0-0] [lt=27] LSSvrList get_server_array_for_locate_start_lsn succ(ret=0, ret="OB_SUCCESS", router_key={cluster_id:1735117219, tenant_id:1012, ls_id:{id:1}})
[2025-07-31 16:32:52.294257] INFO [TLOG.FETCHER] locate_lsn_ (ob_log_ls_fetch_ctx.cpp:952) [1186055][][T0][Y17CE0A00CA61-0000000000200001-0-0] [lt=94] start lsn locate request launched(tls_id={tenant_id:1012, ls_id:{id:1}}, is_start_tstamp=true, start_tstamp="[2025-04-24 00:00:24.150276]", svr_cnt=3, svr_list=[{svr:"10.0.202.96:2882", rpc_executed:false, rpc_err:0, svr_err:0, ls_err:0, start_lsn:{lsn:18446744073709551615}, start_log_tstamp:18446744073709551615, trace_id:Y0-0000000000000000-0-0}, {svr:"10.0.202.94:2882", rpc_executed:false, rpc_err:0, svr_err:0, ls_err:0, start_lsn:{lsn:18446744073709551615}, start_log_tstamp:18446744073709551615, trace_id:Y0-0000000000000000-0-0}, {svr:"10.0.202.95:2882", rpc_executed:false, rpc_err:0, svr_err:0, ls_err:0, start_lsn:{lsn:18446744073709551615}, start_log_tstamp:18446744073709551615, trace_id:Y0-0000000000000000-0-0}])
[2025-07-31 16:32:52.356473] INFO [TLOG] req_start_lsn_by_tstamp (ob_log_rpc.cpp:107) [1186047][][T0][Y17CE0A00CA61-0000000000600940-0-0] [lt=30] rpc: request start LSN by tstamp(ret=0, ret="OB_SUCCESS", tenant_id=1012, svr="10.0.202.96:2882", timeout=60000000, req={rpc_ver:1, param_count:1, params:[{ls_id:{id:1}, start_ts_ns:1745424024150276000}], client_id:{client_addr:"10.0.202.97:1185742", client_pid:1185742}, flag:0}, resp={rpc_ver:1, err:0, result_count:1, result:[{err:-4233, start_lsn:{lsn:18446744073709551615}, start_ts_ns:-1}]})
[2025-07-31 16:32:52.356577] INFO [TLOG.FETCHER] set_result (ob_log_start_lsn_locator.cpp:894) [1186047][][T0][Y17CE0A00CA61-0000000000600940-0-0] [lt=99] start lsn locate request of one server is done(ret=0, ret="OB_SUCCESS", tls_id={tenant_id:1012, ls_id:{id:1}}, svr_identity="10.0.202.96:2882", start_lsn={lsn:18446744073709551615}, start_log_tstamp=-1, start_tstamp_ns=1745424024150276000, delta=-1745424024150276001, rpc_err="OB_SUCCESS", svr_err="OB_SUCCESS", ls_err="OB_ERR_OUT_OF_LOWER_BOUND", cur_max_start_lsn_={lsn:18446744073709551615}, cur_max_start_log_tstamp_=-1, result_svr_list_idx_=-1, succ_locate_count_=0, svr_list_consumed=1, svr_cnt=3)
[2025-07-31 16:32:52.443974] INFO [TLOG] req_start_lsn_by_tstamp (ob_log_rpc.cpp:107) [1186048][][T0][Y17CE0A00CA61-0000000000700940-0-0] [lt=23] rpc: request start LSN by tstamp(ret=0, ret="OB_SUCCESS", tenant_id=1012, svr="10.0.202.94:2882", timeout=60000000, req={rpc_ver:1, param_count:1, params:[{ls_id:{id:1}, start_ts_ns:1745424024150276000}], client_id:{client_addr:"10.0.202.97:1185742", client_pid:1185742}, flag:0}, resp={rpc_ver:1, err:0, result_count:1, result:[{err:-4233, start_lsn:{lsn:18446744073709551615}, start_ts_ns:-1}]})
[2025-07-31 16:32:52.444082] INFO [TLOG.FETCHER] set_result (ob_log_start_lsn_locator.cpp:894) [1186048][][T0][Y17CE0A00CA61-0000000000700940-0-0] [lt=104] start lsn locate request of one server is done(ret=0, ret="OB_SUCCESS", tls_id={tenant_id:1012, ls_id:{id:1}}, svr_identity="10.0.202.94:2882", start_lsn={lsn:18446744073709551615}, start_log_tstamp=-1, start_tstamp_ns=1745424024150276000, delta=-1745424024150276001, rpc_err="OB_SUCCESS", svr_err="OB_SUCCESS", ls_err="OB_ERR_OUT_OF_LOWER_BOUND", cur_max_start_lsn_={lsn:18446744073709551615}, cur_max_start_log_tstamp_=-1, result_svr_list_idx_=-1, succ_locate_count_=0, svr_list_consumed=2, svr_cnt=3)
[2025-07-31 16:32:52.485936] INFO eloop_run (eloop.c:145) [1185833][pnio1][T0][Y0-0000000000000000-0-0] [lt=75] PNIO [ratelimit] time: 1753950772485931, bytes: 0, bw: 0.000000 MB/s, add_ts: 1007611, add_bytes: 0
[2025-07-31 16:32:52.504890] INFO eloop_run (eloop.c:145) [1185837][pnio2][T0][Y0-0000000000000000-0-0] [lt=69] PNIO [ratelimit] time: 1753950772504883, bytes: 0, bw: 0.000000 MB/s, add_ts: 1007619, add_bytes: 0
[2025-07-31 16:32:52.512517] INFO [TLOG] req_start_lsn_by_tstamp (ob_log_rpc.cpp:107) [1186049][][T0][Y17CE0A00CA61-0000000000800940-0-0] [lt=23] rpc: request start LSN by tstamp(ret=0, ret="OB_SUCCESS", tenant_id=1012, svr="10.0.202.95:2882", timeout=60000000, req={rpc_ver:1, param_count:1, params:[{ls_id:{id:1}, start_ts_ns:1745424024150276000}], client_id:{client_addr:"10.0.202.97:1185742", client_pid:1185742}, flag:0}, resp={rpc_ver:1, err:0, result_count:1, result:[{err:-4233, start_lsn:{lsn:18446744073709551615}, start_ts_ns:-1}]})
[2025-07-31 16:32:52.512634] INFO [TLOG.FETCHER] set_result (ob_log_start_lsn_locator.cpp:894) [1186049][][T0][Y17CE0A00CA61-0000000000800940-0-0] [lt=111] start lsn locate request of one server is done(ret=0, ret="OB_SUCCESS", tls_id={tenant_id:1012, ls_id:{id:1}}, svr_identity="10.0.202.95:2882", start_lsn={lsn:18446744073709551615}, start_log_tstamp=-1, start_tstamp_ns=1745424024150276000, delta=-1745424024150276001, rpc_err="OB_SUCCESS", svr_err="OB_SUCCESS", ls_err="OB_ERR_OUT_OF_LOWER_BOUND", cur_max_start_lsn_={lsn:18446744073709551615}, cur_max_start_log_tstamp_=-1, result_svr_list_idx_=-1, succ_locate_count_=0, svr_list_consumed=3, svr_cnt=3)
[2025-07-31 16:32:52.594494] EDIAG [TLOG.FETCHER] get_result (ob_log_start_lsn_locator.cpp:928) [1186055][][T0][Y17CE0A00CA61-0000000000200001-0-0] [lt=30][errcode=-4016] request start lsn from all server fail(tls_id={tenant_id:1012, ls_id:{id:1}}, start_tstamp_ns=1745424024150276000, svr_cnt=3, svr_list_consumed=3, result_svr_list_idx=-1, svr_list=[{svr:"10.0.202.96:2882", rpc_executed:true, rpc_err:0, svr_err:0, ls_err:-4233, start_lsn:{lsn:18446744073709551615}, start_log_tstamp:18446744073709551615, trace_id:Y17CE0A00CA61-0000000000600940-0-0}, {svr:"10.0.202.94:2882", rpc_executed:true, rpc_err:0, svr_err:0, ls_err:-4233, start_lsn:{lsn:18446744073709551615}, start_log_tstamp:18446744073709551615, trace_id:Y17CE0A00CA61-0000000000700940-0-0}, {svr:"10.0.202.95:2882", rpc_executed:true, rpc_err:0, svr_err:0, ls_err:-4233, start_lsn:{lsn:18446744073709551615}, start_log_tstamp:18446744073709551615, trace_id:Y17CE0A00CA61-0000000000800940-0-0}]) BACKTRACE:0x1c10b636 0x1c0fdb11 0xcefb4c0 0xcefaf81 0xcefad84 0xcefab6b 0xd1ed800 0xd0ddbc4 0xd0dd638 0xcfb91b0 0xcfb85b3 0xcfb7998 0xd05c65f 0x7f74d6973ea5 0x7f74d4061b0d
[2025-07-31 16:32:52.594583] EDIAG [TLOG.FETCHER] locate_lsn_ (ob_log_ls_fetch_ctx.cpp:977) [1186055][][T0][Y17CE0A00CA61-0000000000200001-0-0] [lt=86][errcode=0] start lsn locate fail(start_lsn_locate_req={state:2, tls_id:{tenant_id:1012, ls_id:{id:1}}, start_tstamp_ns:1745424024150276000, svr_cnt:3, svr_list_consumed:3, result_svr_list_idx:-1, cur_max_start_lsn:{lsn:18446744073709551615}, cur_max_start_log_tstamp:-1, succ_locate_count:0, svr_list:[{svr:"10.0.202.96:2882", rpc_executed:true, rpc_err:0, svr_err:0, ls_err:-4233, start_lsn:{lsn:18446744073709551615}, start_log_tstamp:18446744073709551615, trace_id:Y17CE0A00CA61-0000000000600940-0-0}, {svr:"10.0.202.94:2882", rpc_executed:true, rpc_err:0, svr_err:0, ls_err:-4233, start_lsn:{lsn:18446744073709551615}, start_log_tstamp:18446744073709551615, trace_id:Y17CE0A00CA61-0000000000700940-0-0}, {svr:"10.0.202.95:2882", rpc_executed:true, rpc_err:0, svr_err:0, ls_err:-4233, start_lsn:{lsn:18446744073709551615}, start_log_tstamp:18446744073709551615, trace_id:Y17CE0A00CA61-0000000000800940-0-0}], fetching_mode:"Integrated Fetching Mode", archive_locate_rs:{start_lsn:{lsn:18446744073709551615}, loc_err:0}}) BACKTRACE:0x1c10b636 0x1c0fdb11 0xcd61d24 0xcf28591 0xcf283ba 0xce71777 0xd0df85b 0xd0ddbd9 0xd0dd638 0xcfb91b0 0xcfb85b3 0xcfb7998 0xd05c65f 0x7f74d6973ea5 0x7f74d4061b0d