线上gc问题-SpringActuator的坑

整体复盘：

一个不算普通的周五中午，同事收到了大量了cpu异常的报警。根据报警表现和通过arthas查看，很明显的问题就是内存不足，疯狂无效gc。而且结合arthas和gc日志查看，老年代打满了，gc不了一点。既然问题是内存问题，那么老样子，通过jmap和heap dump 文件分析。
不感兴趣的可以直接看结论

• 通过jmap命令查看的雷同下图，并没有项目中明显的自界说类，而占空间最大的又是char数组，当时线上占900M左右，整个老年代也就1.8个G；此时dump文件同事还在下载，网速较慢。
  
  
  
  
• 通过业务日志查看，很多restTempalte哀求报错，根据报错信息可知是某xx认证过期了，导致接收到回调，业务处理时调接口报错了；查询数据库，大概有20多万回调。根据过期时间和内存监控，大概能对的上号，表明内存异常和这个认证过期有关。怀疑度最高的只有回调以及回调补偿任务，但是一行一行代码看过去，并不觉得有什么异常。
  下载完dump文件后，先重启了服务器，制止影响业务，然后动手分析文件。
  
• 在dump文件下载完之后，使用jvisualvm分析，最多的char里大部分都是一些哀求的路径，如“example/test/1"，”“example/test/2"之类的，都是接口统一，但是参数不一样，由于是GET哀求，以是现实路径都不一样。Jvisualvm点击gc_root又一直计算不出来，在等待计算的过程中，一度走了弯路
  
  
  
  于是又现下载jprofiler，通过jprofiler的聚类，确定了一定是这个Meter导致的，而通过JProfile的分析，终于定位到是
  org.springframework.boot.actuate.metrics.web.client.MetricsClientHttpRequestInterceptor#intercept这个类。然后发现，MetricsClientHttpRequestInterceptor 持有一个meterRegistry，内里焦点是个map，以是是map没有清除。根据依赖分析，发现是有次需求引入了redisson-spring-boot-starter，而redisson依赖了spring-boot-starter-actuator，这东西默认启动了，会拦截所有的RestTempalte哀求，然后记载一些指标。
  
  
  
  
  
  
  

以是问题变成了，为什么map没有清掉已经执行完的哀求？
我之前并没有研究过spring的actuator，只是看过skywalking的流程，以是我以为也和skywalking一样，记载然后上报，上报之后删除本地的。以是当时怀疑，难道是和我们哀求都异常了有关，但是正如下面的代码，无论是否异常，都是执行finnally，以是又不太可能。
meterRegistry点击查看代码

1. ClientHttpResponse response = null;
2. try {
3.    response = execution.execute(request, body);
4.    return response;
5. }
6. finally {
7.    try {
8.       getTimeBuilder(request, response).register(this.meterRegistry).record(System.nanoTime() - startTime,
9.             TimeUnit.NANOSECONDS);
10.    }
11.    catch (Exception ex) {
12.       logger.info("Failed to record metrics.", ex);
13.    }
14.    if (urlTemplate.get().isEmpty()) {
15.       urlTemplate.remove();
16.    }
17. }

复制代码

而在我自己尝试复现之后，meterRegistry的指标根本不会被自动清除，生命周期和应用的生命周期一样。由于并不存在上报，数据全部在内存（虽然可以导出到数据库，但并没有深入研究）。实在也公道，由于如果要通过Grafana等可视化平台查看的时候，我们也希望查看任意时刻的监控。而且其有一个属性是maxUriTags，默认值是100，其作用是限制meterMap里uri的个数，理论上并不会记载太多。
结论

以是到此为止，可以定结论，那就是由于引入了redisson-spring-boot-starter，导致不知情引入了spring-boot-starter-actuator。
因此默认开启了http.client.request指标的监控，关于http.client.request，有一个属性是maxUriTags，默认值是100，其作用是限制meterMap里uri的个数。但是maxUriTags起作用的地方MeterFilter没有生效。
由于maxUriTags没有生效，导致监控信息里的uri由于业务大量的GET哀求中存在唯一id，本身就很占内存。压死内存的最后稻草是认证过期和补偿任务。补偿任务为保证实时性一直在频仍执行，而接口的uri里两个变量（token和uniId）导致meterMap里的key不重复，一直在插入，20万回调，token两小时更新一次，持续了两天，最终产生了124万条字符串，被map持有，无法接纳。
办理方案

• 不必要监控
  直接清除掉spring-boot-starter-actuator
  
• 必要监控但不必要http.client.request指标
  1. management:
  2.   metrics:
  3.         web:
  4.           client:
  5.                 request:
  6.                   autotime:
  7.                         enabled: false

  复制代码
• 必要http.client.request指标
  jar包升到2.5.1或以上
  1. <dependency>
  2.         <groupId>org.springframework.boot</groupId>
  3.         <artifactId>spring-boot-actuator-autoconfigure</artifactId>
  4.         <version>2.5.1</version>
  5. </dependency>

  复制代码

复现：

新建测试项目

相关代码和配置如下
点击查看代码

1. @SpringBootApplication
2. @Slf4j
3. public class Application {
4.     public static void main(String[] args) {
5.         ConfigurableApplicationContext run = SpringApplication.run(Application.class);
6.         RestTemplate bean = run.getBean(RestTemplate.class);
7.         for (int i = 0; i < 300000; i++) {
8.             try {
9.                 String forObject = bean.getForObject("http://localhost:9999/first/echo?i="+i, String.class);
10.             }catch (Exception e){
11.                 log.error("执行"+i+"次");
12.             }
13.         }
14.     }
15. }
17. @Configuration
18. public class RestTemplateTestConfig {
19.     @Bean
20.     public RestTemplate restTemplate(RestTemplateBuilder builder){
21.         return builder.build();
22.     }
23. }
25. <dependencies>
26.     <dependency>
27.         <groupId>org.redisson</groupId>
28.         <artifactId>redisson-spring-boot-starter</artifactId>
29.         <version>3.13.1</version>
30.     </dependency>
31.     <dependency>
32.         <groupId>org.apache.httpcomponents</groupId>
33.         <artifactId>httpclient</artifactId>
34.     </dependency>
35. </dependencies>
37. server:
38.   port: 8080
39. spring:
40.   redis:
41.     host: ************
42.     password: **********
43. #management:
44. #  endpoints:
45. #    web:
46. #      exposure:
47. #        include: "metrics"
48. #  metrics:
49. #    web:
50. #      client:
51. #        request:
52. #          autotime:
53. #            enabled: false

复制代码

启动项目通过jconsole查看整个堆的监控和老年代监控分别如下，可以看出老年代一直在增长，并不会接纳

甚至手动触发GC，老年代也接纳不了

1. [Full GC (System.gc()) [Tenured: 195217K->195457K(204800K), 0.3975261 secs] 233021K->195457K(296960K), [Metaspace: 30823K->30823K(33152K)], 0.3976223 secs] [Times: user=0.39 sys=0.00, real=0.40 secs]

复制代码

通过jprofiler确定重要是meterMap占据内存了，最多的都是字符串。

分析

actuator导致rest启动了metrics记载
在使用RestTemplateBuilder构建RestTemplate的时候，会触发懒加载的RestTemplateAutoConfiguration里的RestTemplateBuilderConfigurer，在此期间，config中会注入RestTempalteCustomizer类型的bean。

而项目中引用了redisson-spring-boot-starter，从依赖分析可以看出间接引用了actuator相关的包。

这导致会在RestTemplateMetricsConfiguration配置类中实例化一个叫做MetricsRestTemplateCustomizer的bean，这个bean会通过上面的restTepalteBuilderConfigurer.configure方法给restTemplate添加拦截器MetricsClientHttpRequestInterceptor。

拦截器的intercept方法会在finnally中最终记载此次哀求的一些指标

1. io.micrometer.core.instrument.Timer.Builder#register->
2. io.micrometer.core.instrument.MeterRegistry#time->
3. io.micrometer.core.instrument.MeterRegistry#registerMeterIfNecessary->
4. io.micrometer.core.instrument.MeterRegistry#getOrCreateMeter{
5. meterMap.put(mappedId, m);
6. }

复制代码

最终存到了是SimpleMeterRegistry这个bean的meterMap中去，这个bean也是actuator-autoconfigure自动注入的

但是到目前为止，只是启动了metrics记载，假如maxUriTags有效的话，会在超过100条记载后getOrCreateMeter方法里的accept这里过滤掉，并不会走到下面的meterMap.put(mappedId, m)

为什么maxUriTags没有生效？

maxUriTags只在下图这个位置使用了，作用是构建了一个MeterFilter，根据debug我们可以确定bean是产生了的

但是在accept这里打上断点，再触发一些哀求可以发现，代码并不会走到这里

往上跟，没有走到这里的情况只能是filters里没有这个MeterFilter，但我们刚才又确定metricsHttpCLientUriTagFilter这个bean是产生了的，那么就只能是没有添加到filters，也就是没有调用过meterFilter

从meterFilter往上只有可能是addFilters，一层一层往上最终到了MeterRegistryPostProcessor#postProcessAfterInitialization这个方法

我们上面说过负责记载的bean叫做simpleMeterRegistry，但是我们在这里打上条件断点发现并没有走到这里

找到SimpleMeterRegistry和MeterRegistryPostProcessor这两个bean注入的地方打断点观察，都产生了，且MeterRegistryPostProcessor比SimpleMeterRegistry产生的要早

理论上没问题，但现在确实没走到，以是只能在SimpleMeterRegistry产生的时候在org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory#applyBeanPostProcessorsAfterInitialization打断点，然后可以发现，在simpleMeterRegistry实例化快结束的时候，调用后处理器时this.beanPostProcessors确实没有MeterRegistryPostProcessor

一样平常来说，postPorcessor的bean注入是在refresh方法的registerBeanPostProcessors中，是早于普通bean的实例化

以是simpleMeterRegistry实例化的时候没有MeterRegistryPostProcessor是不公道的情况，定位simpleMeterRegistry是何时实例化的成了关键问题
simpleMeterRegistry的实例化时机

在new SimpleMeterRegistry这里打上断点观察堆栈发现，simpleMeterRegistry是MetricsRepositoryMethodInvocationListener的参数，MetricsRepositoryMethodInvocationListener则是metricsRepositoryMethodInvocationListenerBeanPostProcessor的参数
以是是在实例化metricsRepositoryMethodInvocationListenerBeanPostProcessor这个处理器的时候，由于依赖导致先实例化了simpleMeterRegistry这个bean依赖

导致实例化了SimpleMeterRegistry，而这个时候由于没有注册，以是SimpleMeterRegistry在执行applyBeanPostProcessorsAfterInitialization时就执行不到meterRegistryPostProcessor了

spring已经修复了这个问题，spring-boot-actuator-autoconfigure版本大于2.5.0的都已经没有问题了。办理方案
2.5.1 版本中，添加了一个这个ObjectProvider，在源头上不会立即把依赖的bean初始化完

2.5.0 版本

1. public Object resolveDependency(DependencyDescriptor descriptor, @Nullable String requestingBeanName,
2.       @Nullable Set<String> autowiredBeanNames, @Nullable TypeConverter typeConverter) throws BeansException {
4.    descriptor.initParameterNameDiscovery(getParameterNameDiscoverer());
5.    if (Optional.class == descriptor.getDependencyType()) {
6.       return createOptionalDependency(descriptor, requestingBeanName);
7.    }
8.    //由于使用了ObjectProvider，所以这里只是返回了一个DependencyObjectProvider
9.    else if (ObjectFactory.class == descriptor.getDependencyType() ||
10.          ObjectProvider.class == descriptor.getDependencyType()) {
11.       return new DependencyObjectProvider(descriptor, requestingBeanName);
12.    }
13.    else if (javaxInjectProviderClass == descriptor.getDependencyType()) {
14.       return new Jsr330Factory().createDependencyProvider(descriptor, requestingBeanName);
15.    }
16.    else {
17.    //2.5.0版本中会在这个方法加载入参依赖的bean
18.       Object result = getAutowireCandidateResolver().getLazyResolutionProxyIfNecessary(
19.             descriptor, requestingBeanName);
20.       if (result == null) {
21.          result = doResolveDependency(descriptor, requestingBeanName, autowiredBeanNames, typeConverter);
22.       }
23.       return result;
24.    }
25. }

复制代码

免责声明：如果侵犯了您的权益，请联系站长，我们会及时删除侵权内容，谢谢合作！更多信息从访问主页：qidao123.com:ToB企服之家，中国第一个企服评测及商务社交产业平台。