机票酒店网站建设,重庆公司网站制作公司,西班牙语网站建设,诸城网站做的好的整体复盘
一个不算普通的周五中午#xff0c;同事收到了大量了cpu异常的报警。根据报警表现和通过arthas查看#xff0c;很明显的问题就是内存不足#xff0c;疯狂无效gc。而且结合arthas和gc日志查看#xff0c;老年代打满了#xff0c;gc不了一点。既然问题是内存问题同事收到了大量了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点击查看代码
而在我自己尝试复现之后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指标 management:metrics:web:client:request:autotime:enabled: false需要http.client.request指标 jar包升到2.5.1或以上 dependencygroupIdorg.springframework.boot/groupIdartifactIdspring-boot-actuator-autoconfigure/artifactIdversion2.5.1/version
/dependency复现
新建测试项目 相关代码和配置如下
点击查看代码
启动项目通过jconsole查看整个堆的监控和老年代监控分别如下可以看出老年代一直在增长并不会回收 甚至手动触发GC老年代也回收不了
[Full GC (System.gc()) [Tenured: 195217K-195457K(204800K), 0.3975261 secs] 233021K-195457K(296960K), [Metaspace: 30823K-30823K(33152K)], 0.3976223 secs] [Times: user0.39 sys0.00, real0.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中最终记录此次请求的一些指标 io.micrometer.core.instrument.Timer.Builder#register-
io.micrometer.core.instrument.MeterRegistry#time-
io.micrometer.core.instrument.MeterRegistry#registerMeterIfNecessary-
io.micrometer.core.instrument.MeterRegistry#getOrCreateMeter{
meterMap.put(mappedId, m);
}最终存到了是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 版本 public Object resolveDependency(DependencyDescriptor descriptor, Nullable String requestingBeanName,Nullable SetString autowiredBeanNames, Nullable TypeConverter typeConverter) throws BeansException {descriptor.initParameterNameDiscovery(getParameterNameDiscoverer());if (Optional.class descriptor.getDependencyType()) {return createOptionalDependency(descriptor, requestingBeanName);}//由于使用了ObjectProvider所以这里只是返回了一个DependencyObjectProviderelse if (ObjectFactory.class descriptor.getDependencyType() ||ObjectProvider.class descriptor.getDependencyType()) {return new DependencyObjectProvider(descriptor, requestingBeanName);}else if (javaxInjectProviderClass descriptor.getDependencyType()) {return new Jsr330Factory().createDependencyProvider(descriptor, requestingBeanName);}else {//2.5.0版本中会在这个方法加载入参依赖的beanObject result getAutowireCandidateResolver().getLazyResolutionProxyIfNecessary(descriptor, requestingBeanName);if (result null) {result doResolveDependency(descriptor, requestingBeanName, autowiredBeanNames, typeConverter);}return result;}
}
