一 进行数据统计
1 内存占用查看
using thread-local object allocation.
Parallel GC with 10 thread(s)
Heap Configuration:
MinHeapFreeRatio = 40
MaxHeapFreeRatio = 70
MaxHeapSize = 5368709120 (5120.0MB)
NewSize = 1310720 (1.25MB)
MaxNewSize = 17592186044415 MB
OldSize = 5439488 (5.1875MB)
NewRatio = 2
SurvivorRatio = 8
PermSize = 21757952 (20.75MB)
MaxPermSize = 268435456 (256.0MB)
Heap Usage:
PS Young Generation
Eden Space:
capacity = 1766129664 (1684.3125MB)
used = 533709328 (508.98487854003906MB)
free = 1232420336 (1175.327621459961MB)
30.219147488369234% used
From Space:
capacity = 9502720 (9.0625MB)
used = 9474600 (9.035682678222656MB)
free = 28120 (0.02681732177734375MB)
99.70408472521552% used
To Space:
capacity = 11862016 (11.3125MB)
used = 0 (0.0MB)
free = 11862016 (11.3125MB)
0.0% used
PS Old Generation
capacity = 3579183104 (3413.375MB)
used = 3175269304 (3028.172782897949MB)
free = 403913800 (385.2022171020508MB)
88.71491655320465% used
PS Perm Generation
capacity = 162201600 (154.6875MB)
used = 161658584 (154.16963958740234MB)
free = 543016 (0.5178604125976562MB)
99.66522155145202% used
2 通过观察近几天的gc日志可以看出, 一天GC平均统计如下:
1 ygc,16200次左右,总耗时430秒左右,平均5秒一次,每次差不多26毫秒
2 ygc回收效果很好,每次基本可以释放99.5%的空间
3 full gc,15次左右,总耗时50秒左右,单次最大耗时4秒左右
3 获取常驻内存大小:
grep Full /data/web/resin/log/jvm.log_2013-11-* | awk -F"PSOldGen: " '{print $2}' | awk -F'K\\\(' '{print $1}' | awk -F"->" '{print $2}' | sort -nr | head
1998109K->1951M
grep Full /data/web/resin/log/jvm.log_2013-11-* | awk -F"PSPermGen: " '{print $2}' | awk -F'K\\\(' '{print $1}' | awk -F"->" '{print $2}' | sort -nr | head
160796K->157M
4 获取垃圾产生速率
5秒钟填满1706.6M空间
5 目标如下:
1 ygc过于频繁,尽量减少ygc次数,这样可能导致每次ygc时间变长,尽量将垃圾在新生代回收,尽可能少触发full gc
2 full gc频繁,可以减少次数
6 计划如下:
1 针对young gc频繁
1.1 加大新生代容量,相应增大eden区空间,以便可以快速进行初次分配内存
1.2 增大survivor空间,减少young gc次数
2 针对full gc较为频繁
2.1 目前UseParallelGC:老年代使用单线程收集,改为cms
2.2 增大老年代容量,减少full gc次数
3 PermSize设置成和MaxPermSize一样,避免jvm动态调整。
二 确定内存大小
空间设定参考
1 Xmx=Xms,PermSize=MaxPermSize,因为jvm需要full gc才能调整他们的大小.
2 堆大小为老年代常驻内存的3至4倍
3 永久代为永久代常驻内存的1.2到1.5倍
4 年轻代为老年代常驻内存的1至1.5倍
5 老年代不能小于常驻内存的的1.5倍。
6 新生代>Xmx*10%,太小会导致频繁ygc。
2.1 首先确定eden大小
计划将ygc调到平均7秒一次,1706.6*7/5=2389.24
2.2 确定young大小
1951 * 1.5 = 2926
2.3 确定堆区大小
1951*4 = 7804
2.4 确定永久代大小
157*1.5 = 235.5
2.5 确定survivor大小
默认为8,先不调整
Xms=Xmx=7804M
PermSize=MaxPermSize=235M
eden=2926*8/10=2340.8M
s0=s1=2926/10=292.6M
CMS最可能出现的问题是concurrent mode failed,只要保证老年代剩余大小足以容纳新生代晋升上来的对象一般就没有问题。
老年代剩余大小=(7804-2926)/4=1219.5
新生代大小晋升最大值=eden+1survivor=2633
2633>1219,可能发生晋升失败,但是这种情况是新生代对象全部晋升,而根据实际观察,
之前的YGC后晋升到老年代的对象最大为113.95M 平均为2.18M
调优后YGC后晋升到老年代的对象最大为235.89M 平均为不到1M
而1219.5/235.89=5.17,即按最坏情况算,可以ygc5次,而每次ygc平均间隔为7.32,5*7=35秒,35miao内应早Full GC完毕了
三 调试
通过PrintTenuringDistribution,发现ygc时会发生survivor overflow,而该区域占用在项目启动后3分钟内占用高达300M,直接导致ygc时间增大,且老年代迅速增大。
因为对象晋升到老年代受年龄和MaxTenuringThreshold(默认是15,若指定mcs默认为4)的影响,300远大于292/2(TargetSurvivorRatio默认只使用50%,jvm为了防止ygc时to空间不足而导致对象晋升而做的策略,一般不用改),故这些对象只进行一次ygc,就到了老年代。
如果避免这种情况,至少要将survivor增大至600M(试验了几次,还有增大趋势,跟eden大小也有关,eden越大,到survivor中的也越多),但是增大该空间会导致ygc时间变长。
经过观察,对象在ygc中熬过8次基本回收的差不多了,为了尽量在新生代回收,故暂定MaxTenuringThreshold=10
另外,在survivor中age(1-10)的对象总大小在项目稳定运行时基本不会超过40M,故为了一开始的ygc而过多增大survivor而导致后续所有的ygc时间变长不太值得。
鉴于稳定运行时期,分配对象的速率也比较稳定,在Eden区大小不变的情况下(为了保证ygc频率),尝试将TargetSurvivorRatio增大至70。
故最终参数如下:
total 7804
young 2926
eden 2926*8/10=2340.8
survivor 2926/10=292.6 292.6*0.7=204.82
old 7804-2926=4878
20131122发现
CMS: abort preclean due to time 2013-11-23T09:50:59.894+0800: [CMS-concurrent-abortable-preclean: 5.076/5.132 secs] [Times: user=12.94 sys=1.00, real=5.13 secs]
增加CMSScavengeBeforeRemark参数,加速remark
20131123发现full gc
2013-11-23T21:41:20.309+0800: [Full GC [CMS: 1499765K->789453K(4995072K), 4.7440890 secs] 1885971K->789453K(7691712K), [CMS Perm : 239615K->153151K(239616K)], 4.7455880 secs] [Times: user=4.81 sys=0.00, real=4.74 secs]
由于cms默认不对perm区进行回收,加上CMSClassUnloadingEnabled
20131123与20131125日志对比:
没加CMSScavengeBeforeRemark之前:
2013-11-23T09:50:59.902+0800: [GC[YG occupancy: 2103894 K (2696640 K)][Rescan (parallel) , 1.5680650 secs][weak refs processing, 0.8144200 secs] [1 CMS-remark: 3746947K(4995072K)] 5850842K(7691712K), 2.4045340 secs] [Times: user=17.41 sys=0.00, real=2.40 secs]
加了之后:
2013-11-25T16:41:20.225+0800: [GC[YG occupancy: 1905513 K (2696640 K)]2013-11-25T16:41:20.226+0800: [GC [ParNew: 1905513K->21977K(2696640K), 0.0269670 secs] 5652545K->3771915K(7691712K), 0.0290360 secs] [Times: user=0.15 sys=0.02, real=0.03 secs]
[Rescan (parallel) , 0.0093790 secs][weak refs processing, 0.9328530 secs][class unloading, 0.0538110 secs][scrub symbol & string tables, 0.0134790 secs] [1 CMS-remark: 3749937K(4995072K)]
3771915K(7691712K), 1.0622870 secs] [Times: user=1.27 sys=0.02, real=1.06 secs]
很明显发生了一次YGC,只用了29ms,但是将rescan阶段的耗时从1.5680650降低到了0.0093790,而且可以看出对perm区的回收(上面加粗倾斜部分),总时间从2.4秒降到1.06秒。
最终定版参数如下:
args="-Xms7804M -Xmx7804M -Xmn2926M -XX:PermSize=256M -XX:MaxPermSize=256M -XX:SurvivorRatio=8 -XX:TargetSurvivorRatio=70 -XX:MaxTenuringThreshold=10 -J-server -J-Xss256k -J-XX:ThreadStackSize=256 -XX:+HeapDumpOnOutOfMemoryError -J-XX:+PrintGCDetails -J-XX:+PrintGCDateStamps
-XX:+UseConcMarkSweepGC -XX:+DisableExplicitGC -XX:SoftRefLRUPolicyMSPerMB=0 -XX:CMSInitiatingOccupancyFraction=75 -XX:+UseCMSInitiatingOccupancyOnly -XX:ParallelGCThreads=12 -XX:+CMSScavengeBeforeRemark -XX:+CMSClassUnload
ingEnabled -Djava.library.path=/data/web/resin/libexec:/data/web/jdk/lib:/usr/lib64 -Djmagick.systemclassloader=false -DWapUseShortTicket=true"
jvm.log_2013-11-30和jvm.log_2013-12-01是未调优之前的结果。
jvm.log_2013-11-30.1和jvm.log_2013-12-01.1是调优之后的结果。
1 ygc次数减少3500次左右,平均9(24*3600/9659)秒一次,比之前延迟了3秒,但是每次增加9ms左右
2 full gc减少10次左右,full gc每次时间可以保持在1秒左右
3 总时间减少50秒左右