提供方耗时正常,调用方毛刺频频
作者:京东零售 王森
一 现象
调用方 A -> JSF -> 提供方 B
大多数情况下,调用方耗时 和 提供方耗时 基本没有差别
个别情况下,调用方耗时 远高于 提供方耗时,大概 5 分钟 20+次
1.调用方 A 耗时如下图
2.提供方 B 耗时如下图
3.调用方监控添加
在调用 JSF 接口前后加的监控,没有其他任何逻辑,包括日志打印
4.提供方监控添加
在代码最外层 JSF 接口加的监控,之外没有任何代码逻辑
5.耗时对比
二 排查思路
1.数据流转环节分析
调用方从请求到接收数据,除了提供方业务耗时,还有其他环节,分别是
1.调用方容器和宿主机
2.调用方->提供方经过的网络环节
3.提供方容器和宿主机的环节
4.提供方->调用方的网络环节
2.初步定位
容器和宿主机之间由于流量过大,处理压力大导致的瓶颈
网络波动
一步一步排除,先看网络
3.找证据
3.1 找监控
找到监控相关的技术同学,回答说没有网络的监控
于是找到了 JDOS 的同学,排查后提供了一种怀疑方向,如下图
容器内存使用率(包含 cache)基本一直保持在 99%以上,建议先确定该指标的影响,并降低该指标
3.1.2 指标含义
指标定义文档解释如下
还是看不太懂指标的含义,懵 B 状态
提工单咨询,给出的解决方案如下
java 应用,无 ngix,还是懵,继续求助
最后得出结论:
这个之前在营销中心那边有遇到 C++ 使用 page cache 还有使用 zgc 的 需要参考一下 cache 这个指标,其他的场景 目前看 系统会在物理内存不够用的时候 释放 cache;
这个是指有的 c++应用底层接口直接使用了 pagecache,java 可以忽略
更详细解释:
内存那部分是这样的,每个容器的 Memory Cgroup 在统计每个控制组的内存使用时包含了两部分,RSS 和 Page Cache。
RSS 是每个进程实际占用的物理内存,它包括了进程的代码段内存,进程运行时需要的堆和栈的内存,这部分内存是进程运行所必须的。
Page Cache 是进程在运行中读写磁盘文件后,作为 Cache 而继续保留在内存中的,它的目的是为了提高磁盘文件的读写性能。(Java 程序只要操作磁盘读写也会用到 page cache)
有时会看到这样一种情况:容器里的应用有很多文件读写,你会发现整个容器的内存使用量已经很接近 Memory Cgroup 的上限值了,但是在容器中我们接着再申请内存,还是可以申请出来,并且没有发生 OOM。那是因为容器中有部分是 PageCache,当容器需要更多内存时,释放了 PageCache,所以总大小并没有变化。
结论:对于 java 系统来说,容器内存使用率(包含 cache)没有影响(cache 会自动释放)
3.1.3 降低容器内存使用率(包含 cache)
虽说没有影响,还是想办法降低试试效果(非常相信大佬)
看了其他几个 java 集群
看到最后一个图,小小分析了下,发现三个小时会降低一波,正好和日志清除的时间间隔一致。
对提供方 B 清除日志后发现果然降低,如下
但是毛刺依然存在!!
3.2 容器处理性能瓶颈
扩容前,CPU 和内存也处于正常水平
扩容后(汇天 4 台 -> 汇天 8 台),CPU 和内存没啥太多变化
调用方耗时如下,基本没啥变化,头大
3.3 耗时分析
运维的同事帮忙分析了一波,给出年轻代 GC 耗时较高可能会影响耗时;如下
找了两个毛刺的数据,找到对应提供方的机器,查看那一分钟内有 yanggc 耗时(分钟的粒度),计算下来,调用方耗时比较接近 提供方耗时+提供方 yanggc 耗时,但是没有直接采取措施,主要一下原因
1.yanggc 粒度比较粗,分钟级
2.一直认为 FullGC 会导致 STW,增加耗时,yangGc 不会有太大影响
3.只有一两次的数据分析,数据也没有那么准确
4.备战期间,线上机器封板,动起来比较麻烦,想找下其他原因,双管齐下
3.4 网络对抓 + PFinder
1.调用方多台机器,提供方也是多台机器,网络抓包要想抓全得 N*M,比较费劲
2.PFinder 也是随机抓包
3.毛刺也是随机产生的
想保证,抓到毛刺请求,且,PFinder 有数据,采取如下对策
1.选择调用方的一台机器 X 提供方的一台机器,进行抓包
2.监控调用方的这台机器的 UMP 监控
3.调用方的 UMP 监控有毛刺时,查看是否有 PFinder 监控数据,如果没有则继续抓,有则停止
最后抓到了想要的数据
网络运维的同事帮忙对抓网络包,左边是调用方,右边是提供方,如下
调用方的 PFinder 的数据如下
提供方代码开始 PFinder 的数据如下
数据分析后结论如下:
调用方 22:24:50.775730 发出 22:24:50.988867 收到 耗时 213ms
提供方 22:24:50.775723 收到数据包,等到 22:24:50.983 才处理,22:24:50.988776 处理结束回包
提供方等待 208ms 左右,实际处理 4.55ms,加起来 213 左右,和调用方耗时对应上了
网络抓包是从容器到容器的抓包
阻塞原因猜测:
1.容器瓶颈,处理不过来 - CPU、内存正常,且当天下午扩容一倍,没有明显好转
2.yanggc 照成延迟 - 和运维同学张宪波大佬分析的不谋而合,且是有数据支撑的
4.处理
1.目的:降低 yanggc 耗时(没有 FullGC)
2.当前:
3.方式:
1.增大堆内存(年轻代)
2.扩容(已经扩了一次,没有明显变化)
3.mq 消费流量切到其他分组(一般先反序列化,根据参数过滤),减少新对象创建
4.结果:
调用方耗时如下
提供方耗时如下
提供方 yanggc
调整前后调用方耗时
最终提供方和调用方耗时不一致的问题得到解决
版权声明: 本文为 InfoQ 作者【京东科技开发者】的原创文章。
原文链接:【http://xie.infoq.cn/article/685b53f5ba1c6fd1d08eabcac】。文章转载请联系作者。
评论