Java 程序 CPU 内存使用率飙升排查与解决

虾米无名

业务背景

出现问题的服务是作为一个中间层， 负责为下游服务提供 Json 格式的API，打通整个产品线，同时，也会承为担上游服务分流，以及一些附加的业务需求。整体的码量不大，也算是比较简单的一个项目。
历史背景

经手过 N 人， 简单的业务常常有着“复杂”的实现（人为复杂）... 时常黑人问号脸 ？？？可想而知里面有多少坑需要填...
技术背景

纯后端项目，SpringBoot， RestTemplate，Azure BlobStorage...
AKS resource CPU 762m Memory 762MB， Evn SIT
CPU 使用率飙升问题的发现

某下游系统E，想测试我们系统提供的API能承受多大的数据量，这里暂且把我们组的系统成为MS，这个API的功能是收到 E 的请求后，从 Azure BlobStorage 服务下载csv文件并把每一条record封装成一个个 request 发送到上游系统 A（一个很老的系统）。
在我们没有收到通知的请况下，E 向 BlobStorage 放了一个超过 4w records 的csv文件并请求MS进行处理，MS 发送到 A 拿到返回结果一般要 1s 左右，如果数据质量太差，可能会触发 A 的全表查询，响应时间会更长... 可想而知 4w records 绝不可能在 30min 内跑完。但 E 不了解这个情况，在15min后又请求了一此MS，同样是 4w records， 约15min后又请求了一次... 在这个时候MS已经彻底挂了，所有的API请求都call不进来... 于是开始了漫长的问题排查之路...
解决思路

• 查看容器目前的状态，CPU 100% 内存却只使用了 400MB 左右（可疑）, 找 IS 团队帮忙拿到 JVM 的 GC log，竟发现了发生的FGC次数 2W 多次... 按理说才 4w 条数据，不应该啊，重启了POD, 让 E 的同事重新试试的, 不要重复请求...
  

2.第二天 E 的开发同事又来说 MS 又挂了,而且只跑了4w... 难道4w 也不行, 这很不正常啊, 于是自己测试了以下2w, CPU 也是100% , 1w 也是 CPU 100%, 5k CPU同样是被拉满, 也是不行
3. 我开始看这 API 里面的代码,首先看 csv 文件的读取操作，发现代码居然是一次读取了整个文件的内容，没有对文件进行切割，分批读取，一下子加载4w条数据... 这是非常危险的动作，还好本身业务的数据量就不大，平时生产环境一天最多也就 1w 2w 的数据量，着实捏了把汗... 由于某些原因这个暂时改不了,只能标记为需要优化的...

4. 再检查业务逻辑,一切看着都没什么问题... 可代码里大量的线程池调用引起了我的注意, 到config包下查看线程的配置,

    @Bean
    public ThreadPoolTaskExecutor threadPoolTaskExecutor(){
        ThreadPoolTaskExecutor threadPoolTaskExecutor = new ThreadPoolTaskExecutor();
        threadPoolTaskExecutor.setCorePoolSize(20);
        threadPoolTaskExecutor.setMaxPoolSize(25);
        threadPoolTaskExecutor.setQueueCapacity(100000);
        threadPoolTaskExecutor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
        return threadPoolTaskExecutor;
    }这个线程池的拒绝策略是 CallerRunsPolicy , 这应是为确保所有的数据都要完成, 但是这个 API 的这个异步动作是由 tomcat 线程提交, 如果队列满的话, 所有请求都跑到tomcat的线程池,那么整个服务就无法接受新的请求, 可是 Queue size 是 100000, 按理来说 4w 是不可能出先这种情况的... 由于有可能就是 JVM 没法分配 10w 大小给到这个线程池...
5. 查看Dockerfile，发现真正启动程序的CMD只写了
CMD["java", "-jar", "app.jar"]ok，这是第一个能确定的问题。虽然 AKS 为部署这个MS服务的pod分配了 762MB 大小的内存，但是 JVM 默认内存配置是不会读这么多内存的

客户端： 1. 最大堆大小 ：物理内存小于 192MB 时， 为物理内存的一半；物理内存大于192mb时且小于1GB时，为物理内存的四分之一；大于等于1GB时，都为256MB； 2. 初始化堆大小：至少为8MB；物理内存大于512M且小于1GB时，为物理内存的1/64；大于等于1GB时，都为16MB。
服务器端：
最大堆大小 1. 32位的JVM上，物理内存小于192MB时，为物理内存的一半；物理内存大于192MB且小于4GB时，为物理内存的四分之一；大于等于4GB时，都为1GB； 2. 64位的JVM上，物理内存小于192MB时，为物理内存的一半；物理内存大192MB且小于128GB时，为物理内存的四分之一；大于等于128GB时，都为32GB。
初始化堆大小则是与客户端相同
按照以上配置计算，实际MS的JVM堆一开始也只有 8MB，最大也才 762 * 1/4 = 192MB，这其实对 POD 资源非常浪费，于是我给它加上以下参数

CMD["java", "-XX:MaxRAMPercentage=75","-XX:InitialRAMPercentage=45","-XX:MinRAMPercentage=35","-jar", "app.jar"]改完重新部署了一版, 以为问题搞定... 重测结果跑 2W CPU 又爆了... 这里面肯定还漏了什么关键的地方...
6. 打开 idea 自带 profiler 工具, capture memory snapshot, 发现有RestTemplate类型居然也 5k 个???, 立马定位到config包下 RestTemplate 的配置类, 果不其然, 居然配置了原型模式... 像这种大对象是不能这么使用的,我说怎么那么容易GC... 年轻代那么快就满了
    @Bean
    @Scope(value = "prototype")
    public RestTemplate restTemplate(){
        RestTemplate restTemplate = new RestTemplate();
        ...
        return restTemplate;
    }直接把  
7. @Scope(value = "prototype") 删了,考虑到用 Apache HttpClient ,于是给它配置了了每条链接的最大连接数...到这里,优化基本完成,与其说是优化,不如说是改bug... 很佩服在生产环境上这样的程序居然跑得好好的, 真的是牛...
总结

虽然问题解决了,但这次问题排查让我看到这个项目里面代码组织结构有多么混乱,简单的需求,复杂的实现,缺乏前瞻性,与工程思维 要以此警戒自己不可设计写出这样的代码
当然,解决这个问题的过程还用到许多工具, jmap, jstat, jvisualvm... 等等,但这些东西网上一百度 谷歌一大堆,crtl c + crtl v 实在无趣, 本文就不列举出如何使用了...
总之,排查问题的思路就是,  
1. 确定是哪一环节出问题, API 还是定时任务等等...  
2. 复现场景...  
3. debug 调试...
4. 适当借助工具
5. 以上都是废话, 学好计组, 你会发现计算机里面的东西无非就是加中间层, 不断套娃...
6. 推荐几本书: 《深入理解JVM》周志明, 《Spring源码深度解析》, 《On Java》,《Heard first 设计模式》...