2025年服务频繁出现100毫秒的延迟,原因是什么?

服务频繁出现100毫秒的延迟,原因是什么?背景说明 陌陌的微服务框架支持 Redis 协议调用方式 在使用 Redis 协议调用 MOA 服务时 每个请求会被包装为一个消息 这个消息会用一个唯一 ID 来标识 ID 是由机器名称 进程 ID 消息产生的时间戳组成 当请求消息经过网络到达服务端应用后 MOA 框架在处理消息前会先用当前时间减去消息的产生时间 如果差值大于 100 毫秒则会记录该请求到慢请求文件中 正常请求下该文件几乎不会产生数据

大家好,我是讯享网,很高兴认识大家。

背景说明

陌陌的微服务框架支持Redis协议调用方式, 在使用Redis协议调用MOA服务时, 每个请求会被包装为一个消息, 这个消息会用一个唯一ID来标识,ID是由机器名称+进程ID+消息产生的时间戳组成,当请求消息经过网络到达服务端应用后,MOA框架在处理消息前会先用当前时间减去消息的产生时间,如果差值大于100毫秒则会记录该请求到慢请求文件中。正常请求下该文件几乎不会产生数据,但是最近多名业务侧同学反馈慢请求文件数据较多,导致TP90数据飙高,希望帮忙排查原因。

排查过程

是否是容器问题?

陌陌的应用层全部跑在Docker容器上,为了排查容器自身因素,将该服务的部分实例迁到了VM上,对比发现VM上的实例基本上没有慢请求日志,所有基本确定该问题跟Docker容器相关。

网络不稳?

2018-12-18 12:23:40,822 REQUEST: Command [id=xxxxxxx-kube-node-web-php-

7020.6728, action=/service/xxxx-action-service, source=127.0.0.1, thread=, params={args=[ap], m=getXxxRecReadNum}] waitedTime: 103 ms

对比消息产生时间和服务端接收到数据包时间可知消息传递的网络耗时几乎可忽略,排除网络不稳定带来的影响。

网卡到socket读缓存区慢了?

通过上面tcpdump结果来说,数据从网卡到ReveiveQ再到用户态获取数据这一个过程也是及时的,为了再次验证这个结论,运维同学通过systemtap工具在tcp_v4_do_rcv调用时,将skb的内容打印出来,并将调用时间打印出来,通过比较系统调用时间和skb中的消息时间比对发现基本一致。

//probe kernel.statement("tcp_rcv_established@net/ipv4/t
讯享网
小讯
上一篇 2025-04-03 07:45
下一篇 2025-01-04 17:03

相关推荐

版权声明:本文内容由互联网用户自发贡献,该文观点仅代表作者本人。本站仅提供信息存储空间服务,不拥有所有权,不承担相关法律责任。如发现本站有涉嫌侵权/违法违规的内容,请联系我们,一经查实,本站将立刻删除。
如需转载请保留出处:https://51itzy.com/kjqy/12215.html