关于JAVA GC LOG —— 如何看
本文基于Java HotSpot(TM) 64-Bit Server VM (build 24.71-b01, mixed mode)
1
GC相关的几个JVM启动参数：
| 参数 | 描述 |
|---|---|
| -XX:+PrintGCDetails | Print more details at garbage collection. Manageable. (Introduced in 1.4.0.) |
| -XX:+PrintGCDateStamps | Enables printing of a date stamp at every GC |
| -Xloggc::filename | Log GC verbose output to specified file. The verbose output is controlled by the normal verbose GC flags. |
| -XX:+UseGCLogFileRotation | Enabled GC log rotation, requires -Xloggc. |
| -XX:NumberOfGCLogFiles=1 | Set the number of files to use when rotating logs, must be >= 1. The rotated log files will use the following naming scheme, filename.0, filename.1, …, filename.n-1. |
| -XX:GCLogFileSize=8K | The size of the log file at which point the log will be rotated, must be >= 8K. |
| -XX:+PrintTenuringDistribution | Print tenuring age information. |
其它参数，详见Java HotSpot VM Options
2
一个Tomcat/7.0.26的例子：
JAVA_OPTS="-server -Xms1500M -Xmx1500M -Xmn500M -Xss256k -XX:PermSize=256m -XX:MaxPermSize=256m -XX:+UseParNewGC -XX:ParallelGCThreads=8 -XX:SurvivorRatio=6 -XX:TargetSurvivorRatio=90 -XX:MaxTenuringThreshold=15 -XX:SoftRefLRUPolicyMSPerMB=0 -XX:+UseConcMarkSweepGC -XX:+CMSIncrementalMode -XX:+UseCMSCompactAtFullCollection -XX:CMSFullGCsBeforeCompaction=5 -XX:CMSInitiatingOccupancyFraction=55 -XX:CMSIncrementalSafetyFactor=20 -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:../logs/gc-$DATE.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=128K -XX:+PrintTenuringDistribution "
对于young generation，使用ParNew；对于Tenured generation，使用CMS。
如何配置这些不同的算法，详见Our Collectors
一段GC日志：
2015-02-05T19:27:34.537+0800: 3737.811: [Full GC2015-02-05T19:27:34.537+0800: 3737.812: [CMS: 68036K->71687K(1024000K), 0.3253180 secs] 228627K->71687K(1472000K), [CMS Perm : 58490K->58337K(262144K)] icms_dc=0 , 0.3257740 secs] [Times: user=0.33 sys=0.00, real=0.33 secs]
2015-02-05T19:27:34.866+0800: 3738.141: [GC [1 CMS-initial-mark: 71687K(1024000K)] 71689K(1472000K), 0.0041430 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
2015-02-05T19:27:34.871+0800: 3738.145: [CMS-concurrent-mark-start]
2015-02-05T19:31:25.881+0800: 3969.156: [GC2015-02-05T19:31:25.881+0800: 3969.156: [ParNew
Desired survivor size 58982400 bytes, new threshold 15 (max 15)
- age 1: 8783432 bytes, 8783432 total
: 384000K->13384K(448000K), 0.0148490 secs] 455687K->85071K(1472000K) icms_dc=0 , 0.0153590 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]
2015-02-05T19:33:50.170+0800: 4113.445: [GC2015-02-05T19:33:50.171+0800: 4113.445: [ParNew
Desired survivor size 58982400 bytes, new threshold 15 (max 15)
- age 1: 5015016 bytes, 5015016 total
- age 2: 3093632 bytes, 8108648 total
我们仔细看看：
2015-02-05T19:27:34.537+0800:(日期) 3737.811:(时间戳) [Full GC(垃圾收集类型)2015-02-05T19:27:34.537+0800:(日期) 3737.812:(时间戳) [CMS:(算法以及generation) 68036K->71687K(1024000K), 0.3253180 secs(Tenured generation的情况)] 228627K->71687K(1472000K)(整个堆的情况), [CMS Perm : 58490K->58337K(262144K)(Perm的情况)] icms_dc=0 , 0.3257740 secs] [Times: user=0.33 sys=0.00, real=0.33 secs]
2015-02-05T19:31:25.881+0800: 3969.156: [GC2015-02-05T19:31:25.881+0800: 3969.156: [ParNew
Desired survivor size 58982400 bytes, new threshold 15 (max 15)
- age 1: 8783432 bytes, 8783432 total
: 384000K->13384K(448000K), 0.0148490 secs] 455687K->85071K(1472000K) icms_dc=0 , 0.0153590 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]
更加详细的分析，参考Understanding CMS GC Logs
3
如何可视化？
使用GCViewer