服务器从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的高性能支撑，一些需求就可以轻松搞定了。
Tags:
gc,
Java,
JDK,
jmap,
Linux,
log
Related posts
