gc参数设置错误导致一直full gc
程序员文章站
2022-05-06 16:51:12
...
gc param
JAVA_OPTS="${JAVA_OPTS} -Xms1g -Xmx1g -XX:NewSize=512m -XX:MaxNewSize=1g -Xss512k -XX:SurvivorRatio=6"
JAVA_OPTS="${JAVA_OPTS} -XX:PermSize=128m -XX:MaxPermSize=256m"
JAVA_OPTS="${JAVA_OPTS} -XX:+UseConcMarkSweepGC -XX:+CMSClassUnloadingEnabled -XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=80"
JAVA_OPTS="${JAVA_OPTS} -XX:+DisableExplicitGC"
JAVA_OPTS="${JAVA_OPTS} -XX:+HeapDumpOnOutOfMemoryError"
JAVA_OPTS="${JAVA_OPTS} -verbose:gc -Xloggc:$BASE_DIR/logs/gc.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps"
JAVA_OPTS="${JAVA_OPTS} -XX:+DoEscapeAnalysis"
现象
启动一段时间后full gc 非常多,并且一直full gc,cpu占用较高
jstat -gcutil 6740 1s
S0 S1 E O P YGC YGCT FGC FGCT GCT
0.00 0.00 36.72 99.79 44.48 149 3.693 7155 2914.767 2918.460
0.00 0.00 36.74 99.79 44.48 149 3.693 7157 2915.111 2918.804
0.00 0.00 37.15 99.79 44.48 149 3.693 7157 2915.474 2919.167
0.00 0.00 37.17 99.79 44.48 149 3.693 7157 2915.474 2919.167
0.00 0.00 37.17 99.79 44.48 149 3.693 7159 2915.794 2919.487
0.00 0.00 37.20 99.79 44.48 149 3.693 7159 2916.166 2919.859
0.00 0.00 37.20 99.79 44.48 149 3.693 7159 2916.166 2919.859
老年代利用率99.79%
Full gc 非常多:7159
jmap -heap 6740
Attaching to process ID 6740, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 24.80-b11
using parallel threads in the new generation.
using thread-local object allocation.
Concurrent Mark-Sweep GC
Heap Configuration:
MinHeapFreeRatio = 40
MaxHeapFreeRatio = 70
MaxHeapSize = 1073741824 (1024.0MB)
NewSize = 536870912 (512.0MB)
MaxNewSize = 1073741824 (1024.0MB)
OldSize = 5439488 (5.1875MB)
NewRatio = 2
SurvivorRatio = 6
PermSize = 134217728 (128.0MB)
MaxPermSize = 268435456 (256.0MB)
G1HeapRegionSize = 0 (0.0MB)
Heap Usage:
New Generation (Eden + 1 Survivor Space):
capacity = 939524096 (896.0MB)
used = 324895744 (309.8447265625MB)
free = 614628352 (586.1552734375MB)
34.580884660993306% used
Eden Space:
capacity = 805371904 (768.0625MB)
used = 324895744 (309.8447265625MB)
free = 480476160 (458.2177734375MB)
40.34108247212955% used
From Space:
capacity = 134152192 (127.9375MB)
used = 0 (0.0MB)
free = 134152192 (127.9375MB)
0.0% used
To Space:
capacity = 134152192 (127.9375MB)
used = 0 (0.0MB)
free = 134152192 (127.9375MB)
0.0% used
concurrent mark-sweep generation:
capacity = 65536 (0.0625MB)
used = 65400 (0.06237030029296875MB)
free = 136 (1.2969970703125E-4MB)
99.79248046875% used
Perm Generation:
capacity = 134217728 (128.0MB)
used = 59700376 (56.934715270996094MB)
free = 74517352 (71.0652847290039MB)
44.4802463054657% used
21022 interned Strings occupying 2161776 bytes.
老年代配置太小:5.1875M
gc.log
CommandLine flags: -XX:+CMSClassUnloadingEnabled -XX:CMSInitiatingOccupancyFraction=80 -XX:+DisableExplicitGC -XX:+DoEscapeAnalysis -XX:+HeapDumpOnOutOfMemoryError -XX:InitialHeapSize=1073741824 -XX:MaxHeapSize=1073741824 -XX:MaxNewSize=1073741824 -XX:MaxPermSize=268435456 -XX:NewSize=536870912 -XX:OldPLABSize=16 -XX:PermSize=134217728 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:SurvivorRatio=6 -XX:ThreadStackSize=512 -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:+UseParNewGC
2017-05-02T16:52:06.943-0800: 13.247: [GC2017-05-02T16:52:06.943-0800: 13.247: [ParNew: 786496K->31371K(917504K), 0.0725850 secs] 786496K->31371K(917568K), 0.0727990 secs] [Times: user=0.13 sys=0.02, real=0.07 secs]
2017-05-02T16:52:31.607-0800: 37.910: [GC2017-05-02T16:52:31.609-0800: 37.912: [ParNew: 817867K->46918K(917504K), 0.2479520 secs] 817867K->46918K(917568K), 0.2501410 secs] [Times: user=0.23 sys=0.15, real=0.25 secs]
2017-05-02T16:56:01.853-0800: 248.156: [GC2017-05-02T16:56:01.855-0800: 248.158: [ParNew: 833414K->41409K(917504K), 0.0957810 secs] 833414K->41409K(917568K), 0.0979290 secs] [Times: user=0.17 sys=0.12, real=0.10 secs]
2017-05-02T16:57:14.966-0800: 321.270: [GC2017-05-02T16:57:14.968-0800: 321.271: [ParNew: 827905K->40734K(917504K), 0.0534460 secs] 827905K->40734K(917568K), 0.0554990 secs] [Times: user=0.16 sys=0.03, real=0.06 secs]
2017-05-02T16:58:28.893-0800: 395.197: [GC2017-05-02T16:58:28.895-0800: 395.198: [ParNew: 827230K->42165K(917504K), 0.0903920 secs] 827230K->42165K(917568K), 0.0916100 secs] [Times: user=0.17 sys=0.01, real=0.09 secs]
2017-05-02T16:59:44.275-0800: 470.578: [GC2017-05-02T16:59:44.277-0800: 470.580: [ParNew: 828661K->42810K(917504K), 0.0520530 secs] 828661K->42810K(917568K), 0.0541480 secs] [Times: user=0.15 sys=0.01, real=0.05 secs]
2017-05-02T17:01:02.837-0800: 549.140: [GC2017-05-02T17:01:02.839-0800: 549.142: [ParNew: 829306K->42849K(917504K), 0.1528770 secs] 829306K->42849K(917568K), 0.1548970 secs] [Times: user=0.19 sys=0.19, real=0.16 secs]
2017-05-02T17:02:21.761-0800: 628.065: [GC2017-05-02T17:02:21.763-0800: 628.067: [ParNew: 829345K->42779K(917504K), 0.0484280 secs] 829345K->42779K(917568K), 0.0504720 secs] [Times: user=0.16 sys=0.02, real=0.05 secs]
2017-05-02T17:03:41.109-0800: 707.413: [GC2017-05-02T17:03:41.111-0800: 707.415: [ParNew: 829275K->42570K(917504K), 0.0451940 secs] 829275K->42570K(917568K), 0.0472230 secs] [Times: user=0.16 sys=0.00, real=0.05 secs]
2017-05-02T17:04:59.543-0800: 785.846: [GC2017-05-02T17:04:59.545-0800: 785.848: [ParNew: 829066K->35805K(917504K), 0.0540570 secs] 829066K->35805K(917568K), 0.0560790 secs] [Times: user=0.17 sys=0.01, real=0.05 secs]
2017-05-02T17:06:19.281-0800: 865.585: [GC2017-05-02T17:06:19.283-0800: 865.587: [ParNew: 822301K->43009K(917504K), 0.0664980 secs] 822301K->43009K(917568K), 0.0687660 secs] [Times: user=0.16 sys=0.02, real=0.07 secs]
2017-05-02T17:07:40.577-0800: 946.881: [GC2017-05-02T17:07:40.579-0800: 946.883: [ParNew: 829505K->35695K(917504K), 0.0500640 secs] 829505K->35695K(917568K), 0.0522790 secs] [Times: user=0.16 sys=0.01, real=0.06 secs]
2017-05-02T17:09:01.660-0800: 1027.964: [GC2017-05-02T17:09:01.662-0800: 1027.965: [ParNew: 822191K->35550K(917504K), 0.0462440 secs] 822191K->35550K(917568K), 0.0482520 secs] [Times: user=0.15 sys=0.01, real=0.04 secs]
2017-05-02T17:10:23.692-0800: 1109.995: [GC2017-05-02T17:10:23.694-0800: 1109.997: [ParNew: 822046K->35915K(917504K), 0.0474050 secs] 822046K->35915K(917568K), 0.0496640 secs] [Times: user=0.15 sys=0.00, real=0.05 secs]
2017-05-02T17:11:45.330-0800: 1191.634: [GC2017-05-02T17:11:45.332-0800: 1191.636: [ParNew: 822411K->39798K(917504K), 0.0438740 secs] 822411K->39798K(917568K), 0.0460200 secs] [Times: user=0.15 sys=0.00, real=0.04 secs]
2017-05-02T17:20:13.443-0800: 1699.747: [GC2017-05-02T17:20:13.444-0800: 1699.747: [ParNew (promotion failed): 826294K->819078K(917504K), 2.5235450 secs]2017-05-02T17:20:15.967-0800: 1702.271: [CMS: 50K->63K(64K), 0.4754080 secs] 826294K->25600K(917568K), [CMS Perm : 58218K->57910K(131072K)], 3.0024250 secs] [Times: user=1.93 sys=1.58, real=3.00 secs]
2017-05-02T17:20:16.452-0800: 1702.755: [GC [1 CMS-initial-mark: 63K(64K)] 25845K(917568K), 0.0516520 secs] [Times: user=0.04 sys=0.00, real=0.05 secs]
2017-05-02T17:20:16.504-0800: 1702.808: [CMS-concurrent-mark-start]
2017-05-02T17:20:16.638-0800: 1702.942: [CMS-concurrent-mark: 0.131/0.134 secs] [Times: user=0.07 sys=0.01, real=0.13 secs]
2017-05-02T17:20:16.639-0800: 1702.942: [CMS-concurrent-preclean-start]
2017-05-02T17:20:16.683-0800: 1702.986: [CMS-concurrent-preclean: 0.044/0.044 secs] [Times: user=0.03 sys=0.00, real=0.05 secs]
2017-05-02T17:20:16.683-0800: 1702.986: [CMS-concurrent-abortable-preclean-start]
2017-05-02T17:20:16.683-0800: 1702.986: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2017-05-02T17:20:16.683-0800: 1702.987: [GC[YG occupancy: 33450 K (917504 K)]2017-05-02T17:20:16.683-0800: 1702.987: [Rescan (parallel) , 0.0393800 secs]2017-05-02T17:20:16.723-0800: 1703.026: [weak refs processing, 0.0002250 secs]2017-05-02T17:20:16.723-0800: 1703.026: [class unloading, 0.0066750 secs]2017-05-02T17:20:16.730-0800: 1703.033: [scrub symbol table, 0.0173430 secs]2017-05-02T17:20:16.747-0800: 1703.050: [scrub string table, 0.0008670 secs] [1 CMS-remark: 63K(64K)] 33514K(917568K), 0.0677130 secs] [Times: user=0.12 sys=0.01, real=0.07 secs]
2017-05-02T17:20:16.751-0800: 1703.055: [CMS-concurrent-sweep-start]
2017-05-02T17:20:16.763-0800: 1703.067: [CMS-concurrent-sweep: 0.012/0.012 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
2017-05-02T17:20:16.764-0800: 1703.067: [CMS-concurrent-reset-start]
2017-05-02T17:20:16.764-0800: 1703.067: [CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2017-05-02T17:20:18.766-0800: 1705.069: [GC [1 CMS-initial-mark: 63K(64K)] 44182K(917568K), 0.0303270 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
2017-05-02T17:20:18.797-0800: 1705.100: [CMS-concurrent-mark-start]
2017-05-02T17:20:18.830-0800: 1705.134: [CMS-concurrent-mark: 0.034/0.034 secs] [Times: user=0.03 sys=0.00, real=0.04 secs]
2017-05-02T17:20:18.831-0800: 1705.134: [CMS-concurrent-preclean-start]
2017-05-02T17:20:18.831-0800: 1705.134: [CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2017-05-02T17:20:18.831-0800: 1705.134: [CMS-concurrent-abortable-preclean-start]
2017-05-02T17:20:18.831-0800: 1705.134: [CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2017-05-02T17:20:18.831-0800: 1705.135: [GC[YG occupancy: 44172 K (917504 K)]2017-05-02T17:20:18.831-0800: 1705.135: [Rescan (parallel) , 0.0351060 secs]2017-05-02T17:20:18.866-0800: 1705.170: [weak refs processing, 0.0001470 secs]2017-05-02T17:20:18.867-0800: 1705.170: [class unloading, 0.0044870 secs]2017-05-02T17:20:18.871-0800: 1705.174: [scrub symbol table, 0.0142320 secs]2017-05-02T17:20:18.885-0800: 1705.189: [scrub string table, 0.0007320 secs] [1 CMS-remark: 63K(64K)] 44236K(917568K), 0.0575210 secs] [Times: user=0.15 sys=0.00, real=0.05 secs]
2017-05-02T17:20:18.889-0800: 1705.192: [CMS-concurrent-sweep-start]
2017-05-02T17:20:18.899-0800: 1705.203: [CMS-concurrent-sweep: 0.010/0.010 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
2017-05-02T17:20:18.900-0800: 1705.203: [CMS-concurrent-reset-start]
2017-05-02T17:20:18.900-0800: 1705.203: [CMS-concurrent-reset: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
解决办法
修改gc内存参数,减小新生代大小,加大old区大小
JAVA_OPTS="${JAVA_OPTS} -Xms1g -Xmx1g -XX:NewSize=512m -XX:MaxNewSize=512m -Xss512k -XX:SurvivorRatio=6"
总结
gc参数配置不当,导致old太小,最终导致一直full gc。
如何确定新老年代的内存大小,看起来很复杂,有知道的烦请分享一下。
上一篇: 浅谈网络编程之Socket