跳到主要内容

记一次项目线上的内存暴增以及解决办法

image.png

前景提要​

项目上线了，在开发时一切正常，运行正常，项目上线后，还没运行一个星期，发现项目运行越来越慢，进入后台管理界面用了30秒。当时刚听到这个消息，“怎么可能！！！内测，都还没几个人用呢”，直到我自己打开系统，等了好久才进入系统，信了。

线索追踪​

查看错误日志​

知道系统出现了问题，但是线上的系统我又碰不到，申请下，运维人员带我去了机房，真是戒备森严。查看错误日志，没有关键的信息。想让运维人员给我把错误日志拿出来，我回去研究研究，被语气很强硬的直接否决了。。。

查看程序运行状态​

使用

px -aux |grep ***

定位程序pid

top -p <PID>

查看程序占用内存 虽然这个系统比较大，但是占用的内存达到了4GB，真是可怕。

jmap查看线上程序运行的内存信息​

jmap -histo <PID>

刷刷刷一段文字，上一张本地演示的图，是之后在本地复现的截图 image.png 简单的说说这个图里有啥

  • num:序号
  • instances：实例对象
  • bytes：占用的大小
  • class name：类名称,B就是byte[],C就是char[]，I就是int[],如果还有S的话就是short[]了，

发现了情况， “byte[]怎么这么多！！！项目中有用到什么byte[]吗？,好像没有啊。可能是其他对象产生的，比如文件流，写入写出之类的。啊，我想到了，不会有人流的处理没有close掉吧“ 询问了运维人员能不能拍照，既然拿不出里面的文件，拍照可以的吧。 运维：- 不行！想什么呢！

没办法，再看看其他的

看看堆信息​

jmap -heap <PID>

image.png 当时的情况记不太清了，随便看了几眼，脑袋还在想着之前byte[]的事。

既然都来了，那多看点其他的信息，

查看gc的情况​

jstat -gc <PID> 1000(间隔时间) 10000(次数)

image.png 图片里面

  • S0C:第一个幸存区大小
  • S1C:第二个幸存区大小
  • S0U:第一个幸存区的使用大小
  • S1U:第二个幸存区的使用大小
  • EC：伊甸园的大小
  • EU：伊甸园区的使用大小
  • OC：老年代大小
  • OU：老年代使用大小
  • MC：方法区大小（元空间）
  • MU：方法区使用大小
  • CCSC：压缩类空间使用大小
  • YGC：年轻代垃圾回收次数
  • YGCT：年轻代垃圾回收消耗时间，单位：s
  • FGC：老年代垃圾回收次数
  • FGCT：老年代垃圾回收消耗时间，单位：s
  • GCT：垃圾回收消耗总时间，单位：s

当时的情况是，Full GC触发的数量极其之多，然后我直接用手机请求一次外网地址看看,还没点几下功能，直接触发Full GC了。一脸黑线，还好运维没看懂我在干嘛，不然真的够尴尬的。 一般来说，Full GC几小时触发，或者几天触发一次才正常，而young GC几分钟，几小时触发一次才正常，这种情况下，记下了我刚刚点的那几个功能，那部分的代码很有可能有问题。

感觉看的差不多了，运维也一直催我ok没有，因为是下班时间，再看看有没有死锁吧。

使用jstack查找死锁​

顺便写一下jstack的使用，那会儿还好我带着平板去的，可以直接查我平板上的资料

1.使用top -p <PID>,显示java进程的内存情况，pid是java进程号 2.按H，获取每个线程的内存情况 3.找到内存和cpu占用最高的线程id 4.转为16进制得到线程的16进制表示0x2365 5.执行jstack <PID>|grep -A 10 2365,得到线程堆栈信息中2365这个线程所在行的后面10行 6.查看对应的堆栈信息找出可能存在问题的代码

ok，没有死锁

问题重现​

其实这部分在本地进行重现的话还是很容易就做到了，毕竟线上内存32G的机器不到7天就出问题，本地可以直接使用工具jvisualvm，jprofile等实时监控。 这里我使用的就是jprofile了，还是一个挺强大的工具。

jprofile使用​

项目启动​

当项目进行启动后，不进行访问，还是挺正常的，used size不超过500M image.png

正常请求​

开始进行请求访问，瞬间就增加到2G image.png

手动触发GC​

手动触发一次GC后，那么剩下来的，那就肯定是不能被GC回收的垃圾对象了 image.png

查看live memory​

果不其然，就是byte[]占的最多 image.png

对象分析​

对选中的对象进行选中显示 image.png 进入界面 image.png

关键点来了 使用选中的对象 image.png outgoing表示选中对象产生的对象 incoming表示是谁产生的这些对象，这里当然选择的是incoming image.png

进入界面 image.png 然后选中其中一个 image.png 进入界面 image.png image.png 然后我发现一个很重要的东西 image.png

什么，竟然是tomcat产生的！messageBytes,根据我对netty的理解，说的是入站处理器对消息的解码操作。​

破案​

我再看了其他的byte[]都是如此，难道tomcat才是真凶？？？可是？！ 灵光一闪，想起tomcat的配置项，肯定是什么地方配置有问题

删除所有的tomcat配置项​

然后重新进行启动，监控 image.png 并没有解决，可是byte[]明明指向的就是tomcat，难不成是我搞错了？ 我再想想刚刚的messageBytes，意味着请求，当一个请求进来时，导致的内存增加，netty会怎么进行处理呢？

！！！想到了，删除请求的所有配置！！！​

比如：

server:
  port: 82
  max-http-header-size: 102400000

spring:
  http:
    multipart:
      max-file-size: 100MB
      max-request-size: 10MB

servlet:
     multipart:
       max-file-size:  10MB
       max-request-size:  20MB

重新启动，请求，监控

image.png

完美！果然，就是某个参数配置出现了问题。现在只需要找出是哪个配置项有问题就行，顶多试5次，运气比较好，第一次就中了，就是

max-http-header-size: 102400000

配置出现的问题，百度一下这个参数的作用 image.png

果然我不是被坑的一个人。 看了看git的提交日志，找到同事问了问为啥加这个参数，这些都是后话了，涉及到具体的业务场景，至此结案。

总结​

对于参数的一些配置从网上直接copy的时候最好明白参数的含义，这样才知道为什么要用这个参数，以及针对业务场景进行优化代码。每个小细节的优化才能凑成大的优化，期望调整2，3个参数就能把性能提高2，30%是不现实的，即使是Eleastic-Search也做不到吧。 对于代码底层的理解也能更加方便我们找到问题所在，而不是瞎猜问题，之前出现这个问题后，一直以为是ehcache导致的问题。毕竟程序是死的，真正解决问题的是人。