线上内存泄漏!如何破案

作者:rangobai,腾讯CSIG数据工程师
| 导语要有性能意识,量变引起质变,简单如一行日志都会在高并发的情况引发血案,考验着研发的技术功底
一 案件背景
9月的某个上午,业务侧突然反馈线上数据服务响应慢,造成任务积压,正常情况下耗时5ms的服务,单次响应达到了5s量级. 收到反馈后我们马上开始排查服务状况,但发现各项指标很健康,接口平均耗时3ms,p99约为1s,和经验值比无太大差别. 业务侧随后补充反馈是某些请求很慢,感觉是若干pod有问题,当流量打到这几台机器时就会变慢.
开始怀疑是网络问题,但没有证据.随后小库网关的一台机器突然宕机,这个现象引起了我们注意.在上次迭代中,我们服务有一次重大升级,所有请求均会经过网关服务转发,以实现Server/DB单元化绑定,问题可能出在转发环节.
为了验证猜想,我们重启了网关,随后业务侧积压现象迅速消失,排查范围锁定网关服务.
二 调查过程
小库网关本身无太多业务逻辑,依赖项非常少,为了实现时间最小损耗,技术框架采用spring cloud gateway,底层WebFlux 则使用了高性能的 Reactor 模式.在上线前的多次压测中,网关服务表现非常优秀,时间损耗基本在毫秒级别.万万没想到上线没几天就挖了个大坑,必须要刨根问底调查清楚
2.1 第一次定位
由于刚迁移到新私密机房,可用于问题还原的监控手段不多,刚开始只能从查看pod云监控以及日志着手.
首先查看日志异常 :可以看到确实有大量PT5S超时存在,但是根据traceId追踪大多数超时请求在服务侧均为毫秒级响应.
其次查看业务侧请求量变化:虽然我们服务有过qps破万的表现,但是问题时间段请求量异常的平稳,甚至略有降低.
最后查看问题时间段性能表现:cpu在40%左右,无突增现象.Pod内存监控由于JVM提前分配,无太大参考价值.I/O流量在问题时间段没有波动.
磁盘满了
此时没有清晰的调查方向,就在我们黔驴技穷的时候,又一台网关pod重启了,我们同学迅速登录机器,查看案发现场-磁盘爆满, 200G的云硬盘在上线的两天内就被打满,请求block.线上请求量其实大大超出我们的预估,生产日志量接近10G/小时/台, 日志保留7天的策略顿时显得不合时宜.
【线上内存泄漏!如何破案】随后我们清理了所有pod的日志,并采取了两个策略:

  • 日志清理策略设为保留1天,因为有日志本身上报cls,保留太久日志没有必要
  • 清理无效日志,打印要有技巧性,不是越多越好,高并发下对服务伤害性越大.
修改上线后,服务运行平稳,再也没出现上午的问题,调查小组愉快的度过了第一天.
2.2 第二次定位
就在以为我们万事大吉的时候,现实光速打脸,第二天早上8点半,生命线里出现大量异常警告,随后网关服务陆续重启,登录机器,磁盘利用率10%,尴了个尬.
CPU问题三板斧
因为自动重启没有保留案发现场,所以只能在昨天的基础上继续调查.
第一个合理怀疑的方向是CPU,虽然CPU利用率40%不能算很高, 但网关和业务机器比达到了1:2,对于仅转发请求的网关来说仍然是不正常的高了.排查此类问题就要启动CPU问题三板斧了
第一板斧: jps查看JAVA进程ID 46
第二板斧: top -Hp 46 查看进程所有线程的活动
可以看出仍然是log4j2的101线程占用了最多的CPU能力,
最后一板斧: jstack pid 查看线程活动,以定位线程堆栈
线上内存泄漏!如何破案

文章插图
这个时候,日志打印占用了最多cpu已经一目了然.
最大利器Arthas
但是作为成熟的研发,我们当然不满足于三板斧调查问题,这时候就要请出线上另一大杀器arthas :profiler | arthas,以下介绍来自官网:
Arthas 是一款线上监控诊断产品,通过全局视角实时查看应用 load、内存、gc、线程的状态信息,并能在不修改应用代码的情况下,对业务问题进行诊断,包括查看方法调用的出入参、异常,监测方法执行耗时,类加载信息等,大大提升线上问题排查效率Arthas(阿尔萨斯)能为你做什么?这个类从哪个 jar 包加载的?为什么会报各种类相关的 Exception?我改的代码为什么没有执行到?难道是我没 commit?分支搞错了?遇到问题无法在线上 debug,难道只能通过加日志再重新发布吗?线上遇到某个用户的数据处理有问题,但线上同样无法 debug,线下无法重现!是否有一个全局视角来查看系统的运行状况?有什么办法可以监控到 JVM 的实时运行状态?怎么快速定位应用的热点,生成火焰图?怎样直接从 JVM 内查找某个类的实例?


推荐阅读