--- title: OceanBase 数据库中启用 pkt-nio 功能时 RPC 的 fly_ts 耗时长的原因-OceanBase数据库使用指南 description: 了解OceanBase数据库在实际应用中关于 OceanBase 数据库中启用 pkt-nio 功能时 RPC 的 fly_ts 耗时长的原因相关的常见问题和使用技巧，帮助您快速解决 OceanBase 数据库中启用 pkt-nio 功能时 RPC 的 fly_ts 耗时长的原因的难题。 --- 切换语言 - 简体中文 - English 划线反馈 # OceanBase 数据库中启用 pkt-nio 功能时 RPC 的 fly_ts 耗时长的原因 更新时间：2026-04-20 03:36 适用版本： V4.1.x、V4.2.x 内容类型：TechNote - OceanBase 数据库从 V4.2.1 BP3、V4.2.3、V4.3 开始的版本这条日志，在 `send_timestamp` 之后，增加打印了 `peer="xxx.xxx.xxx.xxx:xxxx", sz=xxx` 的信息： ```shell WDIAG [RPC] create (ob_poc_rpc_server.cpp:141) [16163][pnio1][T0][xxxxx-xxxxx-xxxxx-xxxxx] [lt=28][errcode=0] PNIO packet wait too much time between proxy and server_cb(pcode=5402, fly_ts=1000162, send_timestamp=1713240251458326, peer="xxx.xxx.xxx.xxx:xxxx", sz=xxx) ``` - OceanBase 数据库 V4.1 和之前的版本使用 easy 框架处理 RPC，可参见 [packet fly cost too much time](https://www.oceanbase.com/knowledge-base/oceanbase-database-1000000000207690?back=kb) 进行排查。 1. 两台机器之间时钟不同步，使用 clockdiff IP 命令来确认。 2. 网络延迟大，通过 ping 大包来确认。 3. 系统负载高导致，网络、CPU、内存使用异常。 4. OBServer 进程被 gdb 或者 pstack 了，导致线程被暂停。 具体可参考 [packet fly cost too much time](https://www.oceanbase.com/knowledge-base/oceanbase-database-1000000000207690?back=kb) 。 上述，第 1、2 种情况，两台机器之间的 `fly_ts` 通常为一个恒定范围的值，而且 `fly_ts` 的日志会持续打印。 - 查看 `fly_ts` 日志中关于 `fly_ts` 耗时长的 RPC 的发送端地址有哪些。 - 问题可能出现在打印了 `fly_ts` 的 OBServer（RPC 接收端）上，也可能出现在发送端的 OBServer 上。 - 如果对端地址属于不同的 OBServer，大概率是接收端的问题，优先在出现了 fly_ts 的 OBServer 上进行排查。 - 如果发送端地址只有一个，大概率是这个发送端的问题，优先到这个地址的 OBServer上，按照后续步骤查看相关日志和监控进行排查。 - 例如，在测试环境中，一个 IP 上可能会起多个 OBServer，这时候就不好确定地址是否属于不同的 OBServer，需要执行 `lsof -i:port`，来确认这个 port 是属于哪个 OBServer 进程的。 - 如果 fly_ts > 500ms，如果是网络框架层的原因导致的延迟，发送端或者接收端 `pkt-nio` 层通常会打印 `delay_warn` 的相关日志。 - 如果打印的带有 `delay_warn` 的日志里，只有 `[delay_warn] pktc_flush_cb delay high: xxx start_us=xxx` 或者 `[delay_warn] pkts_flush_cb delay high: xxx start_us=xxx` 这样的，基本都是 `socket` 上数据读写慢导致的。 - 可能的原因罗列如下。 1. 主备库之间设置了网络限速，打印 `fly_ts` 日志的线程名都是 `pnio2`，`pcode` 为 0x853（OB_LS_FETCH_LOG2），搜索 `set ratelimit as` 日志可以看到 server 限制的带宽。 2. `tc` 设置了延迟，因为 RPC 的流量压力比较大导致了延迟放大。 3. `tc/iptables` 限制了带宽或者网络本身的带宽不够，而上层发 RPC 的压力比较大，导致了延迟。 4. `socket` 的对端没有及时 read 数据，可能是对端网络 IO 线程 hung 住或者执行慢，需要根据对端的日志中进行排查。 在 `delay_warn` 里打印对端的地址。 2 和 3 在表现上是相同的，都和上层发送 RPC 的压力相关，对于 `pkt-nio` 来说没办法区分是哪一种情况，因为都是 `socket` 发送缓冲区上的数据消耗得慢，最终导致 RPC 请求积压在发送队列上。 - 如果还有 `[delay_warn] eloop handle events delay high` 和 `[delay_warn] cost too much time: xxx, procedure: xxx` 的日志，说明是网络 IO 线程中有一些调用占据了过长的时间，导致 IO 线程没有来得及去处理其它 RPC 请求。这两条日志会打印是什么过程导致了耗时（包括执行 RPC 回调、`deliver` 接收到的 RPC 请求、内存申请、read 系统调用、write 系统调用）。 | 过程 | `[delay_warn] eloop handle events delay high` 的日志 | `[delay_warn] cost too much time: xxx, procedure: xxx` 的日志 | | --- | --- | --- | | 执行RPC回调 | client_cb= '一个比较长的时间' | procedure: pn_pktc_resp_cb | | deliver 接收到的 RPC 请求 | server_process= | procedure: pn_pkts_handle_func | | 内存申请 | malloc= | procedure: mod_alloc | | read 系统调用 | read= | procedure: sk_read | | write 系统调用 | write= | procedure: sk_writev | - deliver 接收到的 RPC 请求是指网络 IO 线程从 socket 里读到数据后，解析成 `ObRequest` 并 deliver 到租户队列的过程，这时候可以继续搜索 `rpc_serve_cb`、`rpc_request_create` 的日志，结合代码进行排查。 - 对于 read 系统调用或者 write 系统调用耗时长的问题，通常是系统可用内存不足、触发了内存直接回收导致的慢（ [xxx]()），这时在网络探活中也有相关日志的打印。 ```shell grep -rn "net_keepalive" observer.log |grep "cost too much time" ``` ## 适用版本 OceanBase 数据库 V4.1.x,V4.2.x 版本。 Previous [网络限速未生效，导致 OceanBase 内核认为机器网卡速率为默认值 1Gbp](https://www.oceanbase.com/knowledge-base/oceanbase-database-1000000006085086) Next [普通用户连接时遇到报错 ERROR 1040 (08004): Too many connections](https://www.oceanbase.com/knowledge-base/oceanbase-database-1000000002356015) ![有帮助](https://gw.alipayobjects.com/mdn/ob_asset/afts/img/A*y6ocSqN8cqsAAAAAAAAAAAAAARQnAQ)![无帮助](https://gw.alipayobjects.com/mdn/ob_asset/afts/img/A*BG9IQJyLHF8AAAAAAAAAAAAAARQnAQ)![反馈](https://gw.alipayobjects.com/mdn/ob_asset/afts/img/A*eTWdQKCRKHwAAAAAAAAAAAAAARQnAQ)[AI](https://www.oceanbase.com/obi) 咨询热线