☰

GC가 크게 일시 중지되고 ParNew(승격 실패)

tag-icon • tag-icon java garbage-collecting
GC가 크게 일시 중지되고 ParNew(승격 실패)

Java 애플리케이션 중 하나가 GC를 수행하는 동안 크게 일시 중지됩니다. "ParNew(승격 실패)" 때문에 시간이 걸리는 것 같습니다.

자바 버전:

$ java -version
java version "1.6.0_21"
Java(TM) SE Runtime Environment (build 1.6.0_21-b06)
Java HotSpot(TM) 64-Bit Server VM (build 17.0-b16, mixed mode)

GC 설정:

JAVA_OPTS="$JAVA_OPTS -XX:+PrintGCApplicationConcurrentTime -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintTenuringDistribution -Dsun.rmi.dgc.client.gcInterval=86400000 -Dsun.rmi.dgc.server.gcInterval=86400000 -verbose:gc -Xloggc:/path/to/gc/gc.log"
JAVA_OPTS="$JAVA_OPTS  -XX:NewSize=5g -XX:MaxNewSize=5g -Xms10g -Xmx10g -XX:PermSize=512m -XX:MaxPermSize=512m -XX:SurvivorRatio=30 -XX:TargetSurvivorRatio=90 -XX:MaxTenuringThreshold=15"
# Parallel setting
JAVA_OPTS="$JAVA_OPTS -XX:+UseParNewGC -XX:ParallelGCThreads=16"
# CMS setting
JAVA_OPTS="$JAVA_OPTS  -XX:+UseConcMarkSweepGC -XX:+CMSParallelRemarkEnabled -XX:+CMSCompactWhenClearAllSoftRefs -XX:CMSInitiatingOccupancyFraction=85 -XX:+CMSScavengeBeforeRemark -XX:+CMSConcurrentMTEnabled -XX:ParallelCMSThreads=2"

다음은 몇 가지 긴 일시 중지에 대한 gc.log 출력입니다.

2015-06-04T10:02:28.988+0000: 129998.706: [GC[YG occupancy: 1904924 K (5079040 K)]2015-06-04T10:02:28.988+0000: 129998.706: [GC 129998.706: [ParNew (promotion
 failed)
Desired survivor size 150994944 bytes, new threshold 10 (max 15)
- age   1:   39557704 bytes,   39557704 total
- age   2:   23752968 bytes,   63310672 total
- age   3:   11024200 bytes,   74334872 total
- age   4:   10529816 bytes,   84864688 total
- age   5:    9602712 bytes,   94467400 total
- age   6:    9621976 bytes,  104089376 total
- age   7:   27355240 bytes,  131444616 total
- age   8:    6326944 bytes,  137771560 total
- age   9:    7153592 bytes,  144925152 total
- age  10:    6944200 bytes,  151869352 total
- age  11:    7226592 bytes,  159095944 total
- age  12:    6674048 bytes,  165769992 total
: 1904924K->1904924K(5079040K), 84.3892780 secs] 6687900K-     >7143259K(10321920K), 84.3894730 secs] [Times: user=241.33 sys=9.83,  real=84.39 secs]
130083.096: [Rescan (parallel) , 1.0518870 secs]130084.148: [weak refs     processing, 0.0056350 secs] [1 CMS-remark: 5238334K(5242880K)]   7143259K(10321920K), 85.
4473940 secs] [Times: user=249.44 sys=10.00, real=85.44 secs]
Total time for which application threads were stopped: 85.4485540 seconds

2015-06-09T01:36:38.354+0000: 531648.072: [GC[YG occupancy: 3444075 K (5079040 K)]2015-06-09T01:36:38.354+0000: 531648.072: [GC 531648.072: [ParNew (promotion
 failed)
Desired survivor size 150994944 bytes, new threshold 6 (max 15)
- age   1:  118719600 bytes,  118719600 total
- age   2:   20791640 bytes,  139511240 total
- age   3:    2411752 bytes,  141922992 total
- age   4:    3146888 bytes,  145069880 total
- age   5:    3595160 bytes,  148665040 total
- age   6:    3950560 bytes,  152615600 total
- age   7:    2455960 bytes,  155071560 total
- age   8:    2780536 bytes,  157852096 total
- age   9:    2346000 bytes,  160198096 total
- age  10:    2952600 bytes,  163150696 total
- age  11:    1078304 bytes,  164229000 total
- age  12:    1857992 bytes,  166086992 total
- age  13:    1093752 bytes,  167180744 total
: 3444075K->3444075K(5079040K), 53.3528910 secs] 7494225K->8679897K(10321920K), 53.3531460 secs] [Times: user=168.75 sys=10.21, real=53.36 secs]
531701.426: [Rescan (parallel) , 1.2041260 secs]531702.630: [weak refs processing, 0.0002920 secs] [1 CMS-remark: 5235821K(5242880K)] 8679897K(10321920K), 54.
5583950 secs] [Times: user=178.02 sys=10.43, real=54.57 secs]
Total time for which application threads were stopped: 54.5615990 seconds
2015-06-09T01:37:32.913+0000: 531702.631: [CMS-concurrent-sweep-start]


2015-06-10T12:58:53.687+0000: 658983.405: [GC 658983.405: [ParNew (promotion failed)
Desired survivor size 150994944 bytes, new threshold 11 (max 15)
- age   1:   62173384 bytes,   62173384 total
- age   2:    4913808 bytes,   67087192 total
- age   3:   10095568 bytes,   77182760 total
- age   4:   12476376 bytes,   89659136 total
- age   5:    8521376 bytes,   98180512 total
- age   6:     985064 bytes,   99165576 total
- age   7:    8824120 bytes,  107989696 total
- age   8:    9991888 bytes,  117981584 total
- age   9:   23527832 bytes,  141509416 total
- age  10:    5438928 bytes,  146948344 total
- age  11:    6171880 bytes,  153120224 total
- age  12:    6983376 bytes,  160103600 total
- age  13:    1196080 bytes,  161299680 total
- age  14:    5357040 bytes,  166656720 total
: 5079040K->5079040K(5079040K), 31.3569910 secs]659014.762: [CMS: 5239285K->5242879K(5242880K), 11.5386160 secs] 9441788K->5341454K(10321920K), [CMS Perm : 42
6919K->426638K(524288K)], 42.8959280 secs] [Times: user=120.92 sys=7.35, real=42.90 secs]
Total time for which application threads were stopped: 42.8996760 seconds
Application time: 0.0001030 seconds
2015-06-10T12:59:36.587+0000: 659026.305: [GC [1 CMS-initial-mark: 5242879K(5242880K)] 5343035K(10321920K), 0.0946190 secs] [Times: user=0.09 sys=0.00, real=0.09 secs]
Total time for which application threads were stopped: 0.0979600 seconds
2015-06-10T12:59:36.682+0000: 659026.400: [CMS-concurrent-mark-start]
Application time: 0.2920200 seconds

GC 설정에 문제가 있는 경우 어떻게 문제를 해결할 수 있나요?

답변1

최신 버전의 Java 1.6으로 업데이트하면 도움이 될 수 있습니다. GC 동작과 관련된 일부 패치입니다.

새 크기가 너무 과도한 것 같습니다. 일반적으로 새로운 세대의 GC에서 살아남은 몇 Mb가 있으며 이는 Old Generation을 위한 것으로 보입니다. -XX:NewSize128m에서 512m 사이 어딘가에 떨어 뜨려 보십시오 . 설정 을 제거해도 문제가 되지 않을 것입니다 -XX:MaxNewSize=5g.

이러한 설정으로 인해 문제가 발생할 가능성이 높습니다 -XX:SurvivorRatio=30 -XX:TargetSurvivorRatio=90 -XX:MaxTenuringThreshold=15". 그냥 설정해 보세요 -XX:SurvivorRatio=32. 이러한 설정으로 인해 GC 루틴은 생존자 비율의 크기를 지속적으로 조정하려고 시도합니다. 생존자 비율은 약 10~15입니다. 생존자 점유율을 모니터링하고 거의 꽉 차도록 조정하세요.

-XX:MaxTenuringThreshold아마도 4 이하의 설정을 원할 것입니다 . 느린 동시 GC 동안 새로운 세대에 더 많은 객체가 있을 것입니다. 초기 표시 중에 새 세대가 최대한 비어 있기를 원합니다. 내 테스트에 따르면 새로운 세대의 모든 개체는 동시 표시 프로세스 중에 라이브로 간주됩니다. 마킹 프로세스에 소요되는 시간은 실제 개체 수에 비례하므로 이는 큰 페널티가 될 수 있습니다. 설정을 낮추면 생존율을 높일 수 있습니다.

설정으로 -XX:+PrintGCApplicationConcurrentTime -XX:+PrintGCApplicationStoppedTime인해 로그가 복잡해지고 유용한 정보가 많이 나오지 않을 수 있습니다. 나는 그것들을 제거할 것이다.

Concurrent GC에 사용되는 스레드 수를 늘릴 수 있습니다. CPU 스레드의 25%를 고려하십시오.

70~75 범위로 낮추는 것을 고려하십시오 -XX:CMSInitiatingOccupancyFraction. 메모리 할당 크기로 인해 85%로도 괜찮을 수 있습니다. 메모리가 너무 조각화되면 메모리가 압축되는 동안 오랫동안 일시 중지됩니다.

-Xms -Xmx5g 또는 6g에 지정된 전체 메모리를 줄이는 것이 좋습니다 . 1~4시간마다 이전 세대 GC를 갖는 것을 목표로 삼을 수도 있습니다. GC 주기 사이에 메모리가 페이지 아웃되면 페이지 인이 될 때까지 기다려야 할 수 있습니다. 이로 인해 GC 시간이 크게 늘어날 수 있습니다. 낮은 초기 점유율을 지원하려면 더 많은 이전 세대가 필요할 수 있습니다.

관련 정보