OceanBase ODP -4016 报错排查：分布式事务路由 + 大 SQL 触发的通信异常

转载自：瑞蓝创

作者简介：邓枭，瑞蓝创数据库工程师

在 OceanBase 生产环境中，开启分布式事务路由后偶现数据库通信链路失败，应用侧抛出Communications link failure，ODP 日志报-4016错误，这一问题多由分布式事务路由重试与大 SQL 超出缓冲区限制共同触发。本文结合实际生产报错堆栈，从问题现象、根因分析到落地解决方案，完整拆解该问题的排查与解决过程。

【问题描述】

JDBC连接OB偶尔会报错连接断开，JDBC堆栈如下：

[ERROR] [ConsumeMessageThread_12 | xxxx | xxx |xxxx] druid.sql.Statement - {conn-19206, pstmt-200668233} execute error. 
com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 5 milliseconds ago.  The last packet sent successfully to the server was 5 milliseconds ago.
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1121)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3673)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3562)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4113)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2570)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2731)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2818)
at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2157)
at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:1379)
at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_execute(FilterChainImpl.java:3461)
at com.alibaba.druid.filter.FilterEventAdapter.preparedStatement_execute(FilterEventAdapter.java:440)
at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_execute(FilterChainImpl.java:3459)
at com.alibaba.druid.filter.FilterEventAdapter.preparedStatement_execute(FilterEventAdapter.java:440)
at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_execute(FilterChainImpl.java:3459)
at com.alibaba.druid.proxy.jdbc.PreparedStatementProxyImpl.execute(PreparedStatementProxyImpl.java:167)
at com.alibaba.druid.pool.DruidPooledPreparedStatement.execute(DruidPooledPreparedStatement.java:497)
at org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:41)
at org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:66)
at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:45)
at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:100)
at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:75)
at sun.reflect.GeneratedMethodAccessor940.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.apache.ibatis.plugin.Invocation.proceed(Invocation.java:46)
at cn.com.servyou.xqy.framework.daoframework.interceptor.PanDaoInterceptor.interceptForCacheUpdate(PanDaoInterceptor.java:179)
at cn.com.servyou.xqy.framework.daoframework.interceptor.PanDaoInterceptor.intercept(PanDaoInterceptor.java:50)
at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:57)
at com.sun.proxy.$Proxy109.update(Unknown Source)
at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:148)
at cn.com.servyou.xqy.framework.daoframework.PanSqlSessionTemplate$9.doInSqlSession(PanSqlSessionTemplate.java:326)
at cn.com.servyou.xqy.framework.daoframework.PanSqlSessionTemplate.executeWith(PanSqlSessionTemplate.java:449)
at cn.com.servyou.xqy.framework.daoframework.PanSqlSessionTemplate.update(PanSqlSessionTemplate.java:348)
at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:49)
at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:43)
at com.sun.proxy.$Proxy113.updateInvoiceStatus(Unknown Source)
at sun.reflect.GeneratedMethodAccessor1901.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:302)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
at cn.com.servyou.i7boot.log.interceptor.AbstractDigestLogInterceptor.invoke(AbstractDigestLogInterceptor.java:21)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:208)
at com.sun.proxy.$Proxy114.updateInvoiceStatus(Unknown Source)
at cn.com.servyou.invoice.core.input.impl.InputInvoiceCoreServiceImpl.doNormalUpdate(InputInvoiceCoreServiceImpl.java:1619)
at cn.com.servyou.invoice.core.input.impl.InputInvoiceCoreServiceImpl.updateInvoiceStatusForCollect(InputInvoiceCoreServiceImpl.java:1498)
at cn.com.servyou.invoice.core.collect.storages.input.InputInvoiceStorage.saveOrUpdateInvoices(InputInvoiceStorage.java:360)
at cn.com.servyou.invoice.core.collect.storages.input.InputInvoiceStorage.saveOrUpdateInvoices(InputInvoiceStorage.java:102)
at cn.com.servyou.invoice.core.collect.storages.AbstractInvoiceStorage.storeInvoices(AbstractInvoiceStorage.java:105)
at cn.com.servyou.invoice.core.collect.storages.input.InputInvoiceStorage.storeInvoices(InputInvoiceStorage.java:966)
at cn.com.servyou.invoice.core.collect.impl.AbstractInvoiceCollectService$2.executeService(AbstractInvoiceCollectService.java:1359)
at cn.com.servyou.invoice.core.collect.impl.AbstractInvoiceCollectService$2.executeService(AbstractInvoiceCollectService.java:1349)
at cn.com.servyou.xqy.framework.rpc.facadeimpl.ServiceTemplateImpl$1.doInTransactionWithoutResult(ServiceTemplateImpl.java:71)
at org.springframework.transaction.support.TransactionCallbackWithoutResult.doInTransaction(TransactionCallbackWithoutResult.java:34)
at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:133)
at cn.com.servyou.xqy.framework.rpc.facadeimpl.ServiceTemplateImpl.execute(ServiceTemplateImpl.java:67)
at cn.com.servyou.xqy.framework.rpc.facadeimpl.ServiceTemplateImpl.executeWithTx(ServiceTemplateImpl.java:29)
at cn.com.servyou.invoice.core.collect.impl.AbstractInvoiceCollectService.storeInvoices(AbstractInvoiceCollectService.java:1349)
at cn.com.servyou.invoice.core.collect.impl.AbstractInvoiceCollectService.doCollect(AbstractInvoiceCollectService.java:1296)
at cn.com.servyou.invoice.core.collect.impl.AbstractInvoiceCollectService.doNormalInvoiceCollectByBatch(AbstractInvoiceCollectService.java:1204)
at cn.com.servyou.invoice.core.collect.impl.AbstractInvoiceCollectService.doCollectByBatch(AbstractInvoiceCollectService.java:1196)
at cn.com.servyou.invoice.core.collect.impl.AbstractInvoiceCollectResolveService.doCollectResolve(AbstractInvoiceCollectResolveService.java:228)
at cn.com.servyou.invoice.core.collect.impl.AbstractInvoiceCollectResolveService.lambda$newCollect$0(AbstractInvoiceCollectResolveService.java:79)
at cn.com.servyou.invoice.core.common.impl.MultithreadingExecuteServiceImpl.execute(MultithreadingExecuteServiceImpl.java:46)
at cn.com.servyou.invoice.core.collect.impl.AbstractInvoiceCollectResolveService.newCollect(AbstractInvoiceCollectResolveService.java:78)
at cn.com.servyou.invoice.core.collection.service.impl.InternalInvoiceCollectHandlerServiceImpl.doStorageInvoice(InternalInvoiceCollectHandlerServiceImpl.java:995)
at cn.com.servyou.invoice.core.collection.service.impl.InternalInvoiceCollectHandlerServiceImpl.doStorageInvoice(InternalInvoiceCollectHandlerServiceImpl.java:967)
at cn.com.servyou.invoice.core.collection.service.impl.InternalInvoiceCollectHandlerServiceImpl.doExecute(InternalInvoiceCollectHandlerServiceImpl.java:377)
at cn.com.servyou.invoice.core.collection.service.impl.InternalInvoiceCollectHandlerServiceImpl.execute(InternalInvoiceCollectHandlerServiceImpl.java:184)
at cn.com.servyou.invoice.consumer.collect.NewAbstractInternalInvoiceCollectConsumer.executeCollection(NewAbstractInternalInvoiceCollectConsumer.java:135)
at cn.com.servyou.invoice.consumer.collect.ScInternalInvoiceCollectConsumer.doMessage(ScInternalInvoiceCollectConsumer.java:52)
at sun.reflect.GeneratedMethodAccessor3136.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:216)
at com.servyou.elephant.mq.listener.DefaultMessageConsumer.invokeMethod(DefaultMessageConsumer.java:42)
at com.servyou.elephant.mq.listener.DefaultMessageConsumer.consume(DefaultMessageConsumer.java:73)
at com.servyou.elephant.mq.exceptionhandler.ExceptionHandlerMessageConsumer.consume(ExceptionHandlerMessageConsumer.java:40)
at com.servyou.elephant.mq.idempotent.IdempotentMessageConsumer.consume(IdempotentMessageConsumer.java:54)
at com.servyou.elephant.mq.retrylimit.RetryLimitMessageConsumer.consume(RetryLimitMessageConsumer.java:46)
at com.servyou.elephant.mq.retrylimit.RetryLimitMessageConsumer$$FastClassBySpringCGLIB$$7a274d6e.invoke()
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:720)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
at cn.com.servyou.i7boot.log.interceptor.MessageQueueLogInterceptor.invoke(MessageQueueLogInterceptor.java:49)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:655)
at com.servyou.elephant.mq.retrylimit.RetryLimitMessageConsumer$$EnhancerBySpringCGLIB$$c7368e5b.consume()
at cn.com.servyou.invoice.core.common.rocketmq.decorator.CompanyRouterMessageConsumer.consume(CompanyRouterMessageConsumer.java:51)
at com.servyou.elephant.mq.listener.RocketMQMessageListener.consume(RocketMQMessageListener.java:59)
at com.servyou.elephant.mq.listener.RocketMQMessageListener.access$200(RocketMQMessageListener.java:27)
at com.servyou.elephant.mq.listener.RocketMQMessageListener$DefaultMessageListenerConcurrently.consumeMessage(RocketMQMessageListener.java:110)
at org.apache.rocketmq.client.impl.consumer.ConsumeMessageConcurrentlyService$ConsumeRequest.run(ConsumeMessageConcurrentlyService.java:411)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3119)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3573)

堆栈信息中的：

Expected to read 4 bytes, read 0 bytes

The last packet successfully received from the server was 5 milliseconds ago. The last packet sent successfully to the server was 5 milliseconds ago.

表示是ODP主动断连而非客户端断连，耗时5ms。

ODP对应的日志：

2025-05-26 11:22:0310.102.48.1
appName：localproxy
dbName：xxxxx
dbType：OB_MYSQL
errorCode：-4016
logicDbName：
logicTableName：xxx
rpcId：
sqlCommand：COM_QUERY
sqlText：update xxx%0A             SET compared = '0'%2C%0A                %0A                %0A                    deductive_status = '2'%2C%0A                %0A                %0A                    deductive_month = ''%2C%0A                %0A                %0A                    in_counseling_period = '2'%2C%0A                %0A                %0A                    certification_type = '0'%2C%0A                %0A                %0A                    certification_date = ''%2C%0A                %0A
sqlType：UPDATE
success：failed
tableName：xxxx
time：2025-05-26 11:22:03.652269
traceId：

【触发场景/是否复现】

开启了分布式事务路由：

ALTER PROXYCONFIG SET enable_ob_protocol_v2 = true;
ALTER PROXYCONFIG SET enable_transaction_internal_routing = true;

由于分布式事务路由的ob参与者节点无法执行multiQueries需要二次路由到协调者节点，这个动作是odp进行第二次的内部重试路由。而当sql大小超过4KB将会报错，这个长度由request_buffer_length控制。

检查jdbcUrl 是否配置：allowMultiQueries=true

偶现，可复现

【关键诊断信息】

关键报错信息：

ODP日志这段表示需要重试路由，而报错是OB抛出来的错误码是-6279，需要复现抓对应的ob日志确认原因。

get err pkt from observer, not forward to client, will be consumed soon, and maybe need retry,

TRANS_FREE_ROUTE_NOT_SUPPORTED_ERROR,errcode:6279,

sqlstate:”HY000″, message:”Query is not supported to be executed on txn temporary node”

obproxy.log.20250526112254:[2025-05-26 11:22:03.630022] INFO  [PROXY] handle_client_resp (ob_partition_processor.cpp:394) [40059][Y0-00007FA46AC216A0] [lt=0] [dc=0] get partition entry from remote succ((entry={{this:0x7fa466de2a90, ref_count:2, cr_version:3, cr_id:0, create_time_us:1748229723630005, last_valid_time_us:1748229723630005, last_access_time_us:1748229723630005, last_update_time_us:0, schema_version:1733967398955832, tenant_version:0, time_for_expired:0, state:"AVAIL"}, this:0x7fa466de2a90, pl:{replica_count:2, locations:[[0]{server:"10.102.xxx.181:2881", rpc_server:"10.xx.xx.181:2882", is_dup_replica:false, role:"LEADER", type:"FULL"}, [1]{server:"10.102.xx.112:2881", rpc_server:"10.xx.xx.112:2882", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}]}, has_dup_replica:false, tenant_id:1018, table_id:501442, partition_id:201380})
obproxy.log.20250526112254:[2025-05-26 11:22:03.630056] INFO  [PROXY] handle_client_resp (ob_partition_processor.cpp:406) [40059][Y0-00007FA46AC216A0] [lt=0] [dc=0] new partition entry is the same with old one, will renew last_update_time and avoid refequently updating((updating_entry={{this:0x7fa4633f71d0, ref_count:3, cr_version:3, cr_id:0, create_time_us:1748229701545400, last_valid_time_us:1748229701545400, last_access_time_us:1748229723197762, last_update_time_us:1748229701545422, schema_version:1733967398955832, tenant_version:9103565175292255228, time_for_expired:0, state:"DELETED"}, this:0x7fa4633f71d0, pl:{replica_count:2, locations:[[0]{server:"10.102.xx.181:2881", rpc_server:"10.102.xxx.181:2882", is_dup_replica:false, role:"LEADER", type:"FULL"}, [1]{server:"10.102.xx.112:2881", rpc_server:"10.102.xxx.112:2882", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}]}, has_dup_replica:false, tenant_id:1018, table_id:501442, partition_id:201380}, entry={{this:0x7fa466de2a90, ref_count:2, cr_version:3, cr_id:0, create_time_us:1748229723630005, last_valid_time_us:1748229723630005, last_access_time_us:1748229723630005, last_update_time_us:1748229723630036, schema_version:1733967398955832, tenant_version:9103565175292255228, time_for_expired:0, state:"AVAIL"}, this:0x7fa466de2a90, pl:{replica_count:2, locations:[[0]{server:"10.102.xx.181:2881", rpc_server:"10.102.xx.181:2882", is_dup_replica:false, role:"LEADER", type:"FULL"}, [1]{server:"10.102.xx.112:2881", rpc_server:"10.102.xx.112:2882", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}]}, has_dup_replica:false, tenant_id:1018, table_id:501442, partition_id:201380})
obproxy.log.20250526112254:[2025-05-26 11:22:03.651802] WDIAG [PROXY.TXN] handle_error_resp (ob_mysql_transact.cpp:4557) [40059][Y0-00007FA46AC216A0] [lt=0] [dc=0] trace_log(s.trace_log_=[trans_start], proxy_sessid:749339937844992013, coordinator:{10.102.xx.181:2881}, sql_cmd:3, stmt_type:27 | [get_conn], time:1748229723649196446, lookup:0, sql_cmd:3, stmt_type:27, in_trans:1, internal_route:1, svr:{10.102.xx.112:2881}, sessid:3225410314 | [send_sess], type:2528 | [get_error], code:6279, trace_id: | dropped=0)
obproxy.log.20250526112254:[2025-05-26 11:22:03.651820] WDIAG [PROXY.TXN] handle_error_resp (ob_mysql_transact.cpp:4990) [40059][Y0-00007FA46AC216A0] [lt=0] [dc=0] get err pkt from observer, not forward to client, will be consumed soon, and maybe need retry((send_action="SERVER_SEND_REQUEST", state="RESPONSE_ERROR", error_type="TRANS_FREE_ROUTE_NOT_SUPPORTED_ERROR", resp={is_trans_completed:false, is_resp_completed:true, ending_type:2, is_partition_hit:true, has_new_sys_var:false, has_proxy_idc_name_user_var:false, is_server_db_reset:false, reserved_ok_len_of_mysql:0, reserved_ok_len_of_compressed:0, connection_id:0, scramble_buf:"", is_resultset_resp:false, server_capabilities_lower_.capability:0, ok_packet_action_type:2, last_ok_pkt_len:75, rewritten_last_ok_pkt_len:0, extra_info:{is_exist_sess_info:false, sess_info_count:0, extra_len:0}, error_pkt:field_count:255, errcode:6279, sqlstate:"HY000", message:"Query is not supported to be executed on txn temporary node"})
obproxy.log.20250526112254:[2025-05-26 11:22:03.651851] INFO  [PROXY.TXN] handle_oceanbase_retry_server_connection (ob_mysql_transact.cpp:5965) [40059][Y0-00007FA46AC216A0] [lt=0] [dc=0] transaction internal routing retry(s.trans_info_.sql_cmd_=3)
obproxy.log.20250526112254:[2025-05-26 11:22:03.651854] INFO  [PROXY.TXN] handle_oceanbase_retry_server_connection (ob_mysql_transact.cpp:6006) [40059][Y0-00007FA46AC216A0] [lt=0] [dc=0] pre try failed, will retry((retry_status=FOUND_EXISTING_ADDR, attempts now=2, max_connect_attempts=3, old_target_server={10.102.xx.112:2881}, retry server={10.102.xx.181:2881}, is_first_request=false, is_auth_request=false, is_force_renew=false, force_retry_congested=false, send_action="SERVER_SEND_REQUEST", state="RESPONSE_ERROR", route={consistency_level:"STRONG", cur_chosen_route_type:"ROUTE_TYPE_LEADER", cur_chosen_server:{idc_type:"", zone_type:"Invalid", replica:{server:"10.102.xx.112:2881", rpc_server:"10.102.xx.112:2882", is_dup_replica:false, role:"LEADER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, cur_chosen_pl:null, valid_count:0, leader_item:{idc_type:"", zone_type:"Invalid", replica:NULL, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:true}, ldc_route:{policy:"", disable_merge_status_check:true, curr_cursor_index:0, next_index_in_site:0, location:{use_ldc:false, idc_name:"", item_count:0, site_start_index_array:[[0]0, [1]0, [2]0, [3]0], item_array:null, pl:null, ts:null, readonly_exist_status:"READONLY_ZONE_UNKNOWN"}}, is_table_entry_from_remote:false, is_part_entry_from_remote:false, need_use_dup_replica:false, use_proxy_primary_zone_name:false, table_entry:0x7fa46ab492f0, part_entry:0x7fa460c47470, dummy_entry:null, skip_leader_item:true}, is_reroute_to_coordinator=true, is_in_trans=true, is_internal_routing=true, s.congestion_entry={ref_count:13, this:0x7fa46bc5e6d0, zone_state:{ref_count:5, this:0x7fa46bc554e0, zone_name:"cn-hangzhou-h-z0", region_name:"cn-hangzhou", state:"ACTIVE", last_revalidate_time_us:1748005522623868}, server_ip:{10.102.xx.112:2881}, server_state:"ACTIVE", entry_state:"ENTRY_AVAIL", alive_congested:0, last_alive_congested:0, last_revalidate_time_us:1748005522623977, dead_congested:0, detect_congested:0, stat_alive_failures:0, stat_conn_failures:0, cr_version:3, conn_last_fail_time=0, conn_failure_events=0, alive_last_fail_time=0, alive_failure_events=0})
obproxy.log.20250526112254:[2025-05-26 11:22:03.651930] WDIAG [PROXY.TXN] build_oceanbase_ob20_user_request (ob_mysql_transact.cpp:3345) [40059][Y0-00007FA46AC216A0] [lt=0] [dc=0] unexpected buffer len check(ret=-4016, req_buf_avail=4094, client_request_len=7441)
obproxy.log.20250526112254:[2025-05-26 11:22:03.651935] WDIAG [PROXY.TXN] build_oceanbase_user_request (ob_mysql_transact.cpp:3237) [40059][Y0-00007FA46AC216A0] [lt=0] [dc=0] fail to build oceanbase ob20 user request(ret=-4016, client_request_len=7441, next_compress_seq=0)
obproxy.log.20250526112254:[2025-05-26 11:22:03.651937] WDIAG [PROXY.TXN] build_user_request (ob_mysql_transact.cpp:3181) [40059][Y0-00007FA46AC216A0] [lt=0] [dc=0] fail to build oceanbase user request(ret=-4016)
obproxy.log.20250526112254:[2025-05-26 11:22:03.651940] WDIAG [PROXY.TXN] build_server_request (ob_mysql_transact.cpp:3535) [40059][Y0-00007FA46AC216A0] [lt=0] [dc=0] fail to build user request(ret=-4016)
obproxy.log.20250526112254:[2025-05-26 11:22:03.651943] WDIAG [PROXY.SM] setup_server_request_send (ob_mysql_sm.cpp:9455) [40059][Y0-00007FA46AC216A0] [lt=0] [dc=0] failed to build server request(buf_start=NULL, ret=-4016)
obproxy.log.20250526112254:[2025-05-26 11:22:03.651944] WDIAG [PROXY.SM] handle_api_return (ob_mysql_sm.cpp:3687) [40059][Y0-00007FA46AC216A0] [lt=0] [dc=0] failed to setup_server_request_send(sm_id=450315, ret=-4016)
obproxy.log.20250526112254:[2025-05-26 11:22:03.651948] INFO  [PROXY.SS] do_io_close (ob_mysql_server_session.cpp:153) [40059][Y0-00007FA46AC216A0] [lt=0] [dc=0] server session do_io_close((*this={ss_id:597717, server_sessid:3224451742, server_ip:{10.102.xxx.181:2881}, is_inited:true, magic:19136237, state:1, server_vc:0x7fa468ccf050, client_session:{this:0x7fa45866e090, is_proxy_mysql_client:false, is_waiting_trans_first_request:false, need_delete_cluster:false, is_first_dml_sql_got:true, vc_ready_killed:false, active:false, magic:19132429, conn_decrease:true, current_tid:40059, cs_id:534228, proxy_sessid:749339937844992013, session_info:{is_inited:true, priv_info:{has_all_privilege:false, cs_id:534228, user_priv_set:0, cluster_name:"xx", tenant_name:"xx", user_name:"xx"}, version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:13924, sys_var_version:6037, user_var_version:1, db_name_version:1, last_insert_id_version:6024, sess_info_version:147381}, hash_version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:0, sys_var_version:0, user_var_version:0, db_name_version:0, last_insert_id_version:0, sess_info_version:0}, val_hash:{common_hot_sys_var_hash:0, common_cold_sys_var_hash:0, mysql_hot_sys_var_hash:0, mysql_cold_sys_var_hash:0, hot_sys_var_hash:0, cold_sys_var_hash:0, user_var_hash:0}, global_vars_version:0, is_global_vars_changed:false, is_trans_specified:false, is_user_idc_name_set:false, is_read_consistency_set:false, idc_name:"", cluster_id:0, real_meta_cluster_name:"", safe_read_snapshot:1, syncing_safe_read_snapshot:0, route_policy:1, proxy_route_policy:3, user_identity:0, global_vars_version:0, is_read_only_user:false, is_request_follower_user:false, obproxy_force_parallel_query_dop:1, ob20_request:{remain_payload_len:0, ob20_request_received_done:false, ob20_header:{ob 20 protocol header:{compressed_len:0, seq:0, non_compressed_len:0}, magic_num:0, header_checksum:0, connection_id:0, request_id:0, pkt_seq:0, payload_len:0, version:0, flag_.flags:0, reserved:0}}, client_cap:0, server_cap:637767, last_server_addr:{10.102.xx.112:2881}, last_server_sess_id:3225410314, has_send_init_sql:true, lock_session_num:0}, dummy_ldc:{use_ldc:true, idc_name:"cn-hangzhou-i", item_count:8, site_start_index_array:[[0]0, [1]4, [2]8, [3]8], item_array:[[0]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"10.102.xx.181:2881", rpc_server:"10.102.xx.181:2882", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [1]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"10.102.xx.162:2881", rpc_server:"10.102.48.162:2882", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [2]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"10.102.xx.179:2881", rpc_server:"10.102.48.179:2882", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [3]{idc_type:"SAME_IDC", zone_type:"ReadWrite", replica:{server:"10.102.xx.180:2881", rpc_server:"10.102.48.180:2882", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [4]{idc_type:"SAME_REGION", zone_type:"ReadWrite", replica:{server:"10.102.xxx.111:2881", rpc_server:"10.102.xx.111:2882", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [5]{idc_type:"SAME_REGION", zone_type:"ReadWrite", replica:{server:"10.102.xxx.112:2881", rpc_server:"10.102.xx.112:2882", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [6]{idc_type:"SAME_REGION", zone_type:"ReadWrite", replica:{server:"10.102.xxx.109:2881", rpc_server:"10.102.xxx.109:2882", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}, [7]{idc_type:"SAME_REGION", zone_type:"ReadWrite", replica:{server:"10.102.xxx.110:2881", rpc_server:"10.102.xxx.110:2882", is_dup_replica:false, role:"FOLLOWER", type:"FULL"}, is_merging:false, is_partition_server:false, is_force_congested:false, is_used:false}], pl:null, ts:0x7fa469e522b0, readonly_exist_status:"READONLY_ZONE_NOT_EXIST"}, dummy_entry:0x7fa45d0c7e50, server_state_version:2, cur_ss:0x7fa465b3f1d0, bound_ss:null, lii_ss:0x7fa45b7fa1b0, lock_ss:null, closed_key_ss:null, cluster_resource:{this:0x7fa46e4ffb80, ref_count:3108, is_inited:true, cluster_info_key:{cluster_name:{config_string:"xx"}, cluster_id:0}, cr_state:"CR_AVAIL", version:3, last_access_time_ns:1748229723652050913, deleting_completed_thread_num:0, fetch_rslist_task_count:0, fetch_idc_list_task_count:0, last_idc_list_refresh_time_ns:1748228974291449549, last_rslist_refresh_time_ns:1748005522475226188, server_state_version:2}, client_vc:0x7fa46ac30b60, using_ldg:false, using_service_name:false, trace_stats:NULL}, transact_count:27443, server_trans_stat:1, session_info:{cap:637767, ob_server:, version:{common_hot_sys_var_version:0, common_sys_var_version:0, mysql_hot_sys_var_version:0, mysql_sys_var_version:0, hot_sys_var_version:13924, sys_var_version:6037, user_var_version:1, db_name_version:1, last_insert_id_version:6017, sess_info_version:147381}, val_hash:{common_hot_sys_var_hash:0, common_cold_sys_var_hash:0, mysql_hot_sys_var_hash:0, mysql_cold_sys_var_hash:0, hot_sys_var_hash:0, cold_sys_var_hash:0, user_var_hash:0}, checksum_switch:1, server_type:1}}, server_vc_=0x7fa468ccf050, this=0x7fa465b3f1d0)

复现后定位observer日志：multi stmt is not supported to be executed on txn temporary node

observer.log.20250527103936107:[2025-05-27 10:39:11.873140] WDIAG [SERVER] process (obmp_query.cpp:273) [45288][T1018_L0_G0][T1018][YB420A662C70-000629C52DBFF2BB-0-0] [lt=68][errcode=-6279] multi stmt is not supported to be executed on txn temporary node(ret=-6279, ret="OB_TRANS_FREE_ROUTE_NOT_SUPPORTED", tx_free_route_ctx={tx_id:{txid:20558604169}, txn_addr:"10.102.xxx.181:2882", is_proxy_support:true, in_txn_before_handle_request:true, can_free_route:true, is_fallbacked:false, static_changed:false, dynamic_changed:false, parts_changed:false, extra_changed:false, calculated:false, flag:{v:0}, local_version:27632, global_version:54736, global_version_water_mark:54735, state_sync_infos:{[{last_backend_sess_id:3224579810, last_version:54735}, {last_backend_sess_id:3224579810, last_version:54736}, {last_backend_sess_id:3224579810, last_version:54736}, {last_backend_sess_id:3224579810, last_version:54735}, ]}, audit_record:268439297}, trans_id={txid:20558604169}, session={this:0x7f4955b5c1f8, id:3225307649, deser:false, tenant:"xx", tenant_id:1018, effective_tenant:"xx", effective_tenant_id:1018, database:"xx", user:"xx@%", consistency_level:3, session_state:1, autocommit:false, tx:0x7f0a4ea64080})