首批通过分布式安全可靠测评，为关键业务系统打造
划线反馈
OceanBase 数据库网络相关问题的排查方法
更新时间：2024-05-22 01:26
分享
适用版本：V2.1.x、V2.2.x、V3.1.x、V3.2.x内容类型：How-to
本文介绍 OceanBase 数据库网络相关问题的排查方法。
RPC 调用过程
RPC 超时排查方法
RPC 超时指 RPC 调用没有在预先设定的时间返回结果。超时的原因总体上可以分为两类：
一类是 RPC 响应返回慢。
另一类是 RPC 响应没有返回。
每一类有可能由多种具体原因导致。
示例，RPC 超时 (easy_error=-47, ret=-4012) 的排查方法。
client 端 RPC 超时时典型的日志信息。
INFO easy_connection.c:1783 [85530][0][Y0-0000000000000000] [lt=23] [dc=0] Session has timed out, session(0x7fa035596920), time(9.000155s), packet_id(2903925132279), conn(xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:xxx_xxx_0x7fa2392d2270 tp=1 t=0-1623125894988005 s=0 r=20 io=112248771/2965041847 sq=2964878955).
WARN [STORAGE.TRANS] process_cluster_heartbeat_rpc_cb (ob_tenant_weak_read_service.cpp:391) [85530][0][Y0-0000000000000000] [lt=14] [dc=0] tenant weak read service cluster heartbeat RPC fail(rcode={code:-4012, msg:"weak read service cluster heartbeat rpc timeout, tenant_id=1002, svr="xxx.xxx.xxx.xxx:xxx", timeout=9000000, send_ts=1623125886011857", warnings:[]}, tenant_id_=1002, dst="xxx.xxx.xxx.xxx:xxx", cluster_service_pkey={tid:1101710651031778, partition_id:0, part_cnt:0})
处理这类问题的典型步骤。
client 端日志中找到超时的 session 地址。
grep $TRACE_ID observer.log.xxx输出结果如下：
[Yxxxxxxxx7-0xxxxxxxx9] [lt=6] send packet fail(dst="xxx.xxx.xxx.xxx:xxxx", s=0x7f35064b6e80)根据 session 地址找到 easy 连接字符串 和 packet_id。
grep 0x7f35064b6e80 observer.log.xxx输出结果如下：
Session has timed out, session(0x7f35064b6e80), time(30.000279s), packet_id(897059851485), conn(1xx.xxx.xxx.xxx:xxx_XXX.XXX.XXX.XXX:XXXpacket_id 为 897059851485，目标地址为：XXX.XXX.XXX.XXX:XXX 。
检查 response 是否返回。 使用 packet_id 查找日志中是否有 response 返回。
grep 897059851485 observer.log.xxxx根据 easy 连接字符串中的目标地址找到对端目标 OBServer。
根据 trace_id 在对端 OBServer 日志中分析响应没有返回或者返回慢的原因。
grep "Yxxxxxxxx7-0xxxxxxxx9" observer.log.xxxx如果对端日志中没有更多线索，但有如下日志信息。
WARN easy_connection_dump_request (easy_connection.c:2187) [81093][0][Y0-0000000000000000-0-0] [lt=11] [dc=0] easy_reqeust hold by upper-layer for too much time. req(0x7f8f044771e8), timeout_warn_count(64), protocol(RPC), pcode(517), time(223.830598), packet_id(800405061853), trace_id(Yxxxxxxxx7-0xxxxxxxx9), trace_point(1), bt().可根据
trace_point确定卡住的位置：一般 1 是 DDL 请求处理卡住，3 是卡在租户队列， 5、11 是上层处理请求卡住。如果是 3，在对端查看租户队列积压情况，详细参见 如何排查租户队列积压。
如果是 1，5，11，根据 pcode 在
ob_rpc_packet_list.h中找到对应 pcode。示例。
由
pcode(517) => PCODE_DEF(OB_ALTER_TABLE, 0x205);信息，再根据 pcode 找到对应 RPC 的 owner :DEFINE_DDL_RS_RPC_PROCESSOR(obrpc::OB_ALTER_TABLE, ObRpcAlterTableP, alter_table(arg_, result_));。
RPC 响应返回慢原因
RPC 响应慢的原因有。
发送端队列挤压。
租户队列挤压。
Server 端处理慢。
个别
epoll handler执行时间过长。
RPC 响应未返回原因
造成 RPC 响应不能返回的原因有。
报文被网络丢失。
租户队列慢。
上次的业务线程发生死锁。
easy_warn_log("EASY SLOW: thread: %lx, lastrun: %f cost: %f loop:%d, slowcnt: %ld",th->tid, last, now - last, id, slowcnts[th->idx]);
连接断开的排查方法
错误（read eof）的排查方法
客户端 close 连接引发的断链。
检查日志确定连接断开的原因。
INFO easy_connection.c:1148 [100762][0][Y0-0000000000000000] [lt=3] [dc=0] Read eof from connection. Socket may have been shut down, conn(xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:xxx_4125_0x7f71ff2e5ac0 tp=0 t=1623381188034697-1623381492185008 s=0 r=1 io=12889/410498 s). INFO easy_connection.c:308 [100762][0][Y0-0000000000000000] [lt=6] [dc=0] Destroying connection, conn(xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:xxx_4125_0x7f71ff2e5ac0 tp=0 t=1623381188034697-1623381492185008 s=0 r=1 io=12889/410498 s), reason(on_readable). INFO [SHARE.PT] ob_partition_location_cache.cpp:3268 [100679][3058][Y0-0000000000000000] [lt=23] [dc=14] add_update_task success(task={table_id:{value:1100611139403919, first:1001, second:143}, partition_id:0, add_timestamp:1623381523064521, cluster_id:1, type:0}, leader_inactive_async_update=false, now=1623381523064521, location={table_id:{value:1100611139403919, first:1001, second:143}, partition_id:0, partition_cnt:0, pg_key:{tid:18446744073709551615, partition_id:-1, part_idx:268435455, subpart_idx:268435455}, replica_locations:[{server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:1065, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"xxx.xxx.xxx.xxx:xxx", role:1, sql_port:1063, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:1064, replica_type:0, reserved:0, property:{memstore_percent_:100}}], renew_time:1623380684547804, sql_renew_time:1623380684547804, is_mark_fail:false}, is_nonblock=true) INFO [RPC.OBMYSQL] obsm_handler.cpp:164 [100762][0][Y0-0000000000000000] [lt=4] [dc=0] kill and revert session(conn->version_=0, conn->sessid_=3221676242, proxy_sessid=3470, server_id=1, tmp_ret=0, eret=0) INFO easy_connection.c:340 [100762][0][Y0-0000000000000000] [lt=6] [dc=0] Destroying connection not done due to pool->ref(1), retry(0), conn(xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:xxx_4125_0x7f71ff2e5ac0 tp=0 t=1623381188034697-1623381523064510 s=3 r=1 io=12889/410498 s).客户端发 quit 命令引起的断链。
检查日志确定连接断开的原因。
INFO [SQL] ob_sql_session_mgr.cpp:450 [98594][4][Y0-0000000000000000] [lt=5] [dc=0] get current session count(sess_count=1006) [INFO [SERVER] obmp_quit.h:39 [99743][1366][Y404644564EB-0005C474C306C668] [lt=10] [dc=0] quit INFO easy_connection.c:1148 [100762][0][Y0-0000000000000000] [lt=11] [dc=0] Read eof from connection. Socket may have been shut down, conn(xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:40976_4609_0x7f71ff2dd3c0 tp=0 t=1623381443653888-1623381444142379 s=0 r=0 io=378/4600 sq=0). INFO easy_connection.c:308 [100762][0][Y0-0000000000000000] [lt=9] [dc=0] Destroying connection, conn(xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:40976_4609_0x7f71ff2dd3c0 tp=0 t=1623381443653888-1623381444142379 s=0 r=0 io=378/4600 sq=0), reason(on_readable). INFO [RPC.OBMYSQL] obsm_handler.cpp:164 [100762][0][Y0-0000000000000000] [lt=6] [dc=0] kill and revert session(conn->version_=0, conn->sessid_=3221735126, proxy_sessid=3833, server_id=1, tmp_ret=0, eret=0) INFO easy_connection.c:377 [100762][0][Y0-0000000000000000] [lt=8] [dc=0] Socket closed, fd(4609), conn(xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:40976_4609_0x7f71ff2dd3c0 tp=0 t=1623381443653888-1623381444142492 s=3 r=0 io=378/4600 sq=0).errno 相关错误的排查方法。
例如 errno = 104、110、111 等，需要根据错误码的含义进行具体分析。
示例日志。
INFO easy_connection.c:2543 [50825][0][Y0-0000000000000000] [lt=6] [dc=0] Establishing connection(xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:xxx_xxx_0x7f3419f736f0 tp=1 t=0-0 s=1 r=0 io=0/0 sq=0), s(0x7f3450212470), is_ssl(0). WARN [SHARE.PT] batch_process_tasks (ob_partition_location_cache.cpp:4309) [49957][736][xxxxx-xxxxx] [lt=6] [dc=1] fail to batch renew location(ret=-5019, tasks=[{table_id:{value:1102810162709526, first:1003, second:50198}, partition_id:8, add_timestamp:1623739496941866, cluster_id:1, type:1}, {table_id:{value:1102810162709577, first:1003, second:50249}, partition_id:76, add_timestamp:1623739496941868, cluster_id:1, type:1}, {table_id:{value:1102810162709526, first:1003, second:50198}, partition_id:89, add_timestamp:1623739496941869, cluster_id:1, type:1}]) INFO easy_negotiation.c:200 [50825][0][Y0-0000000000000000] [lt=9] [dc=0] negotiation not enabled!(xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:xxx_xxx_0x7f3419f736f0 tp=1 t=0-0 s=1 r=1 io=0/0 sq=0) WARN [SERVER] run1 (ob_uniq_task_queue.h:379) [49957][736][xxxxx-xxxxx] [lt=7] [dc=1] fail to batch execute task(ret=-5019, tasks.count()=3) INFO easy_socket.c:328 [50825][0][Y0-0000000000000000] [lt=6] [dc=0] Failed to write socket, fd(3120), conn(0x7f3419f736f0), errno(111), strerror(Connection refused). No listener on destination IP/PORT, or connect request rejected by firewall/iptables. Use 'iptalbe -L -n' or 'netstat -ntpl' to check it. WARN easy_connection_write_socket (easy_connection.c:2026) [50825][0][Y0-0000000000000000] [lt=7] [dc=0] Failed to write on connection(0x7f3419f736f0), ret(-1). WARN easy_connection_on_writable (easy_connection.c:1685) [50825][0][Y0-0000000000000000] [lt=5] [dc=0] Failed to write(on_writable), conn(xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:xxx_xxx_0x7f3419f736f0 tp=1 t=0-0 s=1 r=1 io=0/0 sq=0) INFO easy_connection.c:422 [50825][0][Y0-0000000000000000] [lt=10] [dc=0] Destroying connection, conn(xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:xxx_xxx_0x7f3419f736f0 tp=1 t=0-0 s=1 r=1 io=0/0 sq=0), reason(on_writable). INFO [RPC.OBRPC] ob_rpc_net_handler.cpp:283 [50825][0][Y0-0000000000000000] [lt=6] [dc=0] connection disconnect(easy_connection_str(c)="xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:xxx_xxx_0x7f3419f736f0 tp=1 t=0-0 s=1 r=0 io=0/0 sq=0") WARN [STORAGE] get_server_region (ob_locality_manager.cpp:397) [51713][2547][Y0-0000000000000000] [lt=5] [dc=144] fail to get server region(ret=-4018, server="xxx.xxx.xxx.xxx:xxx") INFO easy_connection.c:497 [50825][0][Y0-0000000000000000] [lt=6] [dc=0] Socket closed, fd(3120), conn(1xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:xxx_xxx_0x7f3419f736f0 tp=1 t=0-1623739496945250 s=3 r=0 io=0/0 sq=0), ev_is_pending(0), ev_is_active(0), ev_timer_pending_addr(0x7f3419fc8800), ev_timer_pending(1), timeout_watcher(0x7f3419f737c0). WARN [STORAGE] get_server_region (ob_partition_service.cpp:9879) [51713][2547][Y0-0000000000000000] [lt=1013] [dc=0] fail to get server region(ret=-4018, server="xxx.xxx.xxx.xxx:xxx") WARN [SERVER] send_session (ob_req_transport.cpp:301) [49574][0][xxxxx-xxxxx] [lt=6] [dc=0] send packet fail(dst="xxx.xxx.xxx.xxx:xxx", s=0x7f3450212470) WARN [RPC.FRAME] send (ob_req_transport.h:266) [49574][0][xxxxx-xxxxx] [lt=1012] [dc=0] send packet fail(easy_error=-46, req={pkt:{hdr_:{checksum_:740203303, pcode_:318, hlen_:0, priority_:5, flags_:7, tenant_id_:1, priv_tenant_id_:0, session_id_:0, trace_id_:141744194221578, timeout_:1999647, timestamp:1623739496945149, dst_cluster_id:1, cost_time:{len:0, arrival_push_diff:0, push_pop_diff:0, pop_process_start_diff:0, process_start_end_diff:0, process_end_response_diff:0, packet_id:15688862768, request_arrival_time:0}, compressor_type_:0, original_len_:0, src_cluster_id_:1, seq_no_:0}, chid_:239393, clen_:7, assemble:false, msg_count:0, payload:0}}, ret=-4121) WARN [RPC.OBRPC] rpc_call (ob_rpc_proxy.ipp:540) [49574][0][xxxxx-xxxxx] [lt=10] [dc=0] send rpc request fail fail(pcode=318) WARN [SHARE] do_detect_master_rs_v3 (ob_rs_mgr.cpp:533) [49574][0][xxxxx-xxxxx] [lt=6] [dc=0] fail to get rootserver role(ret=-4121, dst_server="xxx.xxx.xxx.xxx:xxx", cluster_id=1, timeout=1999647)
其他常见问题和排查方法
发送失败 (easy_error=-46) 的排查方法。
日志信息如下。
ERROR easy_connection_on_timeout_conn (easy_connection.c:1968) [85538][0][Y0-0000000000000000] [lt=12] [dc=0] Failed to do check_ack_timeout, and will destroy connection(xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:xxx_xxx_0x7fa2392e3060 tp=1 t=0-1623125909321231 s=0 r=87 io=103158973/2718622946 sq=2715416582). BACKTRACE:0xd39eca6 0x3135214 0xd2de5ae 0xd2e0cad 0xd4f6c59 0x2e386c7 0x2cd5b33 0x2e3f89c 0x2cd945e 0xe541c79 0x7f INFO easy_connection.c:422 [85538][0][Y0-0000000000000000] [lt=112] [dc=0] Destroying connection, conn(xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:xxx_xxx_0x7fa2392e3060 tp=1 t=0-1623125909321231 s=0 r=87 io=103158973/2718622946 sq=2715416582), reason(on_timeout_conn). WARN [SERVER] send_session (ob_req_transport.cpp:301) [85472][2594][xxxxx-xxxxx] [lt=287] [dc=0] send packet fail(dst="xxx.xxx.xxx.xxx:xxx", s=0x7f8f4d606110) WARN [SERVER] send_session (ob_req_transport.cpp:301) [85354][2358][xxxxx-xxxxx] [lt=231] [dc=0] send packet fail(dst="xxx.xxx.xxx.xxx:xxx", s=0x7f9aefc06110) WARN [SQL.EXE] on_timeout (ob_executor_rpc_processor.cpp:676) [85538][0][Y0-0000000000000000] [lt=11] [dc=0] ObRpcAPMiniDistExecuteCB add complete event to scheduler timeout, maybe network error(trace_id=Y1CA2645869E0-0005C437DF4909C0, task_id={ob_job_id:{ob_execution_id:{server:"xxx.xxx.xxx.xxx:xxx", execution_id:1623119131904449, task_type:1, hash:16143705785977111891}, job_id:2}, task_id:1, task_cnt:0}, dist_server_="xxx.xxx.xxx.xxx:xxx") WARN [RPC.FRAME] send (ob_req_transport.h:266) [85354][2358][Y1CA2645869E0-0005C437F02909AB] [lt=13] [dc=0] send packet fail(easy_error=-46, req={pkt:{hdr_:{checksum_:596058411, pcode_:1308, hlen_:0, priority_:5, flags_:6151, tenant_id_:1002, priv_tenant_id_:1, session_id_:0, trace_id_:31483793795552, timeout_:35992570748, timestamp:1623125892395624, dst_cluster_id:1, cost_time:{len:0, arrival_push_diff:0, push_pop_diff:0, pop_process_start_diff:0, process_start_end_diff:0, process_end_response_diff:0, packet_id:2906818743302, request_arrival_time:0}, compressor_type_:0, original_len_:0, src_cluster_id_:1, seq_no_:0}, chid_:44354534, clen_:9351674, assemble:false, msg_count:0, payload:0}}, ret=-4121) WARN [RPC.FRAME] send (ob_req_transport.h:266) [85472][2594][xxxxx-xxxxx] [lt=14] [dc=0] send packet fail(easy_error=-46, req={pkt:{hdr_:{checksum_:1655134704, pcode_:1308, hlen_:0, priority_:5, flags_:6151, tenant_id_:1002, priv_tenant_id_:1, session_id_:0, trace_id_:31483793795552, timeout_:35971611200, timestamp:1623125845609956, dst_cluster_id:1, cost_time:{len:0, arrival_push_diff:0, push_pop_diff:0, pop_process_start_diff:0, process_start_end_diff:0, process_end_response_diff:0, packet_id:2885732862982, request_arrival_time:0}, compressor_type_:0, original_len_:0, src_cluster_id_:1, seq_no_:0}, chid_:44032789, clen_:9470501, assemble:false, msg_count:0, payload:0}}, ret=-4121) WARN [RPC.OBRPC] rpc_call (ob_rpc_proxy.ipp:334) [85472][2594][xxxxx-xxxxxx] [lt=9] [dc=0] send rpc request fail fail(pcode=1308) WARN [RPC.OBRPC] rpc_call (ob_rpc_proxy.ipp:334) [85354][2358][xxxxx-xxxxx] [lt=9] [dc=0] send rpc request fail fail(pcode=1308) WARN [SQL.EXE] task_execute_v2 (ob_executor_rpc_impl.cpp:249) [85354][2358][xxxxx-xxxxx] [lt=7] [dc=0] rpc task_execute fail(ret=-4121, tenant_id=1002, svr="xxx.xxx.xxx.xxx:xxx", timeout=35992570748, timeout_timestamp=1623161884727367) WARN [SQL.EXE] execute_with_sql (ob_remote_scheduler.cpp:325) [85354][2358][xxxxx-xxxxx] [lt=10] [dc=0] need set_incomplete(has_transfer_err=true, has_merge_err=false)资源泄漏（
doing_request_count不断上涨）的排查方法。通过
EASY STAT关键词过滤 observer.log 信息。grep "EASY STAT" observer.log*输出结果如下：
NFO [RPC.FRAME] ob_net_easy.cpp:512 [56393][0][Y0-0000000000000000-0-0] [lt=17] [dc=0] [RPC EASY STAT](log_str="conn count=3/3, request done=2716/16476, request doing=0/0") INFO [RPC.FRAME] ob_net_easy.cpp:512 [56396][0][Y0-0000000000000000-0-0] [lt=14] [dc=0] [RPC EASY STAT](log_str="conn count=3/3, request done=2783/16555, request doing=0/0") INFO [RPC.FRAME] ob_net_easy.cpp:512 [56394][0][Y0-0000000000000000-0-0] [lt=13] [dc=0] [RPC EASY STAT](log_str="conn count=3/3, request done=2787/16527, request doing=0/0") INFO [RPC.FRAME] ob_net_easy.cpp:512 [56395][0][Y0-0000000000000000-0-0] [lt=16] [dc=0] [RPC EASY STAT](log_str="conn count=3/3, request done=2854/16496, request doing=0/0") INFO [RPC.FRAME] ob_net_easy.cpp:550 [56399][0][Y0-0000000000000000-0-0] [lt=13] [dc=0] [BATCH_RPC EASY STAT](log_str="conn count=2/2, request done=66595/9698, request doing=1/0") INFO [RPC.FRAME] ob_net_easy.cpp:550 [56398][0][Y0-0000000000000000-0-0] [lt=18] [dc=0] [BATCH_RPC EASY STAT](log_str="conn count=2/2, request done=66667/9729, request doing=1/0") INFO [RPC.FRAME] ob_net_easy.cpp:550 [56400][0][Y0-0000000000000000-0-0] [lt=16] [dc=0] [BATCH_RPC EASY STAT](log_str="conn count=3/3, request done=66531/9787, request doing=0/0") INFO [RPC.FRAME] ob_net_easy.cpp:550 [56401][0][Y0-0000000000000000-0-0] [lt=19] [dc=0] [BATCH_RPC EASY STAT](log_str="conn count=2/2, request done=66601/9704, request doing=1/0") INFO [RPC.FRAME] ob_net_easy.cpp:550 [56402][0][Y0-0000000000000000-0-0] [lt=14] [dc=0] [BATCH_RPC EASY STAT](log_str="conn count=0/0, request done=0/0, request doing=0/0") INFO [RPC.FRAME] ob_net_easy.cpp:574 [56404][0][Y0-0000000000000000-0-0] [lt=13] [dc=0] [MYSQL EASY STAT](log_str="conn count=0/0, request done=0/27, request doing=0/0") INFO [RPC.FRAME] ob_net_easy.cpp:574 [56406][0][Y0-0000000000000000-0-0] [lt=11] [dc=0] [MYSQL EASY STAT](log_str="conn count=0/0, request done=0/0, request doing=0/0") INFO [RPC.FRAME] ob_net_easy.cpp:574 [56405][0][Y0-0000000000000000-0-0] [lt=13] [dc=0] [MYSQL EASY STAT](log_str="conn count=0/1, request done=0/3, request doing=0/0") INFO [RPC.FRAME] ob_net_easy.cpp:574 [56409][0][Y0-0000000000000000-0-0] [lt=18] [dc=0] [MYSQL EASY STAT](log_str="conn count=0/0, request done=0/0, request doing=0/0") INFO [RPC.FRAME] ob_net_easy.cpp:574 [56407][0][Y0-0000000000000000-0-0] [lt=13] [dc=0] [MYSQL EASY STAT](log_str="conn count=0/0, request done=0/6, request doing=0/0")packet fly too much time 的排查方法：检查网络延迟和包处理时间。
epoll handler cost too much time 的排查方法：检查事件处理函数的耗时。
错误（ret = -4019）排查方法。
通过日志信息。
WARN [SQL.EXE] wait_ap_task_finish (ob_mini_task_executor.cpp:231) [32352][2566][xxxxx-xxxxx] [lt=6] [dc=14] while fetching task finish event, the task event rcode is not OB_SUCCESS(*complete_task={task_addr:"xxx.xxx.xxx.xxx:xxx", task_id:1, ret_code:-4019}, ret=-4019) WARN [SERVER] deliver_rpc_request (ob_srv_deliver.cpp:211) [100357][0][Y0-0000000000000000] [lt=11] [dc=0] can't deliver request(req={packet:{hdr_:{checksum_:798262228, pcode_:1799, hlen_:160, priority_:0, flags_:7175, tenant_id_:1002, priv_tenant_id_:0, session_id_:0, trace_id_:31483793795552, timeout_:9000000, timestamp:1622795884840188, dst_cluster_id:1, cost_time:{len:40, arrival_push_diff:0, push_pop_diff:0, pop_process_start_diff:0, process_start_end_diff:0, process_end_response_diff:0, packet_id:0, request_arrival_time:0}, compressor_type_:0, original_len_:0, src_cluster_id_:1, seq_no_:0}, chid_:41127935, clen_:110, assemble:false, msg_count:0, payload:0}, type:0, group:0, connection_phase:0, retry_times:0}, ret=-4019) WARN [SERVER.OMT] recv_request (ob_tenant.cpp:810) [100351][0][Y0-0000000000000000] [lt=5] [dc=0] push request to queue fail(ret=-4019, *this={id:1002, compat_mode:1, unit_min_cpu:"5.000000000000000000e+00", unit_max_cpu:"5.000000000000000000e+00", slice:"0.000000000000000000e+00", slice_remain:"0.000000000000000000e+00", token_cnt:10, sug_token_cnt:10, ass_token_cnt:10, lq_tokens:1, used_lq_tokens:0, stopped:false, idle_us:2908463, recv_hp_rpc_cnt:22386172, recv_np_rpc_cnt:14650, recv_lp_rpc_cnt:0, recv_mysql_cnt:13568, recv_task_cnt:101, recv_large_req_cnt:65, tt_large_quries:0, pop_normal_cnt:41355808, actives:10, workers:18, nesting workers:7, lq waiting workers:0, req_queue:total_size=65537 queue[0]=65520 queue[1]=0 queue[2]=17 queue[3]=0 queue[4]=0 queue[5]=0 , large queued:0, multi_level_queue:total_size=0 queue[0]=0 queue[1]=0 queue[2]=0 queue[3]=0 queue[4]=0 queue[5]=0 queue[6]=0 queue[7]=0 , recv_level_rpc_cnt:cnt[0]=0 cnt[1]=0 cnt[2]=0 cnt[3]=0 cnt[4]=0 cnt[5]=99458 cnt[6]=114 cnt[7]=0 , group_map:null}) WARN [SERVER] deliver (ob_srv_deliver.cpp:312) [100357][0][Y0-0000000000000000] [lt=640] [dc=0] deliver rpc request fail(req={packet:{hdr_:{checksum_:798262228, pcode_:1799, hlen_:160, priority_:0, flags_:7175, tenant_id_:1002, priv_tenant_id_:0, session_id_:0, trace_id_:31483793795552, timeout_:9000000, timestamp:1622795884840188, dst_cluster_id:1, cost_time:{len:40, arrival_push_diff:0, push_pop_diff:0, pop_process_start_diff:0, process_start_end_diff:0, process_end_response_diff:0, packet_id:0, request_arrival_time:0}, compressor_type_:0, original_len_:0, src_cluster_id_:1, seq_no_:0}, chid_:41127935, clen_:110, assemble:false, msg_count:0, payload:0}, type:0, group:0, connection_phase:0, retry_times:0}, ret=-4019)cluster_id 不匹配的排查方法。
日志中报 wrong cluster id，通常原因是 RPC 调用时设置的 cluster_id 不正确。
根据该日志的线程号找到对应的出错的 RPC 和相关的模块，根据相关模块处理。
ERROR [RPC.FRAME] async_cb (ob_req_transport.cpp:74) [91263][0][Y0-0000000000000000] [lt=19] [dc=0] wrong cluster id(ret=0) BACKTRACE:0x9c2e8da 0x2b8d562 0x2c4a298 0x2c4aa92 0x2c4bdf2 0x2a5e877 0x28069b1 0x291dc1c 0x291ebd0 0x27f7a03 0x292154c 0x27fb32e 0xada2ec9 0x7fd6d... INFO [STORAGE] ob_partition_loop_worker.cpp:369 [126656][4537][Y0-0000000000000000] [lt=12] [dc=0] write checkpoint success(pkey={tid:1099511627892, partition_id:0, part_cnt:0}, cur_checkpoint=1624002610554229) ERROR [RPC.FRAME] async_cb (ob_req_transport.cpp:74) [126439][0][Y0-0000000000000000] [lt=12] [dc=0] wrong cluster id(ret=0) BACKTRACE:0x77e0d8a 0x7724222 0x911158 0x43920e 0x9139c2 0x7902bd7 0x8a1a111 0x8a2a6dc 0x8a2b690 0x8a1cce3 0x8a1440c 0x8a2060e 0x8a12c99 0x7ff573f8ee25 0x7ff573a4df1d INFO [STORAGE.TRANS] ob_trans_service.cpp:6054 [126439][0][Y0-0000000000000000] [lt=1152] [dc=0] refresh location cache success(partition={tid:1000, partition_id:1000, part_cnt:1000}, lbt()="0x77e0d8a 0x2512f45 0x24d35d8 0x24d7188 0x7902c08 0x8a1a111 0x8a2a6dc 0x8a2b690 0x8a1cce3 0x8a1440c 0x8a2060e 0x8a12c99 0x7ff573f8ee25 0x7ff573a4df1d") ERROR [RPC.FRAME] async_cb (ob_req_transport.cpp:74) [126440][0][Y0-0000000000000000] [lt=8] [dc=0] wrong cluster id(ret=0) BACKTRACE:0x77e0d8a 0x7724222 0x911158 0x43920e 0x9139c2 0x7902bd7 0x8a1a111 0x8a2a6dc 0x8a2b690 0x8a1cce3 0x8a1440c 0x8a2060e 0x8a12c99 0x7ff573f8ee25 0x7ff573a4df1d INFO [STORAGE.TRANS] ob_trans_factory.h:94 [126439][0][Y0-0000000000000000] [lt=9] [dc=0] transaction memory statistics(mod_type="OB_TRANS_RPC_TASK", alloc_count=80, release_count=80, used=0) [INFO [STORAGE.TRANS] ob_trans_service.cpp:6054 [126440][0][Y0-0000000000000000] [lt=1270] [dc=0] refresh location cache success(partition={tid:1000, partition_id:1000, part_cnt:1000}, lbt()="0x77e0d8a 0x2512f45 0x24d35d8 0x24d7188 0x7902c08 0x8a1a111 0x8a2a6dc 0x8a2b690 0x8a1cce3 0x8a1440c 0x8a2060e 0x8a12c99 0x7ff573f8ee25 0x7ff573a4df1d") WARN [STORAGE.TRANS] on_timeout (ob_trans_rpc.h:291) [126439][0][Y0-0000000000000000] [lt=19] [dc=0] transaction rpc timeout(tmp_ret=0, pkey={tid:1000, partition_id:1000, part_cnt:1000}, trans_id={hash:1701875773507624461, inc:285578, addr:"xxx.xxx.xxx.xxx:xxx", t:1624002581598195}, msg_type=13, dst="xxx.xxx.xxx.xxx:xxx", sql_no_=0, fd=5381, status=-6230) WARN [STORAGE.TRANS] on_timeout (ob_trans_rpc.h:291) [126440][0][Y0-0000000000000000] [lt=9] [dc=0] transaction rpc timeout(tmp_ret=0, pkey={tid:1000, partition_id:1000, part_cnt:1000}, trans_id={hash:16009454309048995894, inc:285581, addr:"xxx.xxx.xxx.xxx:xxx", t:1624002581741763}, msg_type=13, dst="xxx.xxx.xxx.xxx:xxx", sql_no_=0, fd=5209, status=-6230)发送队列满（Failed to do check_ack_timeout）的排查方法。
通过日志信息。
ERROR easy_connection_on_timeout_conn (easy_connection.c:1968) [85538][0][Y0-0000000000000000] [lt=12] [dc=0] Failed to do check_ack_timeout, and will destroy connection(xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:xxx_xxx_0x7fa2392e3060 tp=1 t=0-1623125909321231 s=0 r=87 io=103158973/2718622946 sq=2715416582). BACKTRACE:0xd39eca6 0x3135214 0xd2de5ae 0xd2e0cad 0xd4f6c59 0x2e386c7 0x2cd5b33 0x2e3f89c 0x2cd945e 0xe541c79 0x7f INFO easy_connection.c:422 [85538][0][Y0-0000000000000000] [lt=112] [dc=0] Destroying connection, conn(1xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:xxx_xxx_3078_0x7fa2392e3060 tp=1 t=0-1623125909321231 s=0 r=87 io=103158973/2718622946 sq=2715416582), reason(on_timeout_conn). WARN [SERVER] send_session (ob_req_transport.cpp:301) [85472][2594][xxxxx-xxxxx] [lt=287] [dc=0] send packet fail(dst="xxx.xxx.xxx.xxx:xxx", s=0x7f8f4d606110) WARN [SERVER] send_session (ob_req_transport.cpp:301) [85354][2358][xxxxx-xxxxx] [lt=231] [dc=0] send packet fail(dst="xxx.xxx.xxx.xxx:xxx", s=0x7f9aefc06110) WARN [SQL.EXE] on_timeout (ob_executor_rpc_processor.cpp:676) [85538][0][Y0-0000000000000000] [lt=11] [dc=0] ObRpcAPMiniDistExecuteCB add complete event to scheduler timeout, maybe network error(trace_id=Y1CA2645869E0-0005C437DF4909C0, task_id={ob_job_id:{ob_execution_id:{server:"xxx.xxx.xxx.xxx:xxx", execution_id:1623119131904449, task_type:1, hash:16143705785977111891}, job_id:2}, task_id:1, task_cnt:0}, dist_server_="xxx.xxx.xxx.xxx:xxx") WARN [RPC.FRAME] send (ob_req_transport.h:266) [85354][2358][xxxxx-xxxxxx] [lt=13] [dc=0] send packet fail(easy_error=-46, req={pkt:{hdr_:{checksum_:596058411, pcode_:1308, hlen_:0, priority_:5, flags_:6151, tenant_id_:1002, priv_tenant_id_:1, session_id_:0, trace_id_:31483793795552, timeout_:35992570748, timestamp:1623125892395624, dst_cluster_id:1, cost_time:{len:0, arrival_push_diff:0, push_pop_diff:0, pop_process_start_diff:0, process_start_end_diff:0, process_end_response_diff:0, packet_id:2906818743302, request_arrival_time:0}, compressor_type_:0, original_len_:0, src_cluster_id_:1, seq_no_:0}, chid_:44354534, clen_:9351674, assemble:false, msg_count:0, payload:0}}, ret=-4121) WARN [RPC.FRAME] send (ob_req_transport.h:266) [85472][2594][xxxxx-xxxxxx] [lt=14] [dc=0] send packet fail(easy_error=-46, req={pkt:{hdr_:{checksum_:1655134704, pcode_:1308, hlen_:0, priority_:5, flags_:6151, tenant_id_:1002, priv_tenant_id_:1, session_id_:0, trace_id_:31483793795552, timeout_:35971611200, timestamp:1623125845609956, dst_cluster_id:1, cost_time:{len:0, arrival_push_diff:0, push_pop_diff:0, pop_process_start_diff:0, process_start_end_diff:0, process_end_response_diff:0, packet_id:2885732862982, request_arrival_time:0}, compressor_type_:0, original_len_:0, src_cluster_id_:1, seq_no_:0}, chid_:44032789, clen_:9470501, assemble:false, msg_count:0, payload:0}}, ret=-4121) WARN [RPC.OBRPC] rpc_call (ob_rpc_proxy.ipp:334) [85472][2594][xxxxx-xxxxxx] [lt=9] [dc=0] send rpc request fail fail(pcode=1308) WARN [RPC.OBRPC] rpc_call (ob_rpc_proxy.ipp:334) [85354][2358][xxxxx-xxxxxx] [lt=9] [dc=0] send rpc request fail fail(pcode=1308) WARN [SQL.EXE] task_execute_v2 (ob_executor_rpc_impl.cpp:249) [85354][2358][xxxxx-xxxxxx] [lt=7] [dc=0] rpc task_execute fail(ret=-4121, tenant_id=1002, svr="xxx.xxx.xxx.xxx:xxx", timeout=35992570748, timeout_timestamp=1623161884727367) WARN [SQL.EXE] execute_with_sql (ob_remote_scheduler.cpp:325) [85354][2358][xxxxx-xxxxxx] [lt=10] [dc=0] need set_incomplete(has_transfer_err=true, has_merge_err=false)设置 RPC 校验 隐藏参数 rpc checksum。
alter system set _rpc_checksum = 'Optional';在时间序列 CeresDB 数据库安装必须修改这个参数，CeresDB 需要在 OceanBase 数据库中创建一个租户使用。
配置网卡速率 nic.rate.speed。
详细参见 如何配置网卡速率。
确认 easy not started 情况。
有时 OBServer 启动过程过程中，可能执行副本回放等操作，导致 easy IO 启动慢，RPC 调用失败。
通过关键词过滤 observer.log 日志信息。
grep -E "ob_net_easy.cpp|easy_client.c" observer.log.20210610191916输出结果如下：
INFO [RPC.FRAME] ob_net_easy.cpp:239 [15636][0][Y0-0000000000000000] [lt=6] [dc=0] listen unix domain succ(path="unix:run/mysql.sock") INFO [RPC.FRAME] ob_net_easy.cpp:263 [15636][0][Y0-0000000000000000] [lt=3] [dc=0] listen start(port=2882) INFO [RPC.FRAME] ob_net_easy.cpp:182 [15636][0][Y0-0000000000000000] [lt=5] [dc=0] add batch rpc handler ERROR easy_client_dispatch (easy_client.c:21) [15980][686][xxx-xxx] [lt=10] [dc=0] easy_io_dispatch is failure: easy not started ERROR easy_client_dispatch (easy_client.c:21) [15980][686][xxx-xxx] [lt=959] [dc=0] easy_io_dispatch is failure: easy not started ERROR easy_client_dispatch (easy_client.c:21) [15980][686][xxx-xxxx] [lt=13] [dc=0] easy_io_dispatch is failure: easy not started ERROR easy_client_dispatch (easy_client.c:21) [15980][686][xxx-xxxx] [lt=10] [dc=0] easy_io_dispatch is failure: easy not started ERROR easy_client_dispatch (easy_client.c:21) [15980][686][xxx-xxxxx] [lt=11] [dc=0] easy_io_dispatch is failure: easy not started ERROR easy_client_dispatch (easy_client.c:21) [15980][686][xxx-xxxxx] [lt=23] [dc=0] easy_io_dispatch is failure: easy not started ERROR easy_client_dispatch (easy_client.c:21) [15638][4][Y0-0000000000000000] [lt=0] [dc=0] easy_io_dispatch is failure: easy not started ERROR easy_client_dispatch (easy_client.c:21) [15980][686][xxx-xxxxxx] [lt=13] [dc=0] easy_io_dispatch is failure: easy not started ERROR easy_client_dispatch (easy_client.c:21) [15980][686][xxx-xxxxxx] [lt=33] [dc=0] easy_io_dispatch is failure: easy not started ERROR easy_client_dispatch (easy_client.c:21) [15980][686][xxx-xxxxxxx] [lt=13] [dc=0] easy_io_dispatch is failure: easy not started ERROR easy_client_dispatch (easy_client.c:21) [15980][686][xxx-xxxxxxx] [lt=19] [dc=0] easy_io_dispatch is failure: easy not started ERROR easy_client_dispatch (easy_client.c:21) [15980][686][xxx-xxxxxxxx] [lt=13] [dc=0] easy_io_dispatch is failure: easy not started WARN easy_client_send (easy_client.c:88) [15980][686][xxx-xxxxxxx] [lt=18] [dc=0] easy_session_dispatch failed: -1 ERROR easy_client_dispatch (easy_client.c:21) [15980][686][xxx-xxxxxxxx] [lt=4] [dc=0] easy_io_dispatch is failure: easy not started ERROR easy_client_dispatch (easy_client.c:21) [15980][686][xxx-xxxxxxxxx] [lt=11] [dc=0] easy_io_dispatch is failure: easy not started ERROR easy_client_dispatch (easy_client.c:21) [15980][686][xxx-xxxxxxxxx] [lt=29] [dc=0] easy_io_dispatch is failure: easy not started ERROR easy_client_dispatch (easy_client.c:21) [15980][686][xxx-xxxxxxxxxx] [lt=12] [dc=0] easy_io_dispatch is failure: easy not started ERROR easy_client_dispatch (easy_client.c:21) [15980][686][xxx-xxxxxxxxxx] [lt=24] [dc=0] easy_io_dispatch is failure: easy not started ERROR easy_client_dispatch (easy_client.c:21) [15885][496][Y0-0000000000000000] [lt=16] [dc=0] easy_io_dispatch is failure: easy not started INFO [RPC.FRAME] ob_net_easy.cpp:374 [16878][0][Y0-0000000000000000] [lt=0] [dc=0] [BATCH_RPC EASY STAT](conn count=0, request done=0, request doing=0) INFO [RPC.FRAME] ob_net_easy.cpp:397 [16894][0][Y0-0000000000000000] [lt=0] [dc=0] [MYSQL EASY STAT](conn count=0, request done=0, request doing=0) INFO [RPC.FRAME] ob_net_easy.cpp:397 [16891][0][Y0-0000000000000000] [lt=0] [dc=0] [MYSQL EASY STAT](conn count=0, request done=0, request doing=0) INFO [RPC.FRAME] ob_net_easy.cpp:329 [16871][0][Y0-0000000000000000] [lt=15] [dc=0] [RPC EASY STAT](conn count=1, request done=6060, request doing=0) INFO [RPC.FRAME] ob_net_easy.cpp:374 [16883][0][Y0-0000000000000000] [lt=0] [dc=0] [BATCH_RPC EASY STAT](conn count=0, request done=0, request doing=0) INFO [RPC.FRAME] ob_net_easy.cpp:374 [16885][0][Y0-0000000000000000] [lt=0] [dc=0] [BATCH_RPC EASY STAT](conn count=0, request done=0, request doing=0) INFO [RPC.FRAME] ob_net_easy.cpp:374 [16887][0][Y0-0000000000000000] [lt=0] [dc=0] [BATCH_RPC EASY STAT](conn count=0, request done=0, request doing=0)租户内存占用高（OB_TEST2_PCODE）。
easy 分配内存的时候，有时不能获取到 pcode，尤其在服务端，这部分内存会被统计到
OB_TEST2_PCODE。当这部分内存高的时候，可以使用命令grep "dump tenant info" observer.log进一步检查是不是瞬间压力大导致的租户队列满导致，也可以通过命令grep "EASY hold"观察 easy 占用内存的变化。
SSL 相关问题。
如 RPC SSL 单边使能。
客户端日志。
INFO easy_connection.c:2375 [53345][0][Y0-0000000000000000] [lt=1] Establishing connection(xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:xxx_xxx_0x7f3a17cf0390 tp=1 t=0-0 s=1 r=0 io=0/0 sq=0), s(0x7f3a40a26810), is_ssl(1).Server 端日志。
INFO [STORAGE] ob_locality_manager.cpp:138 [92197][0][Y0-0000000000000000] [lt=17] [dc=0] rpc connection accept(local_addr="xxx.xxx.xxx.xxx:xxx", dest="xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:xxx_xxx_0x7f2c599f0390 tp=0 t=1623900183006304-0 s=0 r=0 io=0/0 sq=0", use_ssl=false, ssl_invited_nodes=)客户端日志中存在关键词
peer closed connection in SSL handshake。ERROR easy_ssl_handshake (easy_ssl.c:469) [53336][0][Y0-0000000000000000] [lt=4] peer closed connection in SSL handshake BACKTRACE:0xc900f0a 0xc82efd7 0xc8305fb 0xca3847c 0xccbf833 0xccbfa6b 0xccc5192 0xccad46c 0xccc898e 0xccba179 0x7f3df382bdc5 0x7f3df3040d0d INFO [SHARE.PT] ob_partition_location_cache.cpp:3524 [53029][2040][xxx-xxx] [lt=3] server is in blacklist, skip rpc renew(ret=0, server="xxx.xxx.xxx.xxx:xxx") INFO [SHARE.PT] ob_partition_location_cache.cpp:3524 [53073][2128][xxx-xxxx] [lt=3] server is in blacklist, skip rpc renew(ret=0, server="xxx.xxx.xxx.xxx:xxx") ERROR easy_ssl_handshake (easy_ssl.c:469) [53340][0][Y0-0000000000000000] [lt=5] peer closed connection in SSL handshake BACKTRACE:0xc900f0a 0xc82efd7 0xc8305fb 0xca3847c 0xccbf833 0xccbfa6b 0xccc5192 0xccad46c 0xccc898e 0xccba179 0x7f3df382bdc5 0x7f3df3040d0d INFO [SHARE.PT] ob_partition_location_cache.cpp:3524 [53016][2014][xxx-xxxxx] [lt=2] server is in blacklist, skip rpc renew(ret=0, server="xxx.xxx.xxx.xxx:xxx") INFO [SHARE.PT] ob_partition_location_cache.cpp:647 [53029][2040][xxx-xxxxx] [lt=20] renew_location_with_sql success(table_id=1100611139455007, partition_id=0, location={table_id:{value:1100611139455007, first:1001, second:51231}, partition_id:0, partition_cnt:0, pg_key:{tid:18446744073709551615, partition_id:-1, part_idx:268435455, subpart_idx:268435455}, replica_locations:[{server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}], renew_time:1623901059529536, sql_renew_time:1623901059529536, is_mark_fail:false}) INFO [SHARE.PT] ob_partition_location_cache.cpp:3461 [53029][2040][xxx-xxxxxx] [lt=48] location cache not hit, fetch location by partition_table(ret=0, location={table_id:{value:1100611139455007, first:1001, second:51231}, partition_id:0, partition_cnt:0, pg_key:{tid:18446744073709551615, partition_id:-1, part_idx:268435455, subpart_idx:268435455}, replica_locations:[{server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"1xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}], renew_time:1623901059528267, sql_renew_time:1623901059528267, is_mark_fail:false}, new_location={table_id:{value:1100611139455007, first:1001, second:51231}, partition_id:0, partition_cnt:0, pg_key:{tid:18446744073709551615, partition_id:-1, part_idx:268435455, subpart_idx:268435455}, replica_locations:[{server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}], renew_time:1623901059529536, sql_renew_time:1623901059529536, is_mark_fail:false}, expire_renew_time=1623901059528267, cost=1062, lbt()="0xc900f0a 0x92d4ff3 0x92c6374 0x92c697f 0xb165b15 0xb60e9e8 0xb7068b4 0xb706cba 0xb758b80 0xb3d5304 0xb3daf9d 0xb3dc305 0xb2ee415 0xb2eee06 0xb2ef025 0xb6abb6c 0xb6ac1f8 0xb6a205b 0xb60ac42 0xb106698 0xb1146c2 0xb115361 0xb1449d0 0xb115750 0x9bca7c7 0xca44402 0x9c59f59 0x9c53818 0x9c54b2b 0xc6c2bd7 0xc6bfda0 0xc6bec4f") INFO [SHARE.PT] ob_partition_location_cache.cpp:647 [53073][2128][xxx-xxxxxxx] [lt=27] renew_location_with_sql success(table_id=1100611139455007, partition_id=0, location={table_id:{value:1100611139455007, first:1001, second:51231}, partition_id:0, partition_cnt:0, pg_key:{tid:18446744073709551615, partition_id:-1, part_idx:268435455, subpart_idx:268435455}, replica_locations:[{server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}], renew_time:1623901059529985, sql_renew_time:1623901059529986, is_mark_fail:false}) INFO [SHARE.PT] ob_partition_location_cache.cpp:3524 [53051][2084][xxx-xxxxxxxx] [lt=3] server is in blacklist, skip rpc renew(ret=0, server="xxx.xxx.xxx.xxx:xxx") INFO [SHARE.PT] ob_partition_location_cache.cpp:3461 [53073][2128][xxx-xxxxxxxxx] [lt=18] location cache not hit, fetch location by partition_table(ret=0, location={table_id:{value:1100611139455007, first:1001, second:51231}, partition_id:0, partition_cnt:0, pg_key:{tid:18446744073709551615, partition_id:-1, part_idx:268435455, subpart_idx:268435455}, replica_locations:[{server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}], renew_time:1623901059528267, sql_renew_time:1623901059528267, is_mark_fail:false}, new_location={table_id:{value:1100611139455007, first:1001, second:51231}, partition_id:0, partition_cnt:0, pg_key:{tid:18446744073709551615, partition_id:-1, part_idx:268435455, subpart_idx:268435455}, replica_locations:[{server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}], renew_time:1623901059529985, sql_renew_time:1623901059529986, is_mark_fail:false}, expire_renew_time=1623901059528267, cost=1214, lbt()="0xc900f0a 0x92d4ff3 0x92c6374 0x92c697f 0xb165b15 0xb60e9e8 0xb7068b4 0xb706cba 0xb758b80 0xb3d5304 0xb3daf9d 0xb3dc305 0xb2ee415 0xb2eee06 0xb2ef025 0xb6abb6c 0xb6ac1f8 0xb6a205b 0xb60ac42 0xb106698 0xb1146c2 0xb115361 0xb1449d0 0xb115750 0x9bca7c7 0xca44402 0x9c59f59 0x9c53818 0x9c54b2b 0xc6c2bd7 0xc6bfda0 0xc6bec4f") ERROR easy_ssl_handshake (easy_ssl.c:469) [53343][0][Y0-0000000000000000] [lt=6] peer closed connection in SSL handshake BACKTRACE:0xc900f0a 0xc82efd7 0xc8305fb 0xca3847c 0xccbf833 0xccbfa6b 0xccc5192 0xccad46c 0xccc898e 0xccba179 0x7f3df382bdc5 0x7f3df3040d0d ERROR [RPC.OBRPC] resolve_packet_type (ob_rpc_protocol_processor.cpp:235) [53324][0][Y0-0000000000000000] [lt=2] invalid mflag(mflag[0]=22, mflag[1]=3, mflag[2]=1, mflag[3]=0, ret=-4016) BACKTRACE:0xc900f0a 0xc82efd7 0xcaeed97 0xcaecbed 0xcaeba06 0xcaebb75 0xcad7537 0xca407fa 0xccb7798 0xccc5192 0xccad46c 0xccc898e 0xccba179 0x7f3df382bdc5 0x7f3df3040d0d ERROR [RPC.OBRPC] decode (ob_rpc_protocol_processor.cpp:116) [53324][0][Y0-0000000000000000] [lt=34] failed to resolve packet type(ret=-4016) BACKTRACE:0xc900f0a 0xc82efd7 0x3172f65 0xcaebf43 0xcaebced 0xcad7537 0xca407fa 0xccb7798 0xccc5192 0xccad46c 0xccc898e 0xccba179 0x7f3df382bdc5 0x7f3df3040d0d ERROR [RPC.OBRPC] decode (ob_rpc_net_handler.cpp:168) [53324][0][Y0-0000000000000000] [lt=13] failed to decode(easy_conn=0x7f3a25acc610, ms=0x7f3a25afad90, is_current_normal_mode=true, ret=-4016) BACKTRACE:0xc900f0a 0xc82efd7 0xcadbc8e 0xcad8868 0xcad7826 0xca407fa 0xccb7798 0xccc5192 0xccad46c 0xccc898e 0xccba179 0x7f3df382bdc5 0x7f3df3040d0d下面是 Server 短日志，日志中关键词
invalid mflag(mflag[0]=22, mflag[1]=3, mflag[2]=1, mflag[3]=0, ret=-4016)ERROR [RPC.OBRPC] resolve_packet_type (ob_rpc_protocol_processor.cpp:235) [92183][0][Y0-0000000000000000] [lt=10] [dc=0] invalid mflag(mflag[0]=22, mflag[1]=3, mflag[2]=1, mflag[3]=0, ret=-4016) BACKTRACE:0xc900f0a 0xc82c5e2 0xcaee0c9 0xcaeec2a 0xcaecbed 0xcaeba06 0xcaebb75 0xcad7537 0xca407fa 0xccb7798 0xccc5192 0xccad46c 0xccc898e 0xccba179 0x7f30b0a05dc5 0x7f30b021ad0d ERROR [RPC.OBRPC] decode (ob_rpc_protocol_processor.cpp:116) [92183][0][Y0-0000000000000000] [lt=27] [dc=0] failed to resolve packet type(ret=-4016) BACKTRACE:0xc900f0a 0xc82c5e2 0x3172820 0x3172dd5 0xcaebf43 0xcaebced 0xcad7537 0xca407fa 0xccb7798 0xccc5192 0xccad46c 0xccc898e 0xccba179 0x7f30b0a05dc5 0x7f30b021ad0d ERROR [RPC.OBRPC] decode (ob_rpc_net_handler.cpp:168) [92183][0][Y0-0000000000000000] [lt=8] [dc=0] failed to decode(easy_conn=0x7f2c6fb47cc0, ms=0x7f2c6fb86790, is_current_normal_mode=true, ret=-4016) BACKTRACE:0xc900f0a 0xc82c5e2 0xcadb05d 0xcadbb4d 0xcad8868 0xcad7826 0xca407fa 0xccb7798 0xccc5192 0xccad46c 0xccc898e 0xccba179 0x7f30b0a05dc5 0x7f30b021ad0d [2021-06-17 11:23:03.006330] INFO [STORAGE] ob_locality_manager.cpp:138 [92197][0][Y0-0000000000000000] [lt=17] [dc=0] rpc connection accept(local_addr="xxx.xxx.xxx.xxx:xxx", dest="xxx.xxx.xxx.xxx:xxx_xxx.xxx.xxx.xxx:xxx_xxx_0x7f2c599f0390 tp=0 t=1623900183006304-0 s=0 r=0 io=0/0 sq=0", use_ssl=false, ssl_invited_nodes=) ERROR [RPC.OBRPC] resolve_packet_type (ob_rpc_protocol_processor.cpp:235) [92197][0][Y0-0000000000000000] [lt=28] [dc=0] invalid mflag(mflag[0]=22, mflag[1]=3, mflag[2]=1, mflag[3]=0, ret=-4016) BACKTRACE:0xc900f0a 0xc82c5e2 0xcaee0c9 0xcaeec2a 0xcaecbed 0xcaeba06 0xcaebb75 0xcad7537 0xca407fa 0xccb7798 0xccc5192 0xccad46c 0xccc898e 0xccba179 0x7f30b0a05dc5 0x7f30b021ad0d ERROR [RPC.OBRPC] decode (ob_rpc_protocol_processor.cpp:116) [92197][0][Y0-0000000000000000] [lt=59] [dc=0] failed to resolve packet type(ret=-4016) BACKTRACE:0xc900f0a 0xc82c5e2 0x3172820 0x3172dd5 0xcaebf43 0xcaebced 0xcad7537 0xca407fa 0xccb7798 0xccc5192 0xccad46c 0xccc898e 0xccba179 0x7f30b0a05dc5 0x7f30b021ad0d ERROR [RPC.OBRPC] decode (ob_rpc_net_handler.cpp:168) [92197][0][Y0-0000000000000000] [lt=10] [dc=0] failed to decode(easy_conn=0x7f2c599f0390, ms=0x7f2c599f7390, is_current_normal_mode=true, ret=-4016) BACKTRACE:0xc900f0a 0xc82c5e2 0xcadb05d 0xcadbb4d 0xcad8868 0xcad7826 0xca407fa 0xccb7798 0xccc5192 0xccad46c 0xccc898e 0xccba179 0x7f30b0a05dc5 0x7f30b021ad0d INFO [SHARE.PT] ob_partition_location_cache.cpp:3524 [91059][692][xxxxx-xxxxx] [lt=28] [dc=0] server is in blacklist, skip rpc renew(ret=0, server="xxx.xxx.xxx.xxx") ERROR [RPC.OBRPC] resolve_packet_type (ob_rpc_protocol_processor.cpp:235) [92198][0][Y0-0000000000000000] [lt=7] [dc=0] invalid mflag(mflag[0]=22, mflag[1]=3, mflag[2]=1, mflag[3]=0, ret=-4016) BACKTRACE:0xc900f0a 0xc82c5e2 0xcaee0c9 0xcaeec2a 0xcaecbed 0xcaeba06 0xcaebb75 0xcad7537 0xca407fa 0xccb7798 0xccc5192 0xccad46c 0xccc898e 0xccba179 0x7f30b0a05dc5 0x7f30b021ad0d ERROR [RPC.OBRPC] decode (ob_rpc_protocol_processor.cpp:116) [92198][0][Y0-0000000000000000] [lt=28] [dc=0] failed to resolve packet type(ret=-4016) BACKTRACE:0xc900f0a 0xc82c5e2 0x3172820 0x3172dd5 0xcaebf43 0xcaebced 0xcad7537 0xca407fa 0xccb7798 0xccc5192 0xccad46c 0xccc898e 0xccba179 0x7f30b0a05dc5 0x7f30b021ad0d ERROR [RPC.OBRPC] decode (ob_rpc_net_handler.cpp:168) [92198][0][Y0-0000000000000000] [lt=11] [dc=0] failed to decode(easy_conn=0x7f2c5970abf0, ms=0x7f2c59711390, is_current_normal_mode=true, ret=-4016) BACKTRACE:0xc900f0a 0xc82c5e2 0xcadb05d 0xcadbb4d 0xcad8868 0xcad7826 0xca407fa 0xccb7798 0xccc5192 0xccad46c 0xccc898e 0xccba179 0x7f30b0a05dc5 0x7f30b021ad0d INFO [SHARE.PT] ob_partition_location_cache.cpp:3268 [92155][2570][Y0-0000000000000000] [lt=41] [dc=0] add_update_task success(task={table_id:{value:1103909674338510, first:1004, second:51406}, partition_id:0, add_timestamp:1623900183007314, cluster_id:74, type:0}, leader_inactive_async_update=true, now=1623900183007314, location={table_id:{value:1103909674338510, first:1004, second:51406}, partition_id:0, partition_cnt:0, pg_key:{tid:18446744073709551615, partition_id:-1, part_idx:268435455, subpart_idx:268435455}, replica_locations:[{server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"xxx.xxx.xxx.xxx:xxx", role:1, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}, {server:"xxx.xxx.xxx.xxx:xxx", role:2, sql_port:2881, replica_type:0, reserved:0, property:{memstore_percent_:100}}], renew_time:1623899150564296, sql_renew_time:1623899150564296, is_mark_fail:false}, is_nonblock=true)
适用版本
OceanBase 数据库 V2.x，V3.x 版本。
