1.现象
大量用户反映不能正常使用服务,导致用户无法进行下一步工作。
2.检查
因为是休息日,初步听到这个消息的时候怀疑是自己的锅。一是因为项目刚刚进行了重构;二是对MySQL数据进行了迁移,并且对待迁移的旧数据进行了数据分析与调整。此次用户反馈的问题也是项目重构之后也是第一次上线,所以首先怀疑是自己写的代码问题,但是代码都是经过几轮测试之后才正式上线的,应该问题不大;其次怀疑是数据迁移导致的问题,因为历史原因,之前的数据在创建的时候很不规范,所以在迁移的时候进行数据分析时比较麻烦,会导致迁移后的数据与旧数据对应不上。
然后立马打车赶到公司查看服务线上日志。先查看调用方的日志,发现确实是进入到服务提供方(此次重构的服务)之后就出现问题了,顿时心凉半截,想着多怕是自己写的代码问题。然后立马又去查看我的服务,居然发现并不是代码问题,而是显示连接不上redis了。
然后立马反馈给组长,组长说找运维看一下redis的堆栈信息,原本想着是redis是因为负载太大而崩溃了,但是运维反馈redis运行正常 。
我也查看了nacos上配置的redis最大连接数为32,也没啥问题。然后再查看服务引入的redis依赖包,因为该依赖包是公司自研的,并且我在其基础上添加了redis加锁重试机制,因为报错的地方就是在执行加锁重试那一块代码,所以我怀疑是这部分代码的问题。但是经过我的检查,这部分代码也没有什么大问题,不管是释放连接、手动释放锁、给锁加了过期时间,这些都是做了的。
然后我将排查的结果反馈给组长,组长在经过进一步排查之后,说是服务内存问题。他查看了服务内存使用情况,居然发现内存使用的曲线图波动很大。
堆内存在增加到最大堆内存之前,一直没进行回收。
现在就要看为什么出现这种情况了。
可能性有2:
1、分配了过多的大的对象直接到老年代,导致内存直接被打满。但是到达最大堆内存时,又能直接进行回收,没有出现OOM,那么说明对象不是不可回收的对象。
2、新生代、老年代比例异常。导致过多的对象直接生成在新生代,新生代等到内存达到一定阈值才会进行回收。符合这一特征。
那么接下来就是检查JVM参数
"corpora-ability" : ["devName": "cat-corpora-ability", "contextPath": "/corpora-ability", "xmx": "16G", "xmn": "16G", "limit-m": "18G", "cpu": "4", "request-m": "18Gi", "enableMetrics": "true"],
"corpora-business" : ["devName": "cat-corpora-business", "contextPath": "/corpora-business", "xmx": "8G", "xmn": "8G", "limit-m": "10Gi", "cpu": "4", "request-m": "10Gi", "enableMetrics": "true"]
居然发现错误的配置xmn : 16G 和8G ,导致新生代的内存和整个堆内存一致。
也就是JVM在分配对象的时候,会一直分配内存直到打满整个堆内存,此时进行回收。新生代大多数都是可以直接回收的对象。所以内存马上就降下来了。但是因为一次性需要回收大量对象,STW过长。系统在GC期间,其它线程会受影响。所以redis的问题是表象之一。
STW最高能达到3S左右,此时很多心跳检测都会失效。
3.处理
修改xmn配置,重启服务。我想着16g内存,给新生代分配差不多三分之一的内存就行,没想到组长说只需要分配1g就可以。那行吧,听组长的....