关于Spring Boot内存泄露排查的记录

目录
  • 背景
  • 排查过程
    • 1.使用Java层面的工具定位内存区域
    • 2. 使用系统层面的工具定位堆外内存
    • 3. 为什么堆外内存没有释放掉呢?
  • 总结

在项目迁移到Spring Boot之后,发生内存使用量过高的问题。本文介绍了整个排查过程以及使用到的工具,也非常适用于其他堆外内存排查。

背景

为了更好地实现对项目的管理,我们将组内一个项目迁移到MDP框架(基于Spring Boot),随后我们就发现系统会频繁报出Swap区域使用量过高的异常。笔者被叫去帮忙查看原因,发现配置了4G堆内内存,但是实际使用的物理内存竟然高达7G,确实不正常。

JVM参数配置是:

-XX:MetaspaceSize=256M
-XX:MaxMetaspaceSize=256M
-XX:+AlwaysPreTouch
-XX:ReservedCodeCacheSize=128m
-XX:InitialCodeCacheSize=128m,
-Xss512k -Xmx4g -Xms4g,-XX:+UseG1GC
-XX:G1HeapRegionSize=4M

实际使用的物理内存如下图所示:

排查过程

1.使用Java层面的工具定位内存区域

(堆内内存、Code区域或者使用unsafe.allocateMemory和DirectByteBuffer申请的堆外内存)

笔者在项目中添加-XX:NativeMemoryTracking=detailJVM参数重启项目,使用命令jcmd pid VM.native_memory detail查看到的内存分布如下:

发现命令显示的committed的内存小于物理内存,因为jcmd命令显示的内存包含堆内内存、Code区域、通过unsafe.allocateMemory和DirectByteBuffer申请的内存,但是不包含其他Native Code(C代码)申请的堆外内存。所以猜测是使用Native Code申请内存所导致的问题。

为了防止误判,笔者使用了pmap查看内存分布,发现大量64M地址;而这些地址空间不在jcmd命令所给出的地址空间里面,基本上可断定就是这些64M的内存所导致。

2. 使用系统层面的工具定位堆外内存

因为笔者已经基本上确定是Native Code所引起,而Java层面的工具不便于排查此类问题,只能使用系统层面的工具去定位问题。

首先,使用了gperftools去定位问题

gperftools的使用方法可以参考gperftools,gperftools的监控如下:

从上图可以看出:使用malloc申请的内存最高到3G之后就释放了,之后始终维持在700M-800M。笔者第一反应是:难道Native Code中没有使用malloc申请,直接使用mmap/brk申请的?(gperftools原理就使用动态链接的方式替换了操作系统默认的内存分配器(glibc)。)

然后,使用strace去追踪系统调用

因为使用gperftools没有追踪到这些内存,于是直接使用命令strace -f -e"brk,mmap,munmap" -p pid追踪向OS申请内存请求,但是并没有发现有可疑内存申请。strace监控如下图所示:

接着,使用GDB去dump可疑内存

因为使用strace没有追踪到可疑内存申请;于是想着看看内存中的情况。

就是直接使用命令gdp -pid pid进入GDB之后,然后使用命令dump memory mem.bin startAddress endAddressdump内存,其中startAddress和endAddress可以从/proc/pid/smaps中查找。

然后使用strings mem.bin查看dump的内容,如下:

从内容上来看,像是解压后的JAR包信息。读取JAR包信息应该是在项目启动的时候,那么在项目启动之后使用strace作用就不是很大了。所以应该在项目启动的时候使用strace,而不是启动完成之后。

再次,项目启动时使用strace去追踪系统调用

项目启动使用strace追踪系统调用,发现确实申请了很多64M的内存空间,截图如下:

使用该mmap申请的地址空间在pmap对应如下:

最后,使用jstack去查看对应的线程

因为strace命令中已经显示申请内存的线程ID。直接使用命令jstack pid去查看线程栈,找到对应的线程栈(注意10进制和16进制转换)如下:

这里基本上就可以看出问题来了:MCC(美团统一配置中心)使用了Reflections进行扫包,底层使用了Spring Boot去加载JAR。因为解压JAR使用Inflater类,需要用到堆外内存,然后使用Btrace去追踪这个类,栈如下:

然后查看使用MCC的地方,发现没有配置扫包路径,默认是扫描所有的包。于是修改代码,配置扫包路径,发布上线后内存问题解决。

3. 为什么堆外内存没有释放掉呢?

虽然问题已经解决了,但是有几个疑问:

  • 为什么使用旧的框架没有问题?
  • 为什么堆外内存没有释放?
  • 为什么内存大小都是64M,JAR大小不可能这么大,而且都是一样大?
  • 为什么gperftools最终显示使用的内存大小是700M左右,解压包真的没有使用malloc申请内存吗?

带着疑问,笔者直接看了一下Spring Boot Loader那一块的源码。发现Spring Boot对Java JDK的InflaterInputStream进行了包装并且使用了Inflater,而Inflater本身用于解压JAR包的需要用到堆外内存。而包装之后的类ZipInflaterInputStream没有释放Inflater持有的堆外内存。于是笔者以为找到了原因,立马向Spring Boot社区反馈了这个Bug。但是反馈之后,笔者就发现Inflater这个对象本身实现了finalize方法,在这个方法中有调用释放堆外内存的逻辑。也就是说Spring Boot依赖于GC释放堆外内存。

笔者使用jmap查看堆内对象时,发现已经基本上没有Inflater这个对象了。于是就怀疑GC的时候,没有调用finalize。带着这样的怀疑,笔者把Inflater进行包装在Spring Boot Loader里面替换成自己包装的Inflater,在finalize进行打点监控,结果finalize方法确实被调用了。于是笔者又去看了Inflater对应的C代码,发现初始化的时候使用了malloc申请内存,end的时候也调用了free去释放内存。

此刻,笔者只能怀疑free的时候没有真正释放内存,便把Spring Boot包装的InflaterInputStream替换成Java JDK自带的,发现替换之后,内存问题也得以解决了。

这时,再返过来看gperftools的内存分布情况,发现使用Spring Boot时,内存使用一直在增加,突然某个点内存使用下降了好多(使用量直接由3G降为700M左右)。这个点应该就是GC引起的,内存应该释放了,但是在操作系统层面并没有看到内存变化,那是不是没有释放到操作系统,被内存分配器持有了呢?

继续探究,发现系统默认的内存分配器(glibc 2.12版本)和使用gperftools内存地址分布差别很明显,2.5G地址使用smaps发现它是属于Native Stack。内存地址分布如下:

到此,基本上可以确定是内存分配器在捣鬼;搜索了一下glibc 64M,发现glibc从2.11开始对每个线程引入内存池(64位机器大小就是64M内存),原文如下:

按照文中所说去修改MALLOC_ARENA_MAX环境变量,发现没什么效果。查看tcmalloc(gperftools使用的内存分配器)也使用了内存池方式。

为了验证是内存池搞的鬼,笔者就简单写个不带内存池的内存分配器。使用命令gcc zjbmalloc.c -fPIC -shared -o zjbmalloc.so生成动态库,然后使用export LD_PRELOAD=zjbmalloc.so替换掉glibc的内存分配器。其中代码Demo如下:

通过在自定义分配器当中埋点可以发现其实程序启动之后应用实际申请的堆外内存始终在700M-800M之间,gperftools监控显示内存使用量也是在700M-800M左右。但是从操作系统角度来看进程占用的内存差别很大(这里只是监控堆外内存)。

笔者做了一下测试,使用不同分配器进行不同程度的扫包,占用的内存如下:

为什么自定义的malloc申请800M,最终占用的物理内存在1.7G呢?

因为自定义内存分配器采用的是mmap分配内存,mmap分配内存需要按需向上取整到整数个页,所以存在着巨大的空间浪费。通过监控发现最终申请的页面数目在536k个左右,那实际上向系统申请的内存等于512k * 4k(pagesize) = 2G。 为什么这个数据大于1.7G呢?

因为操作系统采取的是延迟分配的方式,通过mmap向系统申请内存的时候,系统仅仅返回内存地址并没有分配真实的物理内存。只有在真正使用的时候,系统产生一个缺页中断然后再分配实际的物理Page。

总结

整个内存分配的流程如上图所示。MCC扫包的默认配置是扫描所有的JAR包。在扫描包的时候,Spring Boot不会主动去释放堆外内存,导致在扫描阶段,堆外内存占用量一直持续飙升。当发生GC的时候,Spring Boot依赖于finalize机制去释放了堆外内存;但是glibc为了性能考虑,并没有真正把内存归返到操作系统,而是留下来放入内存池了,导致应用层以为发生了“内存泄漏”。所以修改MCC的配置路径为特定的JAR包,问题解决。

笔者在发表这篇文章时,发现Spring Boot的最新版本(2.0.5.RELEASE)已经做了修改,在ZipInflaterInputStream主动释放了堆外内存不再依赖GC;所以Spring Boot升级到最新版本,这个问题也可以得到解决。

以上为个人经验,希望能给大家一个参考,也希望大家多多支持我们。

(0)

相关推荐

  • Spring Boot深入排查 java.lang.ArrayStoreException异常

    java.lang.ArrayStoreException 分析 这个demo来说明怎样排查一个spring boot 1应用升级到spring boot 2时可能出现的java.lang.ArrayStoreException. demo地址:https://github.com/hengyunabc/spring-boot-inside/tree/master/demo-ArrayStoreException demo里有两个模块,springboot1-starter和springboot

  • 记一次springboot服务凌晨无故宕机问题的解决

    表述 在一次服务更新后发现每天凌晨0点3秒服务准时挂,开始的时候认为是maven依赖中存在system.exit(3)类似这样的代码,但是我想了下这个代码很多客户都有用到但是只有这一个客户出现了问题,而且另外一个服务没有更新在此前几个月都是没问题的 这几天也是一样无故挂了. 环境 windows服务器 排查 1.初步怀疑是内存泄漏问题,在启动脚本中加入 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=D:\heapdump.log,第二天起来一看

  • springboot项目启动慢的问题排查方式

    目录 springboot项目启动慢的问题排查 1.最开始查看的启动日志,是在输出: 2. 启动项目,打印日志级别改为debug,查看更详细信息 如何优化SpringBoot的项目的启动速度 实际上它是下面三个注解的组合 可以用@SpringBootApplication注解下面的属性 springboot项目启动慢的问题排查 springboot项目,随着时间的推移,启动耗时逐步增加,从几分钟慢慢的达到30多分钟,有点恐怖! 项目中用到技术:hibernate.redis.kafka.线程池等

  • 关于Spring Boot内存泄露排查的记录

    目录 背景 排查过程 1.使用Java层面的工具定位内存区域 2. 使用系统层面的工具定位堆外内存 3. 为什么堆外内存没有释放掉呢? 总结 在项目迁移到Spring Boot之后,发生内存使用量过高的问题.本文介绍了整个排查过程以及使用到的工具,也非常适用于其他堆外内存排查. 背景 为了更好地实现对项目的管理,我们将组内一个项目迁移到MDP框架(基于Spring Boot),随后我们就发现系统会频繁报出Swap区域使用量过高的异常.笔者被叫去帮忙查看原因,发现配置了4G堆内内存,但是实际使用的

  • Spring Boot假死诊断实战记录

    这两天遇到一个服务假死的问题,具体现象就是服务不再接收任何请求,客户端会抛出Broken Pipe. 检查系统状态 执行top,发现CPU和内存占用都不高,但是通过命令 netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}' 发现有大量的CLOSE_WAIT端口占用,继续调用该服务的api,等待超时之后发现CLOSE_WAIT的数量也没有上升,也就是说服务几乎完全僵死. 检查JVM情况 怀疑可能是线程有死锁,决定先

  • Docker环境下Spring Boot应用内存飙升分析与解决场景分析

    目录 Spring Boot应用内存飙升 服务现状 JVM默认内存设置 优化 限制JVM内存 参数解释 JVM常见参数 java.security.egd 作用 优化后的Dockerfile文件 优化后的效果 JVM参数设置是否生效 基础镜像优化 OpenJ9 GraalVM Fabric8 优化后的Dockerfile文件 优化后的效果 备注 Xmx < limit 支持springboot多环境和jvm动态配置的Dockerfile 参考 Spring Boot应用内存飙升 一个简单的Spr

  • spring boot整合mongo查询converter异常排查记录

    目录 前言 自定义转换器 javabean的方式配置MongoTemplate 后记: 前言 使用过spring boot的人都知道spring boot约定优于配置的理念给我们开发中集成相关技术框架提供了很多的便利,集成mongo也是相当的简单,但是通过约定的配置信息来集成mongo有些问题. 当你的字段包含Timestamp这种类型时,读取数据的时候会抛一个类型转换的异常,如 No converter found capable of converting from type [java.u

  • Spring Boot使用RestTemplate消费REST服务的几个问题记录

    我们可以通过Spring Boot快速开发REST接口,同时也可能需要在实现接口的过程中,通过Spring Boot调用内外部REST接口完成业务逻辑. 在Spring Boot中,调用REST Api常见的一般主要有两种方式,通过自带的RestTemplate或者自己开发http客户端工具实现服务调用. RestTemplate基本功能非常强大,不过某些特殊场景,我们可能还是更习惯用自己封装的工具类,比如上传文件至分布式文件系统.处理带证书的https请求等. 本文以RestTemplate来

  • 详解Spring Boot实现日志记录 SLF4J

    在开发中打印内容,使用 System.out.println() 和 Log4j 应当是人人皆知的方法了. 其实在开发中我们不建议使用 System.out 因为大量的使用 System.out 会增加资源的消耗. 而Log4j 更为灵活在性能上也相比 System.out 要高,我们可以配置输出级别,可以指定多个日志文件分别记录不同的日志. 使用 System.out 是在当前线程执行的,写入文件也是写入完毕后才继续执行下面的程序.而使用Log工具不但可以控制日志是否输出,怎么输出,它的处理机

  • 详解Spring Boot配置使用Logback进行日志记录的实战

    spring Boot实战之配置使用Logback进行日志记录 ,分享给大家 在这篇文章中我们将讨论在Spring Boot中使用Logback,在Spring Boot中使用Logback很简单 1.为了测试我们新建两个类 package com.xiaofangtech.sunt.controller; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import org.springframework.web.bind.an

  • spring boot aop 记录方法执行时间代码示例

    本文研究的主要是spring boot aop 记录方法执行时间的实现代码,具体如下. 为了性能调优,需要先统计出来每个方法的执行时间,直接在方法前后log输出太麻烦,可以用AOP来加入时间统计 添加依赖 <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-aop</artifactId> </dependency&

  • 深入学习Spring Boot排查 @Transactional 引起的 NullPointerException问题

    写在前面 这个demo来说明怎么排查一个@Transactional引起的NullPointerException. https://github.com/hengyunabc/spring-boot-inside/tree/master/demo-Transactional-NullPointerException 定位 NullPointerException 的代码 Demo是一个简单的spring事务例子,提供了下面一个StudentDao,并用@Transactional来声明事务:

  • 一次Spring项目打包问题排查的实战记录

    一个 Spring 项目,打成 jar 包之后运行,在有网络的时候是正常的,但是一旦无网络就会报错,具体是怎么回事呢?这篇文章就来记录下这次问题排查经过. 背景介绍 一个图形化的界面,带本地数据库,要求可以在无网络环境下运行,我帮朋友用的 Java 写的图形化界面,虽然不是很美观,但是胜在熟悉 Java. 项目使用的是 idea 的「Build Artifacts」打包,打包之后运行正常,界面和数据库访问都正常,最开始报过几次错,后来就没出现了,也没找到原因,就先那样了. 后来发给别人了,完全打

随机推荐