欢迎您访问程序员文章站本站旨在为大家提供分享程序员计算机编程知识!
您现在的位置是: 首页

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。

如何确定新老年代的内存大小,看起来很复杂,有知道的烦请分享一下。

相关标签: gc