[JVM]一次线上频繁GC的问题解决

落日映苍穹つ 2021-12-23 00:07 310阅读 0赞

起因：周末测试发现线上mq消息积压了十几万的消息，如下图所示

![1355099-20190307225326086-231055655.png][]

每个队列几万的消息，立即采取紧急措施，将队列下线重新上线。

处理积压消息的量，调用量起来了，很快消息积压解决了。开始事件复盘。

![1355099-20190307231718232-1196190196.png][]

首先分析是否是消息消费能力跟不上消息产生原因，看入口消息，QPS是29.6

![1355099-20190307232907872-384560745.png][]

消息消费QPS如下

![1355099-20190307233041229-720305022.png][]

事后开始分析原因，发现队列积压有如下异常：

![1355099-20190307233821179-249548725.png][]

![1355099-20190307233718210-20831394.png][]

超时时间设置的很长，大致分析出消息处理线程等待下游接口超时，连接下游接口设置的超时时间很长，为什么下游接口如此多SocketTimeOut呢？

然后查看具体的超时接口，调用的下游站点发生SocketTimeout

![1355099-20190307234316383-1508430546.png][]

查看下游站点接口的Cat，发现调用时间极不规律，如下图所示

![1355099-20190307234846029-998463798.png][]

看日常的调用时间如下图所示，都不超过100ms的：

![1355099-20190307235016097-926593616.png][]

再看部分机器的GC内存回收，惊呆了，因为这个站点有几个月没有重新发过版本，发现GC如下图，压根没有年轻代的事，新申请的对象都需要在老年代申请，所以导致老年代一直回收。

![1355099-20190308000411455-1843377205.png][]

找一台机器，把GC回收dump下来分析，使用mat查看，如下图所示：

![1355099-20190308001024580-314634600.png][]

一共七百多M空间，一个对象就占了640M空间，找到原因了，继续往下，看这个对象为什么会这么大，从GC Roots最短路径如下，解释下

Shallow Heap指的是对象本身占据的内存大小 Retained Heap = 本身本身占据内存大小 + 当前对象可直接或间接引用到的对象的大小总和，

换句话说，就是当前对象如果被回收，能够回收的内存大小。

![1355099-20190308001716504-1257983692.png][]

继续看，第一步，查看谁引用了这个对象，找到自己代码中的类，

![1355099-20190308002437628-1022607240.png][]

第二步，查看这个对象TaggedMetricRegistry都引用了谁，为什么会占用这么大的内存空间，如下图所示，

![1355099-20190308002633986-1719299578.png][]

找到罪魁祸首了， 现在开始可以看下代码，如下所示：

![1355099-20190308002820541-696632373.png][]

发现 TaggedMetricRegistry继承自MetricRegistry，如下图

metrics是个Map，MetricRegistry的成员变量，继续回来看mat，看内部内存占用

![1355099-20190308003002932-327810984.png][]

如下图所示，发现Map的有几个Node节点尤其大，

![1355099-20190308003320613-1155322425.png][]

追下去，继续

![1355099-20190308003826316-1243550752.png][]

看到这个key，对应在代码中的位置，

![1355099-20190308004332667-563128527.png][]

开始代码分析，这个代码的作用是统计接口每次的执行时间，统计窗口是1分钟，问题就出现在这，因为这个函数的QPS非常高，在update的源码如下：

private final ConcurrentSkipListMap<Long, Long> measurements; 
    
     @Override
        public void update(long value) {
            if (count.incrementAndGet() % TRIM_THRESHOLD == 0) {
                trim();
            }
            measurements.put(getTick(), value);
        }

private long getTick() {
        
        for (; ; ) {
        
            final long oldTick = lastTick.get();
            final long tick = clock.getTick() * COLLISION_BUFFER;
            // ensure the tick is strictly incrementing even if there are duplicate ticks
            final long newTick = tick > oldTick ? tick : oldTick + 1;
            if (lastTick.compareAndSet(oldTick, newTick)) {
        
                return newTick;
            }
        }

private void trim() {
        
        measurements.headMap(getTick() - window).clear();
    }

measurements是一个跳跃表，在1分钟有数据频繁产生的时候，会导致在一个时间窗口（1分钟）measurements极速增长，导致内存快速增长，所以产生频繁Yong GC，把这个Metric统计取消，问题Fixed。

转载于:https://www.cnblogs.com/zhengwangzw/p/10493562.html

[1355099-20190307225326086-231055655.png]: /images/20211220/7ec9d11b72bf430cb2233a9af1e118db.png
[1355099-20190307231718232-1196190196.png]: /images/20211220/00477469addd4a3cb44c40863b391dc3.png
[1355099-20190307232907872-384560745.png]: /images/20211220/8f13fd19e939453a87d56aed89f5b49e.png
[1355099-20190307233041229-720305022.png]: /images/20211220/8c4e3e4d4d1e458dafa5b513dff3452e.png
[1355099-20190307233821179-249548725.png]: /images/20211220/1701c7387ff64cdf9b0c120c3bdbe5f7.png
[1355099-20190307233718210-20831394.png]: /images/20211220/1e52187ca51a4009868adc61bd9cb0d1.png
[1355099-20190307234316383-1508430546.png]: /images/20211220/07de741af1ad4237af444e85a1e6b36f.png
[1355099-20190307234846029-998463798.png]: /images/20211220/7e1e9eecab934ff9af96bac874643d00.png
[1355099-20190307235016097-926593616.png]: /images/20211220/18bd78df63ae4fe8be0ac03b4da07184.png
[1355099-20190308000411455-1843377205.png]: /images/20211220/4fdb672e63e4485980bb38fe3fe58a1e.png
[1355099-20190308001024580-314634600.png]: /images/20211220/4ce18ef4d4ef428d8362bc3e0765c0e2.png
[1355099-20190308001716504-1257983692.png]: /images/20211220/bac70a234bde4efdadf4c19e9652470e.png
[1355099-20190308002437628-1022607240.png]: /images/20211220/d39eb00b056548838023c3855832d14b.png
[1355099-20190308002633986-1719299578.png]: /images/20211220/98b584d176f14bb181a6b13bbca45d8e.png
[1355099-20190308002820541-696632373.png]: /images/20211220/c4bda5dd06e44e26963b04188442676a.png
[1355099-20190308003002932-327810984.png]: /images/20211220/a2a165a98e8a4000957ec159d2c1d303.png
[1355099-20190308003320613-1155322425.png]: /images/20211220/0c6f0e5ae43d42249ef9b365ec9e1e42.png
[1355099-20190308003826316-1243550752.png]: /images/20211220/ec28a9a447f946eb8fc77a4b9fd337c2.png
[1355099-20190308004332667-563128527.png]: /images/20211220/77f4e374000148379761fc578a1beec5.png