有关JVM的GC日志，大家帮忙分析啊！

[coolspringlsq]

ESIN+MYSQL.操作系统为：WINDOWS2008 R2 内存8G，CPU：8核，JDK为：64位1.6.43版。

目前出现系统运行一段时间出现GC日志异常，出现FULLGC.

JVM的配置如下。

<!--
- The JVM arguments
-->
<jvm-arg>-Xmx1200m</jvm-arg>
<jvm-arg>-Xms1200m</jvm-arg>
<jvm-arg>-Xss512k</jvm-arg>

<!-- always use defaults except OutOfMemory(OOM) exception!
<jvm-arg>-Xmn128m</jvm-arg>
<jvm-arg>-XX:MaxPermSize=128m</jvm-arg>
<jvm-arg>-XX:SurvivorRatio=8</jvm-arg>
<jvm-arg>-XX:MaxNewSize=64m</jvm-arg>
<jvm-arg>-XX:MaxTenuringThreshold=3</jvm-arg>
-->

<jvm-arg>-XX:MaxNewSize=128m</jvm-arg>
<jvm-arg>-XX:MaxPermSize=256m</jvm-arg>
<jvm-arg>-XX:NewRatio=4</jvm-arg>
<jvm-arg>-Xloggc:log/gc.log</jvm-arg>
<jvm-arg>-XX:+UseConcMarkSweepGC</jvm-arg>
<jvm-arg>-XX:+CMSPermGenSweepingEnabled</jvm-arg>
<jvm-arg>-XX:+CMSClassUnloadingEnabled</jvm-arg>
<jvm-arg>-XX:MaxTenuringThreshold=3</jvm-arg>
<jvm-arg>-XX:+PrintGCTimeStamps</jvm-arg>
<jvm-arg>-XX:+PrintGCDetails</jvm-arg>
<jvm-arg>-XX:+PrintTenuringDistribution</jvm-arg>
<jvm-arg>-XX:+HeapDumpOnOutOfMemoryError</jvm-arg>




一开始GC日志比较正常。
59.232: [GC 59.232: [ParNew
Desired survivor size 6684672 bytes, new threshold 3 (max 3)
- age 1: 1170248 bytes, 1170248 total
- age 2: 3916208 bytes, 5086456 total
- age 3: 1321072 bytes, 6407528 total
: 115773K->11181K(118016K), 0.0120487 secs] 201967K->100568K(1420544K), 0.0121367 secs] [Times: user=0.08 sys=0.00, real=0.02 secs]
60.389: [GC 60.389: [ParNew
Desired survivor size 6684672 bytes, new threshold 3 (max 3)
- age 1: 639824 bytes, 639824 total
- age 2: 1151240 bytes, 1791064 total
- age 3: 3914080 bytes, 5705144 total
: 116141K->7365K(118016K), 0.0075017 secs] 205528K->98052K(1420544K), 0.0075795 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]

[coolspringlsq]

运行了两三天出现 213602.375: [GC[YG occupancy: 3780 K (118016 K)]213602.375: [Rescan (parallel) , 0.0065068 secs]213602.382: [weak refs processing, 0.0000185 secs]213602.382: [class unloading, 0.0523132 secs]213602.434: [scrub symbol & string tables, 0.0276522 secs] [1 CMS-remark: 1008419K(1302528K)] 1012200K(1420544K), 0.0966628 secs] [Times: user=0.09 sys=0.00, real=0.09 secs] 213602.472: [CMS-concurrent-sweep-start] 213602.973: [CMS-concurrent-sweep: 0.496/0.501 secs] [Times: user=0.58 sys=0.08, real=0.50 secs] 213602.973: [CMS-concurrent-reset-start] 213602.980: [CMS-concurrent-reset: 0.007/0.007 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 213604.969: [GC [1 CMS-initial-mark: 1008383K(1302528K)] 1078901K(1420544K), 0.0964700 secs] [Times: user=0.09 sys=0.01, real=0.09 secs] 213605.065: [CMS-concurrent-mark-start] 213606.354: [CMS-concurrent-mark: 1.288/1.288 secs] [Times: user=2.58 sys=0.03, real=1.28 secs] 213606.354: [CMS-concurrent-preclean-start] 213606.362: [CMS-concurrent-preclean: 0.008/0.008 secs] [Times: user=0.02 sys=0.00, real=0.02 secs] 213606.362: [CMS-concurrent-abortable-preclean-start] CMS: abort preclean due to time 213611.388: [CMS-concurrent-abortable-preclean: 0.764/5.026 secs] [Times: user=0.48 sys=0.17, real=5.02 secs] 213611.389: [GC[YG occupancy: 103714 K (118016 K)]213611.389: [Rescan (parallel) , 0.1100134 secs]213611.499: [weak refs processing, 0.0000515 secs]213611.499: [class unloading, 0.0626116 secs]213611.561: [scrub symbol & string tables, 0.0275545 secs] [1 CMS-remark: 1008383K(1302528K)] 1112098K(1420544K), 0.2104308 secs] [Times: user=0.23 sys=0.00, real=0.22 secs] 213611.600: [CMS-concurrent-sweep-start] 213612.088: [CMS-concurrent-sweep: 0.488/0.488 secs] [Times: user=0.50 sys=0.03, real=0.48 secs] 213612.088: [CMS-concurrent-reset-start] 213612.095: [CMS-concurrent-reset: 0.007/0.007 secs] [Times: user=0.02 sys=0.00, real=0.02 secs] 213612.154: [GC 213612.154: [ParNew Desired survivor size 6684672 bytes, new threshold 3 (max 3) - age 1: 727296 bytes, 727296 total - age 2: 551936 bytes, 1279232 total - age 3: 182840 bytes, 1462072 total : 108177K->2026K(118016K), 0.0171739 secs] 1116351K->1010746K(1420544K), 0.0173081 secs] [Times: user=0.13 sys=0.00, real=0.03 secs] 213612.173: [GC [1 CMS-initial-mark: 1008719K(1302528K)] 1010776K(1420544K), 0.0060061 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 213612.179: [CMS-concurrent-mark-start] 213613.446: [CMS-concurrent-mark: 1.259/1.267 secs] [Times: user=2.59 sys=0.00, real=1.27 secs] 213613.446: [CMS-concurrent-preclean-start] 213613.453: [CMS-concurrent-preclean: 0.007/0.007 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 213613.453: [CMS-concurrent-abortable-preclean-start] 213616.798: [GC 213616.798: [ParNew Desired survivor size 6684672 bytes, new threshold 3 (max 3) - age 1: 238728 bytes, 238728 total - age 2: 459192 bytes, 697920 total - age 3: 525920 bytes, 1223840 total : 106986K->2022K(118016K), 0.0142690 secs] 1115706K->1010919K(1420544K), 0.0143658 secs] [Times: user=0.00 sys=0.00, real=0.02 secs] 213617.062: [CMS-concurrent-abortable-preclean: 0.563/3.609 secs] [Times: user=0.52 sys=0.20, real=3.61 secs] 213617.063: [GC[YG occupancy: 83703 K (118016 K)]213617.063: [Rescan (parallel) , 0.0926961 secs]213617.156: [weak refs processing, 0.0000924 secs]213617.156: [class unloading, 0.0405039 secs]213617.196: [scrub symbol & string tables, 0.0282198 secs] [1 CMS-remark: 1008896K(1302528K)] 1092600K(1420544K), 0.1716456 secs] [Times: user=0.17 sys=0.00, real=0.17 secs] 213617.235: [CMS-concurrent-sweep-start] 213617.741: [CMS-concurrent-sweep: 0.502/0.506 secs] [Times: user=0.61 sys=0.02, real=0.50 secs] 213617.741: [CMS-concurrent-reset-start] 213617.748: [CMS-concurrent-reset: 0.007/0.007 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 213619.736: [GC [1 CMS-initial-mark: 1008441K(1302528K)] 1113468K(1420544K), 0.1515734 secs] [Times: user=0.14 sys=0.02, real=0.14 secs] 213619.888: [CMS-concurrent-mark-start] 213621.168: [CMS-concurrent-mark: 1.281/1.281 secs] [Times: user=2.59 sys=0.00, real=1.28 secs] 213621.168: [CMS-concurrent-preclean-start] 213621.177: [CMS-concurrent-preclean: 0.008/0.008 secs] [Times: user=0.01 sys=0.00, real=0.02 secs] 213621.177: [CMS-concurrent-abortable-preclean-start] 213621.755: [GC 213621.755: [ParNew Desired survivor size 6684672 bytes, new threshold 3 (max 3) - age 1: 316208 bytes, 316208 total - age 2: 110360 bytes, 426568 total - age 3: 384528 bytes, 811096 total : 106982K->1183K(118016K), 0.0152519 secs] 1115423K->1010105K(1420544K), 0.0153782 secs] [Times: user=0.03 sys=0.00, real=0.02 secs] CMS: abort preclean due to time 213626.247: [CMS-concurrent-abortable-preclean: 0.650/5.070 secs] [Times: user=0.20 sys=0.22, real=5.06 secs] 213626.249: [GC[YG occupancy: 19707 K (118016 K)]213626.249: [Rescan (parallel) , 0.0326256 secs]213626.282: [weak refs processing, 0.0000211 secs]213626.282: [class unloading, 0.0401079 secs]213626.322: [scrub symbol & string tables, 0.0286030 secs] [1 CMS-remark: 1008922K(1302528K)] 1028629K(1420544K), 0.1127798 secs] [Times: user=0.14 sys=0.02, real=0.13 secs] 213626.362: [CMS-concurrent-sweep-start] 213626.847: [CMS-concurrent-sweep: 0.485/0.485 secs] [Times: user=0.48 sys=0.02, real=0.48 secs] 213626.847: [CMS-concurrent-reset-start] 213626.854: [CMS-concurrent-reset: 0.007/0.007 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 213628.846: [GC [1 CMS-initial-mark: 1008828K(1302528K)] 1030049K(1420544K), 0.0331694 secs] [Times: user=0.03 sys=0.00, real=0.03 secs] 213628.880: [CMS-concurrent-mark-start] 213630.149: [CMS-concurrent-mark: 1.269/1.269 secs] [Times: user=2.56 sys=0.06, real=1.27 secs] 213630.149: [CMS-concurrent-preclean-start] 213630.156: [CMS-concurrent-preclean: 0.007/0.007 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 213630.156: [CMS-concurrent-abortable-preclean-start] CMS: abort preclean due to time 213635.217: [CMS-concurrent-abortable-preclean: 0.580/5.061 secs] [Times: user=0.14 sys=0.27, real=5.06 secs] 213635.219: [GC[YG occupancy: 23378 K (118016 K)]213635.219: [Rescan (parallel) , 0.0326621 secs]213635.251: [weak refs processing, 0.0000616 secs]213635.251: [class unloading, 0.0381358 secs]213635.290: [scrub symbol & string tables, 0.0274115 secs] [1 CMS-remark: 1008828K(1302528K)] 1032207K(1420544K), 0.1084087 secs] [Times: user=0.09 sys=0.00, real=0.11 secs] 213635.327: [CMS-concurrent-sweep-start] 213635.814: [CMS-concurrent-sweep: 0.487/0.487 secs] [Times: user=0.52 sys=0.03, real=0.50 secs] 213635.814: [CMS-concurrent-reset-start] 213635.821: [CMS-concurrent-reset: 0.007/0.007 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 213637.816: [GC [1 CMS-initial-mark: 1008799K(1302528K)] 1032670K(1420544K), 0.0348419 secs] [Times: user=0.03 sys=0.00, real=0.03 secs] 213637.851: [CMS-concurrent-mark-start] 213638.306: [GC 213638.306: [ParNew Desired survivor size 6684672 bytes, new threshold 3 (max 3) - age 1: 657624 bytes, 657624 total - age 2: 112960 bytes, 770584 total - age 3: 80424 bytes, 851008 total : 106143K->1173K(118016K), 0.0248916 secs] 1114942K->1010312K(1420544K), 0.0250117 secs] [Times: user=0.13 sys=0.00, real=0.03 secs]

[coolspringlsq]

第四天出现： 306848.350: [GC [1 CMS-initial-mark: 1131999K(1302528K)] 1139291K(1420544K), 0.0094848 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 306848.360: [CMS-concurrent-mark-start] 306848.385: [Full GC 306848.385: [CMS306849.855: [CMS-concurrent-mark: 1.475/1.496 secs] [Times: user=3.08 sys=0.02, real=1.50 secs] (concurrent mode failure): 1131999K->1134077K(1302528K), 5.9274619 secs] 1162177K->1134077K(1420544K), [CMS Perm : 262143K->262123K(262144K)], 5.9276779 secs] [Times: user=7.33 sys=0.00, real=5.92 secs] 306854.447: [Full GC 306854.447: [CMS: 1134077K->1136031K(1302528K), 4.5442706 secs] 1219899K->1136031K(1420544K), [CMS Perm : 262143K->262139K(262144K)], 4.5445157 secs] [Times: user=4.61 sys=1.70, real=4.55 secs] 306858.994: [GC [1 CMS-initial-mark: 1136031K(1302528K)] 1136126K(1420544K), 0.0081318 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 306859.003: [CMS-concurrent-mark-start] 306859.108: [Full GC 306859.109: [CMS306860.521: [CMS-concurrent-mark: 1.504/1.518 secs] [Times: user=3.26 sys=0.11, real=1.53 secs] (concurrent mode failure): 1136031K->1134019K(1302528K), 5.8989002 secs] 1183768K->1134019K(1420544K), [CMS Perm : 262143K->262143K(262144K)], 5.8991365 secs] [Times: user=7.30 sys=0.22, real=5.91 secs] 306865.011: [Full GC 306865.011: [CMS: 1134019K->1131898K(1302528K), 7.4510346 secs] 1134019K->1131898K(1420544K), [CMS Perm : 262143K->261264K(262144K)], 7.4512669 secs] [Times: user=4.08 sys=0.14, real=7.45 secs] 306872.538: [GC [1 CMS-initial-mark: 1131898K(1302528K)] 1150758K(1420544K), 0.0294241 secs] [Times: user=0.02 sys=0.01, real=0.02 secs] 306872.567: [CMS-concurrent-mark-start] 306874.002: [GC 306874.002: [ParNew Desired survivor size 6684672 bytes, new threshold 1 (max 3) - age 1: 13000944 bytes, 13000944 total : 104960K->13056K(118016K), 0.0216254 secs] 1236858K->1147499K(1420544K), 0.0219238 secs] [Times: user=0.20 sys=0.00, real=0.03 secs] 306874.320: [CMS-concurrent-mark: 1.557/1.752 secs] [Times: user=3.75 sys=0.11, real=1.77 secs] 306874.320: [CMS-concurrent-preclean-start] 306874.337: [CMS-concurrent-preclean: 0.017/0.017 secs] [Times: user=0.01 sys=0.00, real=0.02 secs] 306874.337: [CMS-concurrent-abortable-preclean-start] 306875.543: [GC 306875.543: [ParNew Desired survivor size 6684672 bytes, new threshold 1 (max 3) - age 1: 7284288 bytes, 7284288 total : 118016K->11772K(118016K), 0.0281432 secs] 1252459K->1159293K(1420544K), 0.0283624 secs] [Times: user=0.13 sys=0.00, real=0.03 secs] 306876.601: [CMS-concurrent-abortable-preclean: 0.751/2.263 secs] [Times: user=1.28 sys=0.33, real=2.26 secs] 306876.603: [GC[YG occupancy: 68363 K (118016 K)]306876.603: [Rescan (parallel) , 0.0443641 secs]306876.648: [weak refs processing, 0.0001346 secs]306876.648: [class unloading, 0.0710007 secs]306876.719: [scrub symbol & string tables, 0.0307261 secs] [1 CMS-remark: 1147520K(1302528K)] 1215884K(1420544K), 0.1573845 secs] [Times: user=0.19 sys=0.00, real=0.16 secs] 306876.761: [CMS-concurrent-sweep-start] 306877.253: [CMS-concurrent-sweep: 0.492/0.492 secs] [Times: user=0.56 sys=0.03, real=0.48 secs] 306877.253: [CMS-concurrent-reset-start] 306877.260: [CMS-concurrent-reset: 0.007/0.007 secs] [Times: user=0.02 sys=0.00, real=0.02 secs] 306877.459: [GC 306877.460: [ParNew Desired survivor size 6684672 bytes, new threshold 3 (max 3) - age 1: 491064 bytes, 491064 total : 116732K->5123K(118016K), 0.0180645 secs] 1262034K->1156974K(1420544K), 0.0182840 secs] [Times: user=0.08 sys=0.00, real=0.03 secs] 306877.479: [GC [1 CMS-initial-mark: 1151851K(1302528K)] 1157084K(1420544K), 0.0075813 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 306877.487: [CMS-concurrent-mark-start] 306878.260: [Full GC 306878.260: [CMS306879.098: [CMS-concurrent-mark: 1.547/1.611 secs] [Times: user=3.30 sys=0.05, real=1.61 secs] (concurrent mode failure): 1151851K->1141799K(1302528K), 7.1730263 secs] 1246168K->1141799K(1420544K), [CMS Perm : 262139K->261794K(262144K)], 7.1732718 secs] [Times: user=6.22 sys=0.02, real=7.17 secs] 306885.597: [GC 306885.597: [ParNew Desired survivor size 6684672 bytes, new threshold 3 (max 3) - age 1: 3236656 bytes, 3236656 total : 104960K->3872K(118016K), 0.0202786 secs] 1246759K->1145672K(1420544K), 0.0204907 secs] [Times: user=0.11 sys=0.00, real=0.03 secs] 306885.619: [GC [1 CMS-initial-mark: 1141799K(1302528K)] 1145887K(1420544K), 0.0083632 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 306885.628: [CMS-concurrent-mark-start] 306886.611: [GC 306886.611: [ParNew Desired survivor size 6684672 bytes, new threshold 1 (max 3) - age 1: 9906048 bytes, 9906048 total - age 2: 3037688 bytes, 12943736 total : 108832K->13056K(118016K), 0.0230458 secs] 1250632K->1158355K(1420544K), 0.0233164 secs] [Times: user=0.11 sys=0.00, real=0.03 secs] 306887.274: [CMS-concurrent-mark: 1.536/1.646 secs] [Times: user=3.56 sys=0.09, real=1.66 secs] 306887.274: [CMS-concurrent-preclean-start] 306887.287: [CMS-concurrent-preclean: 0.012/0.013 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 306887.287: [CMS-concurrent-abortable-preclean-start] 306889.068: [GC 306889.068: [ParNew306889.071: [CMS-concurrent-abortable-preclean: 0.659/1.784 secs] [Times: user=1.59 sys=1.00, real=1.80 secs] 这时候系统出现比较卡的情况。

[coolspringlsq]

顶！顶！顶！顶！顶！

[MQCloud]

1131999K(1302528K)表示old区使用达到了87%才开始进行CMS，是由于jvm动态调整的缘故。 建议设置如下参数进行控制cms开始时间： -XX:CMSInitiatingOccupancyFraction=75 -XX:+UseCMSInitiatingOccupancyOnly 另外gc日志有concurrent mode failure，可以调小CMSInitiatingOccupancyFraction或新生代。 可以参考我的文章 http://blog.csdn.net/a417930422/article/details/16948933 http://blog.csdn.net/a417930422/article/details/16949005