我的程序跑了60多小时就是为了让你看一眼JDK的BUG导致的内存泄漏

38次阅读

共计 6086 个字符,预计需要花费 16 分钟才能阅读完成。

这次的文章从 JDK 的 J.U.C 包下的 ConcurrentLinkedQueue 队列的一个 BUG 讲起。jetty 框架外面的线程池用到了这个队列,导致了内存透露。

同时通过 jconsole、VisualVM、jmc 这三个可视化监控工具,让你看见“内存透露”的产生。有点意思,大家一起看看。

从一个 BUG 说起

前段时间翻到了一个 JDK 有点意思的 BUG,带大家一起瞅瞅。

https://bugs.java.com/bugdatabase/view_bug.do?bug_id=8137185

memory leak,内存透露。

是谁导致的内存透露呢?

ConcurrentLinkedQueue,这个队列。

这个 BUG 外面说,在 jetty 我的项目外面也爆出了这个 BUG:

我看了一下,感觉 jetty 的这个写的挺有意思的。

我依照 jetty 的这个讲吧,反正都是同一个 JDK BUG 导致的。地址如下:

https://bugs.eclipse.org/bugs/show_bug.cgi?id=477817

我用我八级半的糟糕英语给大家翻译一下这个叫做 max 的同学说了些什么。

他说:在 Java 我的项目外面,谬误的应用 ConcurrentLinkedQueue(文章前面用缩写 CLQ 代替)会导致内存透露的问题。

在 jetty 的 QueuedThreadPool 这个线程池外面,应用了 CLQ 这个队列,它会导致内存迟缓增长,最终引发内存透露。

尽管 QueuedThreadPool 仅仅应用了这个队列的 add 办法和 remove 办法。但可怜的是,remove 办法不会把队列的大小变小,只会使队列外面被删除的 node 为空。因而,该列表将增长到无穷大。

而后他给了一个附件,附件外面是一段程序,能够演示这个问题。

咱们先不看他的程序,前面咱们对立演示这个问题。

先给大家看一下 jetty 的 QueuedThreadPool 线程池。

看哪个版本的 jetty 呢?

能够看到这个 BUG 是在 2015 年 9 月 18 日被爆进去的。所以,咱们找一个这个日期之前的版本就行。

于是我找了一个 2015 年 9 月 3 日公布的 maven 版本:

在这个版本外面的 QueuedThreadPool 是这样的:

能够看到,它的确应用了 CLQ 队列。

而从这个对象所有被调用的中央来看,jetty 只应用了这个队列的 size、add、remove(obj) 办法:

和后面 max 同学形容的统一。

而后这个 max 同学给了几张图片,来佐证他的论点:

次要关注我框起来的中央,就是说他展现了一张图片。能够从这图片中看出内存透露的问题,而这个图片的起源是他们实在的我的项目。

这个我的项目曾经运行了大概两天,每五分钟就会有一个 web 申请过去。

上面是他给出的图片:

从他的这个图片中,我就只看出了 CLQ 的 node 很多。

然而他说了,他这个我的项目申请量并不大,用的 jetty 框架也不应该创立这么多的 node 进去。

好了,咱们后面剖析了 max 同学说的这个问题,接下来就是大佬出场,来解惑了:

咱们先不看答复,先看看答复问题的人是谁。

Greg Wilkins,何许人也?

我找到了他的领英地址:

https://www.linkedin.com/in/gregwilkins/?originalSubdomain=au

jetty 我的项目的领导者,短短的几个单词,就足以让你直呼牛逼。

高端的食材,往往只须要最简略的烹饪。高端的人才,往往只须要寥寥数语的介绍。

大佬的简历就是这么朴实无华,且干燥。

而且,你看这个头像。哎,酸了酸了。果然再次印证了这句话:变秃了,也变强了,并不适用于外国的神仙。

好了,咱们看一下这个 jetty 我的项目的领导者是怎么答复这个问题的:

首先他用 stupefied 示意了十分的震惊!而后,用到了 Ouch 语气词。相当于咱们常说的:

他说:卧槽,我发现它不仅导致内存透露,而且会随着工夫的推移,导致队列越来越慢。太 TM 震惊了。

这个问题肯定会对应用大量线程的服务器产生影响 …… 心愿不是所有的服务器都会有影响。

但不论是不是所有的服务器都有这个问题,只有呈现了这个问题,对于某些服务器来说,它肯定是一个十分重大的 BUG。

而后他说了一个 Great catch!我了解这是一个语气助词。就相似于:太牛逼了。

这个不好翻译,我贴一个例句,大家本人去领会一下吧:

我也是没想到,在技术文外面还给大家教起了英文。

最初他说:我正在修复这个问题。

而后,在 7 分 37 秒之后,Greg 又回复了一次:

能够看出,过了快 8 分钟,他还在继续震惊。我狐疑这 8 分钟外面他始终在点头。

他说:我还在为这个 BUG 点头,它怎么这么久都没被发现呢!对于 jetty 来说修复起来十分的简略,应用 set 构造代替 queue 队列即可实现一样的成果。

那咱们看一下修复之后的 jetty 中的 QueuedThreadPool 是怎么的,这里我用的是 2015 年 10 月 6 日公布的一个包,也就是这个 BUG 爆出之后的最近的一个包:

外面对应的代码是这样的:

简略粗犷的用 CurrentHashSet 代替了 CLQ。

因为这个 BUG 在 JDK 中是曾经修复了,出于好奇,我想看看 CLQ 还有没有机会从新站进去。

于是我看了一下往年公布的最新版本外面的代码:

既不是用的 CurrentHashSet,也没有给 CLQ 机会。

而是 JDK 8 的 ConcurrentHashMap 外面的 newKeySet 办法,C 位出道:

这是一个小小的 jetty 线程池的演变过程。祝贺你,又学到了一个基本上不会用到的知识点。

回到 Greg 的回复中,这次的回复外面,他还给了一个修复的演示实例,下一大节我会针对这个实例进行解读。

在 23 分钟之后,他就提交代码修复实现了。

从第一次回复帖子,到定位问题,再到提交代码,用了 30 分钟的工夫。

而后在凌晨 2 点 57 分(这个工夫点,大佬都是不必睡觉的吗?还是说刚修完福报,上班了),max 回复到:

我不敢相信 CLQ 应用起来会有这样的问题,他们至多应该在 API 文档外面阐明一下。

这里的他们,应该指的是 JDK 团队的成员,特指 Doug Lea,毕竟是他老爷子的作品。

为什么没有在 API 文档外面阐明呢?

因为他们本人也不晓得有这个 BUG 啊。

Greg 连着回复了两条,并且间接指出了解决方案:

问题的起因是 remove 办法的源码外面,有上图中标号为 ① 的这样一行代码。

这行代码会去勾销被移除的这个 node(其值曾经被替换为 null)和 list 之间的链接,而后能够让 GC 回收这个 node。

然而,当汇合外面只有一个元素的时候,next != null 这个判断是不成立的。

所以就会呈现这个须要移除的节点曾经被置为 null 了,但却没有勾销和队列之间的连贯,导致 GC 线程不会回收这个节点。

他给出的解决方案也很简略,就是标号为②、③的中央。总之,只须要让代码执行 pred.casNext 办法就行。

总之一句话,导致内存透露的起因是一个被置为 null 的 node,因为代码问题,导致该 node 节点,既不会被应用,也不会被 GC 回收掉。

如果你还没了解到这个 BUG 的起因,阐明你对 CLQ 这个队列的构造还不太清晰。

那么我倡议你读一下《Java 并发编程的艺术》这一本书,外面有一大节专门讲这个队列的,图文并茂,写的还是十分清晰。

这个 BUG 在 jetty 外面的前因后果算是说分明了。

而后,咱们再回到 JDK BUG 的这个链接中去:

他这里写的起因就是我后面说的起因,没有 unlink,所以不能被回收。

而且他说到:这个 BUG 在最新的 JDK 7、8 和 9 版本中都存在。

他说的最新是指截止这个 BUG 被提出来之前:

Demo 跑起来

这一大节外面,咱们跑一下 Greg 给的那个修复 Demo,亲手去摸一下这个 BUG 的样子。

https://bugs.eclipse.org/bugs/attachment.cgi?id=256704

你能够关上下面那个链接,间接复制粘贴到你的 IDEA 外面去:

留神第 13 行,因为 Greg 给的是修复 Demo,所以用的是 ConcurrentHashSet,因为咱们要演示这个 bug,所以应用 CLQ。

这个 Demo 就是在死循环外面调用 queue 的 add(obj) 和 remove(obj) 办法。每循环 10000 次,就打印出工夫距离、队列大小、最大内存、残余内存、总内存的值。

最终运行起来的成果是这样的(JDK 版本是 1.7.0_71):

能够看到每次打印 duration 这个工夫距离是越来越大,队列大小始终为 1。

前面三个内存相干的参数能够先不关怀,下一大节咱们用图形化工具来看。

你晓得下面这个程序,到我写文章写到这里的时候,我跑了多久了吗?

61 小时 32 分 53 秒。

最新一次循环 10000 次所须要的工夫距离是 575615ms,快靠近 10 分钟:

这就是 Greg 说的:不仅仅是内存透露,而且越来越慢。

然而,同样的程序,我用 JDK 1.8.0_212 版本跑的时候状况却是这样的:

工夫距离很稳固,不会随着工夫的推移而减少。

阐明这个版本是修复了这个 BUG 的,我带大家看看源码:

JDK 1.8.0_212 版本的源码外面,在 CLQ 的 remove(obj) 办法的 502 行开端正文了一个 unlink。

官网的修复办法能够看这里:

http://hg.openjdk.java.net/jdk8u/jdk8u-dev/jdk/rev/8efe549f3c87

改变比拟多,然而原理还是和之前剖析的一样:

我仅仅在两个 JDK 版本中跑过示例代码。

在 JDK 1.8.0_212 没有发现内存透露的问题,我看了对应的 remove(obj) 办法的源码的确是修复了。

在 JDK 1.7.0_71 中能够看到内存透露的问题。

unlink,一个简简单单的词,背地原来藏了这么多故事。

jconsole、VisualVM、jmc

既然都说到内存透露了,那必须得介绍几个可视化的故障排除工具。

后面说了,这个程序跑了 61 个小时了,给大家看一下这个时间段外面堆内存的应用状况:

能够看到整个堆内存的使用量是一个显著的、迟缓的回升趋势。

下面这个图就是来自 jconsole。

联合程序,通过图片咱们能够剖析出,这种状况肯定是内存透露了,这是一个十分经典的内存透露的走势。

接下来,咱们再看一下 jmc 的监控状况:

下面展现的是曾经应用的堆内存的大小,走势和 jconsole 的走势一样。

而后再看看 VisualVM 的图:

VisualVM 的图,我不晓得怎么看整个运行了 60 多小时的走势图,然而从下面的图也是能看出是有回升趋势的。

在 VisualVM 外面,咱们能够间接 Dump 堆,而后进行剖析:

能够分明的看到,CLQ 的 Node 的大小占据了 94.2%。

然而,从咱们的程序来看,咱们基本就没有用到这么多 Node。咱们只是用了一个而已。

你说,这不是内存透露是什么。

内存透露最终会导致 OOM。

所以当产生 OOM 的时候,咱们须要剖析是不是有内存透露。也就是看内存外面的对象到底应不应该存活,如果都应该存活那就不是内存透露,是内存不足了。须要检查一下 JVM 的参数配置(-Xmx/-Xms),依据机器内存状况,判断是否还能再调大一点。

同时,也须要检查一下代码,是否存在生命周期过程的对象,是否有数据结构应用不合理的中央,尽量减少程序运行期的内存耗费。

咱们能够通过把堆内存设置的小一点,来模仿一下内存透露导致的 OOM。

还是用之前的测试案例,然而咱们指定 -Xmx 为 20m,即最大可用的堆大小为 20m。

而后把代码跑起来,同时通过 VisualVM、jconsole、jmc 这三个工具监控起来,为了咱们有足够的时候筹备好检测工具,我在第 8 行退出休眠代码,其余的代码和之前的一样:

退出 -Xmx20m 参数:

运行起来之后,咱们同时通过工具来查看内存变动,上面三个图从上到下的工具别离是 VisualVM、jconsole、jmc:

从图片的走势来看,和咱们之前剖析的是一样的,内存始终在增长。

程序运行 19 分 06 秒后,产生 OOM 异样:

那失常的走势图应该是怎么样的呢?

咱们在 JDK 1.8.0_121 版本中(曾经修复了 remove 办法),用雷同的 JVM 参数(-Xmx20m)再跑一下:

首先从下面的日志中能够看出,工夫距离并没有递增,程序运行的十分的快。

而后用 VisualVM 检测内存,同样跑 19 分钟后截图如下:

能够看到堆内存的使用量并没有随着工夫的推移而越来越高。然而还是有十分频繁的 GC 操作。

这个不难理解,因为 CLQ 的数据结构用的是链表。而链表又是由不同的 node 节点组成。

因为调用 remove 办法后,node 节点具备被回收的条件,所以频繁的调用 remove 办法对节点进行删除,会触发 JVM 的 min GC。

这种 JDK BUG 导致的内存透露其实挺让人解体的。首先你第一次感知到它是因为程序产生了 OOM。

兴许你会先无脑的加大堆内存空间,恰好你的程序运行了一周之后又要上线了,所以波及到重启利用。

而后很长一段时间内没有产生 OOM 了。你就想这个问题可能解决了。

然而它还是在持续产生着,很可能因为节假日前后不能上线,比方国庆七天,加上前后几天,大略有半个月的样子利用没有上线,所以没有重启,程序越来越慢,最终导致第二次 OOM 的呈现。

这个时候,你感觉可能不是内存溢出这么简略了。

会不会是内存透露了?

而后你再次重启。这次重启之后,你开始时不时的 Dump 一下内存,拿进去剖析剖析。

忽然发现,这个 node 怎么这么多呢?

最终,找到这个问题的起因。

原来是 JDK 的 BUG。

你就会收回和 Greg 一样的感叹:卧槽,震惊,这么牛皮!?

我这个运行了 60 多小时的程序到当初堆内存应用了 233m,然而我整个堆的大小是靠近 2G。

通过 jmc 同时展现堆的整体大小和曾经应用的堆大小你能够发现,间隔内存透露能够说是道阻且长了:

我粗略的算了一下,这个程序大略还得运行 475 个小时左右,也就是 19 天之后才会呈现因为内存透露,导致的 OOM。

我会尽量跑下去,然而听到我电脑嗡嗡嗡的风扇声,我不晓得它还能不能顶得住。

如果它顶住了,我在前面的文章外面告诉大家。

好了,图形化工具这一大节就到这里了。

咱们只是展现了它们十分小的一个性能,正当的应用它们经常能达到事倍功半的作用。

如果你不太理解它们的性能,倡议你看看《深刻了解 JVM 虚拟机(第 3 版)》,外面有一章节专门讲这几个工具的。

最初说一句(求关注)

这是我昨天晚上写文章的时候拍的,女朋友说一眼望去感觉我是一个盯盘的人,在看股票走势图,这只股票太牛逼了。

要是股市的总体走势也像内存泄露那么单纯而间接就好了。

只有在 OOM 之前落袋为安就行。惋惜有的人就是在 OOM 的前一刻满仓杀入,真是个悲伤的故事。

文中提到的两本书,都是十分优良的值得学习的书籍。作为一个 Java 程序员,如果你还没有领有这两本书,我强烈建议你买来看看。

买不了吃亏,买不了受骗,只会感觉相见恨晚。你会发现原来这么多 JVM、多线程相干的面试题都是出自这两本书:

满腹经纶,难免会有纰漏,如果你发现了谬误的中央,还请你留言指出来,我对其加以批改。

感谢您的浏览,我保持原创,非常欢送并感谢您的关注。

我是 why,一个被代码耽搁的文学创作者,不是大佬,然而喜爱分享,是一个又暖又有料的四川好男人。

正文完
 0