乐趣区

关于spring:升级到Spring-53x之后GC次数急剧增加我TM人傻了

jiezi

最近咱们我的项目降级到了 Spring Boot 2.4.6 + Spring Cloud 2020.0.x，通过我的另一系列即可看出：Spring Cloud 降级之路。然而降级后，咱们发现 YoungGC 显著增高，调配对象速率显著增高，然而降职的对象并没有增多，证实都是新创建的对象并且没过多久就能够被回收。咱们来看其中一个过程的监控，这时候的 http 申请速率大略在 100 左右：

这就很奇怪了，申请速率并没有那么大，然而通过监控能够看出每秒钟调配了将近两个 G 的内存。在降级之前，这个调配速率大略在 100~200 MB 左右，在等同申请速率下。那么这多进去的内存到底是哪里耗费的呢？

咱们须要看一下 内存中各种对象的统计数据 ，即应用 jmap 命令。同时 不能只查看存活对象的统计，因为从监控中看进去并不是老年代对象过多，因为降职的对象并没有增多，相同的，咱们如果咱们能排除当初还存活的对象就更好了。同时，因为 GC 相当频繁，1s 左右就会有一次。所以根本不能冀望一次就能抓到咱们想要的 jmap。同时 jmap 会导致所有线程进入 safepoint 从而 STW，对线上有肯定影响，所以不能太频繁 jmap。所以，咱们采取如下策略：

  1. 扩容一个实例，之后将一个实例，通过注册核心以及限流器将某个实例的流量切走一半；
  2. 针对这个实例，间断执行 jmap -histo（统计所有对象）以及 jmap -histo:live（仅统计存活对象）；
  3. 反复第二步 5 次，每次距离 100ms，300ms，500ms，700ms；
  4. 去掉限流这个实例的限流，将新扩容的实例敞开。

通过这几次的 jmap 比照，咱们发现 jmap 统计中排在后面的对象类型有一个 spring 框架的：

 num     #instances         #bytes  class name (module)
-------------------------------------------------------
   1:       7993252      601860528  [B (java.base@11.0.8)
   2:        360025      296261160  [C (java.base@11.0.8)
   3:      10338806      246557984  [Ljava.lang.Object; (java.base@11.0.8)
   4:       6314471      151547304  java.lang.String (java.base@11.0.8)
   5:         48170      135607088  [J (java.base@11.0.8)
   6:        314420      126487344  [I (java.base@11.0.8)
   7:       4591109      110100264  [Ljava.lang.Class; (java.base@11.0.8)
   8:        245542       55001408  org.springframework.core.ResolvableType
   9:        205234       29042280  [Ljava.util.HashMap$Node; (java.base@11.0.8)
  10:        386252       24720128  [org.springframework.core.ResolvableType;
  11:        699929       22397728  java.sql.Timestamp (java.sql@11.0.8)
  12:         89150       21281256  [Ljava.beans.PropertyDescriptor; (java.desktop@11.0.8)
  13:        519029       16608928  java.util.HashMap$Node (java.base@11.0.8)
  14:        598728       14369472  java.util.ArrayList (java.base@11.0.8)

这个对象是怎么创立进去的呢？如何定位一个曾经不再存活的频繁创建对象，并且这个对象类型是框架外部的？

首先，MAT（Eclipse Memory Analyzer）+ jmap dump 这种整个堆剖析，并不太实用，起因是：

  1. 对象曾经不再存活，MAT 更适宜对于内存透露的剖析，咱们这里是创立进去很多预期外的对象，占用了大量内存，这些对象很快就不再存活。
  2. MAT 对于不再存活的对象，无奈精确剖析出创建者，次要因为 dump 的时候不确定是否能抓到咱们想要的信息，或者有很多信息噪声。

尽管这个问题不能这么定位，我还是将我采集的 jmap dump 后果放在这里用 MAT 剖析的后果展现进去给大家看下：

那么接下来怎么剖析呢？这就又用到了咱们的老朋友，JFR + JMC。老读者晓得，我常常应用 JFR 定位线上问题，这里怎么应用呢？并没有间接的 JFR 事件统计常常创立哪些对象，然而呢，有间接的事件，能够间接体现是谁创立了这么多对象。我个别这么定位：

  1. 通过线程调配对象统计事件查看是哪个线程调配对象过多（Thread Allocation Statistics）。
  2. 通过热点代码剖析哪些热点代码可能会产生这些对象（Method Profiling Sample）。像这种大量创立的对象，抓取 Runnable 代码很大概率被抓取到，并且在事件中占比高。

首先查看 Thread Allocation Statistics 事件，发现基本上所有 servlet 线程（就是解决 Http 申请的线程，咱们用的 Undertow，所以线程名称是 XNIO 结尾的），调配的对象都很多，这样并不能定位问题：

而后咱们来看热点代码统计，点击 Method Profiling Sample 事件，查看堆栈追踪统计，看哪些占比比拟高。

发现占比靠前的，貌似都和这个 ResolvableType 无关，进一步定位，双击第一个办法查看调用堆栈统计：

咱们发现，调用它的是 BeanUtils.copyProperties。查看其它 ResolvableType 无关的调用，都和BeanUtils.copyProperties 无关。这个办法是咱们我的项目中常常应用的办法，用于同类型或者不同类型之间的属性复制。这个办法为何会创立这么多 ResolvableType 呢？

通过查看源码，咱们发现从 Spring 5.3.x 开始，BeanUtils 开始通过创立 ResolvableType 这个对立类信息封装，进行属性复制：


/**
 * 
 * <p>As of Spring Framework 5.3, this method honors generic type information
 */
private static void copyProperties(Object source, Object target, @Nullable Class<?> editable,
        @Nullable String... ignoreProperties) throws BeansException {}

外面的源码，每次都针对源对象和指标对象的类型的每个属性办法创立了新的 ResolvableType，并且 没有做缓存。这导致一次复制，会创立进去大量的 ResolvableType. 咱们来做个试验：

public class Test {public static void main(String[] args)  {TestBean testBean1 = new TestBean("1", "2", "3", "4", "5", "6", "7", "8", "1", "2", "3", "4", "5", "6", "7", "8");
        TestBean testBean2 = new TestBean();
        for (int i = 0; i > -1; i++) {BeanUtils.copyProperties(testBean1, testBean2);
            System.out.println(i);
        }
    }
}

别离应用 spring-beans 5.2.16.RELEASE 和 spring-beans 5.3.9 这两个依赖去执行这个代码，JVM 参数应用 -XX:+UnlockExperimentalVMOptions -XX:+UseEpsilonGC -Xmx512m. 这些参数的意思是，应用 EpsilonGC，也就是在堆内存满的时候，不执行 GC，间接抛出 OutofMemory 异样并程序完结，并且最大堆内存是 512m。这样，程序其实就是看：在内存耗尽之前，不同版本的 BeanUtils.copyProperties 别离能执行多少次。

试验后果是：spring-beans 5.2.16.RELEASE 是 444489 次，spring-beans 5.3.9 是 27456 次。这是相当大的差距啊。

于是，针对这个问题，我向 spring-framework github 提了个 Issue.

而后，对于我的项目中常常应用 BeanUtils.copyProperties 的中央，替换成应用 BeanCopier，并且封装了一个简略类：

public class BeanUtils {private static final Cache<String, BeanCopier> CACHE = Caffeine.newBuilder().build();

    public static void copyProperties(Object source, Object target) {Class<?> sourceClass = source.getClass();
        Class<?> targetClass = target.getClass();
        BeanCopier beanCopier = CACHE.get(sourceClass.getName() + "to" + targetClass.getName(), k -> {return BeanCopier.create(sourceClass, targetClass, false);
        });
        beanCopier.copy(source, target, null);
    }
}

然而须要留神的是，BeanCopier替换 BeanUtils.copyProperties 最间接的一个问题就是：对于属性不同然而名字不同的无奈复制。例如一个是 int 另一个是  Integer 也不行。同时还有深拷贝的一些区别，须要咱们做好单元测试。

批改好后，问题解决。

微信搜寻“我的编程喵”关注公众号，每日一刷，轻松晋升技术，斩获各种 offer：

退出移动版