写点什么

生产服务器内存泄漏的排查过程与优化解决方案

用户头像
冰三郎
关注
发布于: 2021 年 01 月 16 日

最近在排查生产上,应用占用内存过大的问题,排查出来是 jdk8bug+jetty 服务器内存泄漏导致的,将过程记录下来,大家一起探讨。


一、环境信息

  • 操作系统:centos、

  • 内存分配器:glibc2.17

  • JDK 版本:jdk8u_101.b13

  • 配置:4C8G 即 4CPU+8G 物理内存。

  • Jetty 版本:8.1.13

  • 应用信息:java 应用,垃圾收集器使用 G1,-xmx=-xms = 4G


二、现象

  • jetty 启动应用后,Java 应用进程占用 1.4~1.5G。

  • 运行一段时间后,应用进程占用 5G+。

  • 物理内存 free -h,剩余 100-300M 之间。

  • 部分机器开始使用 swap 空间,范围是:100~700M,一直缓慢持续上升。


三、排查过程

现状:

free -h 显示如下:

操作系统开始使用 swap,大家都知道,只有物理内存吃紧的时候才会使用 swap,也就是说明剩余的物理内存分配和使用起来有压力了。操作系统启动了应急策略:使用 swap 将部分不活跃的内存转移到 swap 区域以便腾出更多的内存空间。

使用 sar 和 vmstat 命令,可以看到在频繁的发生 pageout 到 swap 区域,暂未发生整个进程的内存页 swap out:

执行 sar -B 1,显示如下:


执行 vmstat 1,显示如下:

观察到我们的应用进程占据的内存很大,top -pH 该进程,显示如下:


由上图可知,应用进程占用了 5.6 G, 虚拟内存占用了 9.4G(那么大!!!),线程的个数是 700 个。

在开发环境模拟生产流量运行一段时间后,监控堆内堆外的内存使用情况,通过 arthas 工具(或者 jconsole)观察如下:

通过上图可知,我们的应用堆外内存的占用情况是 240M 左右:

code_cache(95M) + metaspace(122M) + compressed_class_space(14M) + direct(724K) +mapped(0K) = 232M。

按照配置堆大小是 4G:-xms =-xmx =4G,JVM 堆外内存占据 240M 来计算的话,进程应该占用的内存上限为:


上限大小 = 堆(4G)+ 非堆(JVM 堆外,code_cache,、metaspace、compressed_class、direct 等,240M) + 线程(400M,其实远远不到) = 4.625G。


但是现在实际占用已超过这个上限将近 1G 。这就足够说明该应用的内存占用是有问题的。是否存在内存泄漏需要排查下,主要排查地方如下:

  • 1、堆内存,看看是否存在堆内存泄漏。

  • 2、堆外内存(仅仅指 JVM 的堆外内存),看看是否存在泄漏。

  • 3、Native Memory 内存泄漏,这部分内存的使用是 JVM 管控和追踪不到的地方。


3.1 堆内存和堆外内存排查

堆内存排查的最好方式是将应用的内存快照 dump 一份,使用 Eclipse 的 MAT(Memory Analyzer Tool)工具进行分析,官网地址:Memory Analyzer Tool ,它是一个强大的基于 Eclipse 的内存分析工具,也可以独立的安装软件,可以分析内存的使用情况,帮助我们找到内存泄露,减少内存消耗。

使用命令进行 dump 内存,切记这个操作会对应用造成影响,生产上使用要谨慎

jmap -dump:live,format=b,file=appMem.bin pid  
复制代码

将 bin 读入到 MAT 后,选择显示可疑内存分析,呈现的结果如下:




MAT 提示我们有两个可疑的内存泄漏点:

  • com.alibab.dubbo.common.URL

  • com.alibaba.druid.pool.DruidDataSource

第一点我们的应用依赖的服务机器数量比较多,服务的数量也很多,所以有 1 万 5 的 URL 对象不足为奇,同时 alibba 的 URL 也不涉及到资源的操作,所以可疑排除内存泄漏。

第二点说明数据库链接数,也没有什么可疑的点。


从可疑点并不能看出来什么,也可以从首页的 Overview 的各个指标,比如 Histogram、Top Consume 和 Big Object 等。可以参考MAT使用详细介绍 这个教程。

同时也通过 atrthas、jconsole、jvisualvm 进行跟踪应用程序的跟踪,可以看到堆内存的分布:新生代 Eden、老年代、堆外的几个指标也很正常。同时通过 arthas 也可以生成内存使用的火焰图,并没有使用 direct 内存。

这时候还是不能确认堆和堆外内存的使用是否正常,这时候使用 NMT(Native Memory Tracking)对 JVM 的内存使用情况进行跟踪。官网地址是:NMT的使用,可以在应用的启动参数中加上如下参数:

-XX:NativeMemoryTracking=detail
复制代码



为了追踪 NMT 的各个内存区域的使用情况,编写了一个每 1 小时采集的脚本,对 NMT 的各个内存区域使用情况进行统计分析:

运行几天后,各个区域的内存使用无异常。

到这儿基本上可以确定应用的 JVM 堆是没有问题的。

3.2 Native Memory 排查

通过上面的分析可知,JVM 的内存使用是没有问题的,这时候就需要考虑 JVM 无法追踪和监控的内存:原生内存。根据/proc/meminfo 整理下操作系统的内存分布情况:

对各个区域进行整理得出如下的内存分布:


这时候写了一个操作系统的 meminfo 的内存定时采集器,这个采集器主要定时采集/proc/meminfo 的各个区域的内存情况:

从上图可以看到如下的变化:

  • MemFree 持续下降并保持平稳,这也符合生产上的现状,内存可用率持续下降。

  • Active(annon)、AnonHugePage、Dirty 这两个区域持续上涨。

  • 其他的指标都是变化后基本上不再变化。


Active(annon)、AnonHugePage 这个主要是进程的匿名内存块使用在增长,Dirty 是指这个进程使用的物理内存大小,是记录逻辑地址与物理地址额映射关系,是真正被操作系统感知到使用的物理内存,这个值也一直在增长,说明我们使用的物理内存越来越多,但是我们使用 Native Memory Tracking 跟踪程序,JVM 整体各个区域是平稳的,不增长的。这时候疑点就出来了:为什么 JVM 外的内存使用一直在增长??。

这时候可以使用 pmap 命令对进程使用的地址空间和大小进行查看,基本命令如下所示:

pmap -x pid | sort -k 2 -r -n | head -50 
复制代码

执行命令后发现大量的 64M 内存块不在 Native Memory Tracking 的地址管理空间中,统计了下大概有 45+个 64M 的逻辑内存块,第一列是地址,第二列是逻辑地址大小,第三列是实际使用的物理内存大小,对申请的物理内存(即第二列)排序后后如下:

又对第三列进行排序,看看内存的使用物理内存的情况:

上面两个图,这些 64M 块的逻辑地址(第一列)都可以在/proc/pid/smap 中,也就是说这些地址确实是属于这个进程申请的,但是为什么会申请那么多的逻辑地址块同时已经使用了那么多物理内存呢?

选择其中一个 64M 的内存块地址,去/proc/pid/smap 中找到这个块的启始地址,使用 gdb 工具将这地址块的内存 dump 出来,看看是什么内容:

gdb --batch --pid -ex "dump memory gdb_64M.dump 0x765e38000000 0x7f5e3bffa000"
复制代码

生成的 gdb_64M.dump, 通过 strings gdb_64M.dump 命令查看内存块的内容,如下:



可以看到基本上都是一些类名称,应该是存储的解压 jar 包的内容。

把思路扩大点,看看为什么会产生 64M 这种东西,外事不决问谷歌,通过关键字“64M”、“内存”等关键字搜索相关的信息,确实搜到了相关信息,总结如下:


64M 内存块是 glibc 申请的,glibc 是一种内存管理器,内部存在一个内存池,应用频繁申请的小内存和释放内存都通过 glibc 内存管理器申请和释放,这样能够减少与操作系统交互的次数,提高性能和效率。但是 glibc 持有的内存池因为存在内存碎片问题,导致内存的释放条件苛刻,导致进程 持有很大一块内存,特别是多线程竞争激烈的情况下,容易出现进程持有大量的内存,导致内存耗尽,表现为内存泄漏。

glibc 每次向操作系统申请一大块内存(32 位系统 1M, 64 位系统 64M)进行切分成小块进行管理。



了解这些信息后,知道了原来是 glibc 在搞鬼,一直持有内存,不容易释放,所以导致内存占用过大。那就验证下 45+个 64M 是不是 glibc 申请的:

使用 strace 工具对应用对操作系统的内存申请(brk 和 mmap)与释放(mummap)进行跟踪,为了能够从应用启动的时候就进行追踪,在 jetty 启动的时候就跟踪:基本命令如下:

strace -f -e "brk,mmap,munmap" -tt -o straceLog ./jetty.sh start
复制代码




第二个图为什么申请的是 2 倍的 64M,这是因为 glibc 在申请内存时没有采用锁机制,而是采用 CAS 的方式,当多个线程同时申请 64M 的操作时,只有一个成功,其他都失败。这时候失败的线程就会第二次申请,这次申请的内存是 128M,申请成功后 ,会释放前面的 64M,保留后面的 64M 地址空间。

从上面的次数可以统计出 48 个 64M 内存块。

这儿基本上确定了 64M 内存是 glibc 申请和管理的。现在业界比较成熟的内存管理器有如下:

  • jemalloc – FreeBSD and Firefox

  • tcmalloc – Google

这两个内存管理器对内存的管理都比较有效,减少了内存碎片的产生,接下来使用 tcmalloc 替换 glibc 后 ,安装 tcmalloc 并在/etc/profile 文件中添加如下环境变量(注意 tcmalloc 是自己的安装地址)

sudo vim /etc/profile:

LD_PRELOAD="/usr/lib/libtcmalloc.so
复制代码

然后执行 source /etc/profile 使得环境变量生效。

经过几天的测试后,结果如下:


操作系统中也没有了 64M 的内存块了,启动时的内存占用也变小了。

可以看出 tcmalloc 对内存的管理要好于 glibc,可以替换成 tcmalloc,应用进程占用更少的内存。

按道理到这儿就应该结束了,已经找到多出来的内存是什么,是什么导致了 64 内存块的存在,怎么优化下内存的管理方式减少内存块个数。


按道理查到这儿应该也可以了。 基本结论如下:

  • 应用程序没有出现内存泄漏。

  • 64M 内存块是 glibc 持有的,且 glibc 因内存池和内存碎片的原因,容易使得进程占用内存过大。


可是好奇害死猫~~~,还是想知道下为什么进程需要那么多的 64M 内存。因为根据 glibc 的特性,只有内存竞争激烈时才会产生大量的 64M 内存块,所以接下来想查明 64M 内存块到底是谁使用的,怎么去优化下不使用那么多内存。


3.3 服务器内存泄漏排查过程

现在需要查清楚的是:

  • 是谁频繁使用内存?

  • 申请 64M 做什么?

  • 使用后为什么一直没释放?是否存在 Native 内存泄漏?

针对第一个问题:是谁频繁使用内存?

编写了一个 Linux 的 hook 函数,去统计线程的 malloc 次数,具体的可以参考Linux的hook机制:自定义动态链接库hook,

LD_PRELOAD=./malloc_hook.so ./jetty.sh start > mallocLog
复制代码



使用如下命令对结果文档进行统计:

cat mallocLog | awk '{print $1}' | less | sort | uniq -c | sort -rn | less
复制代码


统计出的结果如下:


使用 malloc 最多线程 pid=60153,通过 jstack 查看,这个线程是 jetty 的线程:

从堆栈可以看出 jetty 主线程在解压 jar 包,难道是使用 Inflater 解压 jar 需要那么多内存,一直都听说使用 Inflater 不当容易造成内存泄漏,是不是因为使用 Inflater 造成内存泄漏了。


针对第一个问题,来回答第二个问题,需要使用 gperftools,这是 google 的内存分析利器,关于安装和配置,可以参考官网,github 地址:gperftools.使用这个工具的前提是需要使用 tcmalloc,这个已经在前文的配置中配置过了,使用如下命令重新启动 jetty 即可:

HEAPPROFILE="home/user/heap-gperftools/gzip" ./jetty.sh start
复制代码

一定要注意,这个路径存在目录的话这个目录一定要存在,不存在创建好。同时在这个目录下会生成很多文件,一定要筛选出来进程的 heap。还存在其他的参数控制,我采用的默认:

# 此配置表示进程每分配 X 字节内存输出一个文件,默认是 1G 输出一个文件,这个设置的是 4G

export HEAP_PROFILE_ALLOCATION_INTERVAL=4073741824

# 此配置表示进程每使用 X 字节内存输出一个文件,默认是 100M 输出一个文件,这个设置的 4G

export HEAP_PROFILE_INUSE_INTERVAL=4048576000

启动后会输出以下信息:

从输出信息也可以看出在使用 100 多 M 内存后就触发回收了,而不是一直增长。虚拟地址确实是在增长。

生成的 heap 文件使用如下命令进行解析和排序:

/home/xxx/gperftools/bin/pprof –text /usr/local/java8/bin/java gzip_149180.0001.heap |sort -nr -k 5 | head -20
复制代码



对结果排序后,得到的结果如下:


刚开始的第一张 inflater 使用内存不是很明显 ,从第 2 张到第 15 张,inflater 使用就非常的明显,infalter 是用于解压缩器,使用那么凶猛,一定是在在解压东西。

这时候使用 btrace 工具跟踪某个函数的调用,btrace 的脚本如下:


跟踪的调用结果如下:

从图中可以看到,确实是 jetty 启动线程使用解压 jar 包。


现在可以知道的是:申请的 64M,是 jetty 启动时,扫描和解压 jar 包在频繁的使用内存。


现在需要查明第三个问题:使用后为什么一直没释放?是否存在 Native 内存泄漏?

现在知道是因为解压 jar 包需要使用内存,glibc 才会申请 64M 内存,并且放在内存池中,可是解压完成后为什么内存没有释放?


这时候就需要了解下 jetty 的启动过程了。jetty 启动时为了支持 Servlet 规范中的注解方式(使得不再需要在 web.xml 文件中进行 Servlet 的部署描述,简化开发流程),jetty 在启动时会扫描 class、lib 包,使用 ServiceLoader,将使用注解方式声明的 Servlet、Listener 注册到 jetty 容器,在扫描 jar 包的时候调用了 inflate,分配了大量的内存。

现在从 ServiceLoader 这个类入手,分析类的加载过程,分析 jdk 的源码,看看是否有内存泄漏,通过查看源码和搜索相关问题进行确认,jdk8 存在 bug,有以下问题:

  • jdk8 打开 jar 时是默认缓存的,缓存会占用内存。

  • 因为缓存机制,jdk8 的 ServiceLoader 和 UrlClassLoader 同时加载一个 jar 包文件,会导致这个 jar 包的文件句柄泄漏,文件句柄泄漏对 redeploy 危害巨大的,但是对我们这种重启的应用危害性不大。

针对以上两个问题的帖子如下:

JDK-8156014 : (sl) File handle leaked for jar of class loaded with java.util.ServiceLoader

JDK-8013099 : (sl) ServiceLoader interferes with URLClassLoader.close()

通过查看 jdk 源码得知,jdk9-111 已经修复了这个问题,将缓存去掉 ,如下所示:


通过使用解决这个问题的 jdk11,重启应用后占用的内存从:1.4G 下降到 1G。

通过 pmap 查看使用中的 64M 的内存块从启动之初的 15+个降低到 5+个。 优化前和优化后效果如下:


还是有不少的使用的 64M 存在,是不是哪儿还有缓存内存或者内存泄漏,


通过查找 jetty 产品的发布 log,查查这些版本线都解决了那些 bug,网站:https://gitee.com/mirrors/jetty/raw/jetty-9.4.x/VERSION.txt

同时也在 jetty 的论坛上,通过搜索 memory、leak 等关键字搜索哪些 bug 是目前使用版本存在,被高版本修复的,正好定位到一个 bug:

Memory leak while scanning annotations #575 

确定是 jetty 扫描资源时的泄漏,这时通过源码确认这个 bug 并且确定这个 bug 是在那个时候版本上进行修复的:9.3.4,修复的情况如下,使用 try 进行资源打开和关闭:


如果想了解为什么关闭 inputstram 会导致内存泄漏 ,可以看看源码,这个也是和 jdk8 的默认缓存相关,默认缓存了又不关闭通过 InputStream 去关闭或者清理对应的 Inflater(end()或者 reset()),这不就导致内存泄漏了吗!!!内存泄漏的测试例子可以看下Java InputStream未调用close方法进行资源关闭造成直接内存泄漏, 其中如果主动关闭资源的话,关闭流程如下所示:

知道这个问题后,将 jetty 版本升级到解决 这个问题的较高版本,重启应用后:

  • 内存占用从 1G 降低到 600~700M。

  • 64M 的使用块 1~2 个。


四、结论及优化方案

  • jdk8 有 bug,这个 bug 不影响我们的应用,jdk 较高版本在 ServiceLoader 时禁用了缓存,节省了 300M 的堆外内存使用。-----解决方案:升级到 jdk9-111 及以上 版本。

  • AnnotationParser.java 存在未关闭文件流的问题,同时由于 jdk8 的缓存机制,导致内存泄露。----解决方案:升级 jetty-9.3.4 及以上版本。

  • glibc 64M 大内存块问题,这是 glibc 的产品特性,如果多线程高并发的应用,建议使用 tcmalloc 或者 jemalloc,能更好的管理内存。


大功告成了!!!!!!

以上的建议在上生产前,请做好生产压测验证。

发布于: 2021 年 01 月 16 日阅读数: 727
用户头像

冰三郎

关注

还未添加个人签名 2019.10.27 加入

还未添加个人简介

评论 (2 条评论)

发布
用户头像
牛逼,能如此分析堆外内存泄露,可见基础功力很深
2021 年 01 月 22 日 17:42
回复
哈哈,同caicai~~
2021 年 01 月 23 日 16:18
回复
没有更多了
生产服务器内存泄漏的排查过程与优化解决方案