年轻代频繁GC ParNew导致http变慢

背景介绍

某日下午大约四点多,接到合作方消息,线上环境,我这边维护的某http服务突然大量超时(对方超时时间设置为300ms),我迅速到鹰眼平台开启采样,发现该服务平均QPS到了120左右,平均RT在2秒多到3秒,部分毛刺高达5到6秒(正常时候在60ms左右)。

qps情况:

在这里插入图片描述

rt情况
[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-Yh5Dkh5l-1691546155736)(/uploads/new2021/images/m_62d7c0b3a62e26f8cc5167dc1669b3ec_r.png)]

问题解决

该服务是一个对内的运营平台服务(只部署了两台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变高。

开始怀疑,是否DB连接池在高并发下出现排队,tddl默认的连接池大小是10.一查监控,整个占用的连接数从来没有超过7个,排除连接池不足的问题。
[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-RvB79KCq-1691546155737)(/uploads/new2021/images/m_2c7e0b0f6b572ac90f9ec5dfb67ab396_r.png)]

至此,造成RT高的原因,在数据库层面被排除。

接着开始查采样到的服务调用链上的每一个执行点,看看到底是调用链上的那部分耗时最多。发现里面很多执行点都有一个特点,就是本地调用耗时特别长(几百毫秒),但是真正的服务调用(比如db查询动作)时间却很短,(0ms代表执行时间小于1ms,也间接印证之前db的平均RT在0.3ms以内)

本地调用耗时: 267ms

客户端发送请求: 0ms

服务端处理请求: 0ms

客户端收到响应: 1ms

总耗时: 1ms

这时候问题逐渐清晰,问题出现在本地方法执行的耗时过长,可是再次检查该服务所有代码,并没有需要长耗时的本地执行逻辑,那么继续看CPU的load情况。

[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-naLsYLu6-1691546155737)(/uploads/new2021/images/m_3382613beb181c991e8e34dd22a4a2b8_r.png)]

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.0317141secs]2105763K->361653K(4019584K),0.0323010secs] [Times: user=0.12sys=0.00, real=0.04secs]

每次占用cpu的时间在0.04s左右,但是由于ParNew GC太过频繁,每分钟最高100次以上,整体占用cpu时间还是很可观。

[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-wLIQ4XwE-1691546155737)(/uploads/new2021/images/m_9dd9bb7ccc92f6f05715c7bdb851f653_r.png)]

看了下jvm内存参数

[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-kZdvSCtN-1691546155738)(/uploads/new2021/images/m_ab6f4b87a3fc19d1701754c6734a7cc1_r.png)]

年轻代分配了2G内存,其中eden区约1.7G

使用jmap查看年轻代对象占用空间情况,排名靠前的有多个org.apache.tomcat.util.buf包下的对象,比如ByteChunk、CharChunk、MessageBytes等,以及响应涉及的一些临时对象列表。其中ByteChunk等即tomcat响应输出相关类

至此问题明确,超大响应包(50K)在发送到网卡的过程中,需要经过从用户态user space拷贝到内核态 kernel space,然后在拷贝到网卡进行发送(像netty等的零拷贝针对的就是这种拷贝),加上响应体查询过程中,涉及的大量临时对象list,在高并发场景下,就导致年轻代内存占满,然后频繁gc(后续在合适的时间会压测该接口),这里还有一个点,很多人以为ParNewGC不会stop the world,其实是会的。频繁ParNewGC造成用户线程进入阻塞状态,让出CPU时间片,最终导致连接处理等待,接口的RT变高。整个排查过程,鹰眼,idb性能监控等可视化监控平台帮助真的很大,否则到处去查日志得查的晕头转向了。

经验总结
接口设计,需要避免超大响应体出现,分而治之,将一个大接口拆分为多个小接口。

缓存设计,像这个服务一样,一个请求带来将近40次DB查询的,需要考虑在服务端进行缓存(当时偷懒了,要求调用方去做缓存)。

性能设计,要对自己负责系统的性能了如指掌,可以通过压测等手段得到自己系统的天花板,否则,某一个接口hang住,会导致整个应用的可用性出现问题。

流量隔离,内部应用和外部流量之间,需要进行流量隔离,即使通过缓存,也有缓存击穿的问题。

口头说的东西都不靠谱,要落在文档上,还需要检查执行情况。

ParNew GC是JVM中的一种垃圾回收器,它是基于并行垃圾回收算法的,主要用于新生的垃圾回收。ParNew GC在垃圾回收时使用多个线程并行地进行垃圾回收,以达到快速回收内存的目的。 ParNew GC与Serial GC的主要区别是:ParNew GC是使用多线程并行处理的,而Serial GC是单线程处理的。在垃圾回收时,ParNew GC将堆内存分成多个区域,然后使用多个线程并行地进行垃圾回收。这样能够有效地减少垃圾回收的时间,提高应用程序的吞吐量。 ParNew GC的垃圾回收过程分为以下几个阶段: 1. 初始标记阶段(Initial Mark):在这个阶段中,ParNew GC暂停应用程序,然后标记出所有根对象以及所有直接引用的对象。 2. 并发标记阶段(Concurrent Mark):在这个阶段中,ParNew GC使用多个线程并发地标记所有存活的对象。这个阶段与应用程序并发执行,所以不造成应用程序的停顿。 3. 重新标记阶段(Remark):在这个阶段中,ParNew GC再次暂停应用程序,然后标记出在并发标记阶段中被引用的对象。 4. 并发清理阶段(Concurrent Cleanup):在这个阶段中,ParNew GC使用多个线程并发地清理无用的对象。这个阶段与应用程序并发执行,所以不造成应用程序的停顿。 ParNew GC的优点是速度快,因为它使用多线程并行处理。另外,它的停顿时间相对较短,对于对响应时间有要求的应用程序来说,ParNew GC是一个不错的选择。但是,ParNew GC也有一些缺点,比如它需要更多的内存来存储垃圾回收信息,而且需要更多的CPU时间来进行垃圾回收。另外,ParNew GC只能用于新生的垃圾回收,不能用于老年的垃圾回收。
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值