服务器从jdk1.6.0升级到1.6.0_12的过程记录

服务器从jdk1.6.0升级到1.6.0_12的过程记录

作者：lizongbo 发表于：00:21. 星期六, 二月 21st, 2009
版权声明：可以任意转载，转载时请务必以超链接形式标明文章原始出处和作者信息及本版权声明。
http://618119.com/archives/2009/02/21/136.html

---

服务器从jdk1.6.0升级到1.6.0_12的过程记录

前段时间系统存在问题，在java程序运行几天之后，就会出现物理内存被耗尽的情况。
服务器8G内存，启动两个进程，Xmx=3000m，而程序运行一段时间后，物理内存消耗达到了95%，
然后再持续一段时间之后，服务器就出现死机现象，通过“-verbosegc -XX:+PrintGCDetails”生成的gc log里可以发现，死机前java进程通常会有一大堆Full GC记录。
top -s
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
618119 lizongbo 16 0 7533m 4.8G 1692 S 28 61.0 3309:35 java

当时采取的临时办法是在监控到内存超过95%十分钟后，就通过监控kill其中一个进程，并重启该进程。
这样的处理方式虽然避免了死机情况的出现，但是没想到的时候，没有kill的这个进程，
在持续运行一段时间后，居然占用物理内存到了60%。（linux通过top -s 看%MEM的值）
当时查遍所有的代码，没能找到出现问题的原因。
用命令jmap -heap 618119也没看出不对劲的地方。
然后jmap -histo:live 618119|head -n 40 查看数量最多的对象，发现
java.lang.ThreadLocal$ThreadLocalMap$Entry
[Ljava.lang.ThreadLocal$ThreadLocalMap$Entry;
java.util.concurrent.locks.ReentrantReadWriteLock$Sync$HoldCounter
java.util.concurrent.LinkedBlockingQueue$Node
java.util.concurrent.locks.ReentrantReadWriteLock$Sync$ThreadLocalHoldCounter这几个类的实例非常多。
在反复查找代码之后，怀疑是其中用到的ReentrantReadWriteLock出了问题。
关于ReentrantReadWriteLock，可参考：jdk中文本的java doc：
http://download.developers.sun.com.cn/javadoc/jdk6/docs/zh/api/java/util/concurrent/locks/ReentrantReadWriteLock.html
程序里用到了readLock和writeLock的lock与unlock方法，但是试用的方式和官方例子一致，看不出什么问题。
由于曾经看到 阿里的岑文初提到过LinkedBlockingQueue存在内存泄漏：
参考： http://www.blogjava.net/cenwenchu/archive/2008/09/18/229809.html
关于LinkedBlockingQueue可以参考:
http://download.developers.sun.com.cn/javadoc/jdk6/docs/zh/api/java/util/concurrent/LinkedBlockingDeque.html

于是查看linux服务器上的jdk版本:
java -version
java version “1.6.0″
Java(TM) SE Runtime Environment (build 1.6.0-b105)
Java HotSpot(TM) 64-Bit Server VM (build 1.6.0-b105, mixed mode)
原来jdk1.6正式发布时的第一个build正式版本。
因为程序改动并不大，而刚好最近发生这样奇怪的事情，但是拿不出直接证据证明。
于是初步猜测该问题是sun的jdk的bug所致，到sun的官方网站阅读jdk的Update Release Notes日志。

于是在Update Release Notes里找到了以下几个bug修复的记录：

1.6.0_01-b06 修复的关于并发和gc的bug有：
6433335 hotspot garbage_collector ParNewGC times spiking, eventually taking up 20 out of every 30 seconds
6459113 hotspot garbage_collector CMS+ParNew: wildly different ParNew pause times depending on heap shape caused by allocation spread
来源：http://java.sun.com/javase/6/webnotes/6u1.html

1.6.0_02-b06 修复的关于并发和gc的bug有：
6468516 hotspot garbage_collector CMS: deal correctly with concurrently cleared or enqueued Reference objects
6468290 hotspot garbage_collector Divide and allocate out of eden on a per cpu basis
6460501 java classes_util_concurrent Synchronizer timed acquire still leaks memory
6497138 java classes_util_concurrent Scalability limitation in ConcurrentHashMap on Java 6
来源：http://java.sun.com/javase/6/webnotes/6u2.html

1.6.0_04-b12 修复的关于并发和gc的bug有一大堆，就不列出来了：

来源：http://java.sun.com/javase/6/webnotes/6u4.html

1.6.0_10-b33 修复的关于并发和gc的bug有：
6635560 hotspot garbage_collector segv in reference processor on t1000
6642634 hotspot garbage_collector Test nsk/regression/b6186200 crashed with SIGSEGV
6662086 hotspot garbage_collector 6u4+, 7b11+: CMS never clears referents when -XX:+ParallelRefProcEnabled
6676016 hotspot garbage_collector ParallelOldGC leaks memory
6576792 java classes_util_concurrent ThreadPoolExecutor methods leak interrupts when run in pool threads
6639183 java classes_util_concurrent Scheduling large negative delay hangs entire ScheduledExecutor

来源：http://java.sun.com/javase/6/webnotes/6u10.html

1.6.0_12-b04 修复的关于并发和gc的bug有：
6722112 hotspot garbage_collector CMS: Incorrect encoding of overflown object arrays during concurrent precleaning
6722116 hotspot garbage_collector CMS: Incorrect overflow handling when using parallel concurrent marking
6739357 hotspot garbage_collector CMS: Switch off CMSPrecleanRefLists1 until 6722113 can be fixed

来源：http://java.sun.com/javase/6/webnotes/6u12.html

经过对jdk1.6修复bug的记录的分析，怀疑是重点是Synchronizer的这个bug引发的问题
http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6460501，
从bug描述及java源代码分析，java并发库里的大量的并发组件都依赖于AbstractQueuedSynchronizer，
LinkedBlockingQueue，Semaphore，ReentrantLock，ReentrantReadWriteLock等，均有继承AbstractQueuedSynchronizer的Sync。

由此进一步怀疑是jdk的bug造成内存泄漏的问题。
于是先升级了其中一台服务器的jdk到最新版本，
java -version
java version “1.6.0_12″
Java(TM) SE Runtime Environment (build 1.6.0_12-b04)
Java HotSpot(TM) 64-Bit Server VM (build 11.2-b01, mixed mode)

升级之后，程序连续运行7天没出任何问题，内存回收也十分正常。
运行jmap -histo:live 618119|head -n 40 再次查看对象数量的时候，数量排在前10的实例和存在问题之前的顺序不再一样了。
num #instances #bytes class name
———————————————-
1: 12805991 813400696 [B
2: 8575933 205822392 java.lang.Integer
3: 246199 107685936 [[B
4: 344259 98264616 [Ljava.lang.Object;
5: 1621708 90815648 java.lang.ThreadLocal$ThreadLocalMap$Entry
6: 824 63288512 [Ljava.lang.ThreadLocal$ThreadLocalMap$Entry;
7: 1620504 51856128 java.util.concurrent.locks.ReentrantReadWriteLock$Sync$HoldCounter
8: 925444 37017760 java.lang.String
9: 333234 30753832 [C
10: 354863 17033424 java.util.HashMap$Entry

于是对改该程序的其它服务器也进行了jdk升级，升级为1.6.0_12-b04。
观察几天后发现，不再出现物理内存耗尽的情况，而且单进程的java内存消耗不再超过Xmx设置的值，在在线用户低谷时候内存也能够顺利回收了。观察一段时间确认jdk升级的效果后，对其他业务的jdk也进行了升级，相关业务也连续几天没在收到告警了。

JDK7.0引入了新的jdk算法，叫做：G1 （The Garbage-First garbage collector），
尤其适合大用户，高并发，容易产生大量临时对象的业务。
参考：http://blogs.sun.com/theplanetarium/entry/java_vm_trying_a_new
该算法也将在jdk1.6的jdk1.6.0_14中引入，目前jdk1.6 u14已经有ea测试版了，
下载地址为：http://download.java.net/jdk6/binaries/ (http://download.java.net/jdk6/6u14/)
试用G1算法的命令行参数为：-XX:+UnlockExperimentalVMOptions -XX:+UseG1GC
参考：http://oss-tw.blogspot.com/2009/02/java-jvm-g1-java-hotspot-14.html

期待JDK1.6 u14早期发布正式版，也期待JDK1.7（JDK7.0）早日正式发布。
到那时候，有jdk的高性能支撑，一些需求就可以轻松搞定了。