江苏龙网

  1. 首页 > 资讯 > 科技 > >

|不起眼的YGC，居然对应用的RT影响这么大

【|不起眼的YGC，居然对应用的RT影响这么大】
背景介绍
某日下午大约四点多 ， 接到合作方消息 ， 线上环境 ， 我这边维护的某http服务突然大量超时（对方超时时间设置为300ms） ， 我迅速到鹰眼平台开启采样 ， 发现该服务平均QPS到了120左右 ， 平均RT在2秒多到3秒 ， 部分毛刺高达5到6秒（正常时候在60ms左右） 。
qps情况：
|不起眼的YGC，居然对应用的RT影响这么大
本文插图

rt情况：
|不起眼的YGC，居然对应用的RT影响这么大
本文插图

问题解决
该服务是一个对内的运营平台服务（只部署了两台docker）预期qps个位数 ， 近期没做过任何的线上发布 ， 核心操作是整合查询数据库 ， 一次请求最多涉及40次左右的DB查询 ， 最终查询结果为一个多层树形结构 ， 一个响应体大约50K 。 之前口头跟调用方约定要做缓存 ， 现在看到QPS在120左右 ， （QPS证明没有做缓存） ， 遂要求对方做缓存 ， 降低QPS 。 后QPS降到80以内 ， rt恢复正常（平均60ms） ， 最终QPS一直降到40（后续需要推动调用方引入缓存 ， 保证QPS在个位数） 。
问题定位
由于该服务核心操作是查询数据库 ， 且一次请求有40次DB query ， 遂首先排查是否慢sql导致 ， 查看db性能监控 ， 发现db 平均rt在0.3ms以内 ， 可以算出来DB整体耗时在12ms左右 ， 排除慢sql导致RT变高 。
|不起眼的YGC，居然对应用的RT影响这么大
本文插图

开始怀疑 ， 是否DB连接池在高并发下出现排队 ， tddl默认的连接池大小是10.一查监控 ， 整个占用的连接数从来没有超过7个 ， 排除连接池不足的问题
|不起眼的YGC，居然对应用的RT影响这么大
本文插图

至此 ， 造成RT高的原因 ， 在数据库层面被排除 。
接着开始查采样到的服务调用链上的每一个执行点 ， 看看到底是调用链上的那部分耗时最多 。 发现里面很多执行点都有一个特点 ， 就是本地调用耗时特别长（几百毫秒） ， 但是真正的服务调用（比如db查询动作）时间却很短 ， (0ms代表执行时间小于1ms ， 也间接印证之前db的平均RT在0.3ms以内)
本地调用耗时: 267ms 客户端发送请求: 0ms 服务端处理请求: 0ms 客户端收到响应: 1ms 总耗时: 1ms这时候问题逐渐清晰 ， 问题出现在本地方法执行的耗时过长 ， 可是再次检查该服务所有代码 ， 并没有需要长耗时的本地执行逻辑 ， 那么继续看CPU的load情况
|不起眼的YGC，居然对应用的RT影响这么大
本文插图

load长时间在4左右徘徊 ， 我们的docker部署在4c8G的宿主机上 ， 但是我们不能独占这个4C的 ， 持续这么高的load已经不正常了 。 继续追查cpu load飙高的原因 ， 接着去看GC日志 ， 发现大量的Allocation Failure ， 然后ParNew次数在每分钟100次以上 ， 明显异常 ， 见下GC日志例子
2020-03-25T16:16:18.390+0800: 1294233.934: [GC (Allocation Failure) 2020-03-25T16:16:18.391+0800: 1294233.935: [ParNew: 1770060K->25950K(1922432K), 0.0317141 secs] 2105763K->361653K(4019584K), 0.0323010 secs] [Times: user=0.12 sys=0.00, real=0.04 secs]每次占用cpu的时间在0.04s左右 ， 但是由于ParNew GC太过频繁 ， 每分钟最高100次以上 ， 整体占用cpu时间还是很可观
|不起眼的YGC，居然对应用的RT影响这么大
本文插图

看了下jvm内存参数
Heap Configuration: MinHeapFreeRatio= 40 MaxHeapFreeRatio= 70 MaxHeapSize= 4294967296 (4096.0MB) NewSize= 2147483648 (2048.0MB) MaxNewSize= 2147483648 (2048.0MB) OldSize= 2147483648 (2048.0MB) NewRatio= 2 SurvivorRatio= 10 MetaspaceSize= 268435456 (256.0MB) CompressedClassSpaceSize = 1073741824 (1024.0MB) MaxMetaspaceSize= 536870912 (512.0MB) G1HeapRegionSize= 0 (0.0MB)年轻代分配了2G内存 ， 其中eden区约1.7G


推荐阅读


上一篇：驱动之家|《脱口秀大会》罗永浩出金句：我这辈子第一次被人家说不了解这行业

下一篇：拍卖|滴滴：无法辨别拍卖平台疑似滴滴股权出售方身份暂无IPO计划