2011-04-19 4 views
9

보유 된 콜렉터에 대해 CMS를 사용하는 Java 서버를 실행 중입니다. 부하 테스트를 받으면서 매 5 초마다 1 초마다 젊은 콜렉션이 보급되고 (동시 발생) 보입니다. 이것은 좋다.Java CMS가 무시되고 대신 전체 GC 가져 오기

약 2 분의 1 용량의 실제 트래픽으로 실행하면 매 7 초마다 약 4 초마다 어린 콜렉션이 생기고 (평행, 세계를 멈 춥니 다!). 왜 JVM은 CMS 콜렉터를 사용하는 대신 전 세계적인 콜렉션을 수행하기로 결정합니까?

gc.log에서 "Full GC"가 실행 중이고 3 초 이상 완료됨을 볼 수 있습니다. 여기에는 동시 모드 오류가 없습니다. 명시 적으로 콜렉션을 요청하는 것은 없습니다.

1350.596: [GC 1350.596: [ParNew 
Desired survivor size 119275520 bytes, new threshold 3 (max 3) 
- age 1: 34779376 bytes, 34779376 total 
- age 2: 17072392 bytes, 51851768 total 
- age 3: 24120992 bytes, 75972760 total 
: 1765625K->116452K(1864192K), 0.1560370 secs] 3887120K->2277489K(5009920K), 0.1561920 secs] [Times: user=0.40 sys=0.04, real=0.16 secs] 
1355.106: [GC 1355.107: [ParNew 
Desired survivor size 119275520 bytes, new threshold 3 (max 3) 
- age 1: 44862680 bytes, 44862680 total 
- age 2: 20363280 bytes, 65225960 total 
- age 3: 16908840 bytes, 82134800 total 
: 1747684K->123571K(1864192K), 0.1068880 secs] 3908721K->2307790K(5009920K), 0.1070130 secs] [Times: user=0.29 sys=0.04, real=0.11 secs] 
1356.106: [Full GC 1356.106: [CMS: 2184218K->1268401K(3145728K), 3.0678070 secs] 2682861K->1268401K(5009920K), [CMS Perm : 145090K->145060K(262144K)], 3.0679600 secs] [Times: user=3.05 sys=0.02, real=3.07 secs] 
1361.375: [GC 1361.375: [ParNew 
Desired survivor size 119275520 bytes, new threshold 3 (max 3) 
- age 1: 33708472 bytes, 33708472 total 
: 1631232K->84465K(1864192K), 0.0189890 secs] 2899633K->1352866K(5009920K), 0.0191530 secs] [Times: user=0.19 sys=0.00, real=0.02 secs] 
1365.587: [GC 1365.587: [ParNew 
Desired survivor size 119275520 bytes, new threshold 3 (max 3) 
- age 1: 33475320 bytes, 33475320 total 
- age 2: 22698536 bytes, 56173856 total 
: 1715697K->67421K(1864192K), 0.0229540 secs] 2984098K->1335822K(5009920K), 0.0231240 secs] [Times: user=0.25 sys=0.00, real=0.03 secs] 

다음은 JVM 플래그이다 : 당신의 생존 공간이 충분하지 않은 경우

-server -Xss256K -Xms5120M -Xmx5120M -XX:NewSize=2048M -XX:MaxNewSize=2048M 
-XX:SurvivorRatio=7 -XX:+UseConcMarkSweepGC -XX:+UseParNewGC 
-XX:+CMSParallelRemarkEnabled -XX:CMSInitiatingOccupancyFraction=80 
-XX:+UseCMSInitiatingOccupancyOnly -XX:CMSFullGCsBeforeCompaction=1 
-XX:SoftRefLRUPolicyMSPerMB=73 -verbose:gc -XX:+PrintGCDetails 
-XX:+PrintGCTimeStamps -XX:+PrintTenuringDistribution -Xloggc:logs/gc.log 
-XX:MaxPermSize=256m -XX:PermSize=256m -XX:MaxTenuringThreshold=3 
+0

주목할만한 점 ... 약 2800 초 (+/- 200 초) 후에 CMS가 다시 사용되기 시작합니다. 일반적으로 1 또는 2 번의 시도가 "동시 모드 중단됨"으로 중단되고 그 다음에는 모두 성공적인 CMS입니다. 이 시간 동안 트래픽은 변경되지 않았습니다. 2415.457 - 전체 GC ... 젊은 컬렉션 ... 2684.320 - CMS-초기 마크 (첫번째 CMS 마크 어디서나 로그) 2684.436 - 젊은 전체 GC (동시 모드 중단) ... .. . ... 다른 CMS가 ... 중단 ... 젊은 ... 3224.451 - CMS-초기 마크 3234.855 - 젊은 3230.254 - CMS-말 3231.972 - (완료) CMS 리셋 ... 모두 좋은 ... –

+0

에 따르면 [CMS 코드] (http://cr.openjdk.java.net/~jrose/6863023/diff-04-to-05/raw_files/new/src/share/vm/gc_implementation /concurrentMarkSweep/concurrentMarkSweepGeneration.cpp), "동시 모드 중단"메시지 e는 (a)'GCCause :: is_user_requested_gc' 또는 (b)'GCCause :: is_serviceability_requested_gc' 때문에 발생합니다. 즉, 원인은 (a)'_java_lang_system_gc' 또는'_jvmti_force_gc' 또는 (b)'_jvmti_force_gc','_heap_inspection' 또는'_heap_dump'입니다.Full GC와 중단의 원인이 같은 것으로 보일 수 있지만,이 중 아무 것도 일어나지 않아야합니다. –

+0

관심이있는 경우 한 서버의 [GC 로그 파일] (http://www.backgroundexposure.com/gc.log.txt)의 처음 8000 초입니다. –

답변

2

, 그것은 전체 GC를 트리거 할 수 있습니다. (생존자 비율에 대해 불평하는 것으로 보입니다.)

생존자 비율을 줄이거 나 더 나은 해결책은 에덴 공간에서 생존하는 개체가 적어 지도록 NewSize를 늘리는 것입니다. 나는 6GB의 에덴 공간을 가지고있다.)

+0

생존자 공간은 일반적으로 약 4-6 사이클을 유지하지만, 필요없는 memcpy의 양을 줄이기 위해 각 사이클의 양을 줄이지 않으므로 3 사이클로 제한합니다. –

+0

BTW, 나의 에덴 크기는 전체 부하에서 1 초마다 평균 50ms의 평균 세계 시간으로 콜렉션을 발생시키지 않도록 선택되었습니다. 요청은 일반적으로 50ms 미만으로 응답되며 99.9 %는 250ms 미만입니다. –

+0

BTW : 최소한의 물체를 만드는 에덴 공간은 하루 종일 충분합니다. 매일 밤 새벽 5시에 완전한 GC가 하나 있는데, 사소한 GC는 전혀 없습니다. ;) 응답 시간은 0.1ms 미만으로 시간 비율이 높습니다. –

1

나는 완전한 GC를 피하기 위해 커다란 힙을 튜닝 할 때 비슷한 현상을 보았다. 나는 에덴의 크기를 줄이고 싶을지도 모른다고 생각합니다. 이것은 종신 세대에 비해 상당히 큽니다.

내가 믿는 것은 당신의 eden이 1/2 속도의 트래픽으로 한 번에 "오래"을 얻는 것이 최대 속도 (생존하지 않는 곳)보다 많다는 것입니다. 즉, 더 많은 사람들이 일제히 재임을해야합니다. 그리고 그 시간에 맞지 않으면 방안을 마련하기 위해 전체 GC를 실행할 수 있습니다. 여기에 참고로

우리가 24기가바이트 힙에 6기가바이트 지금 무엇을 사용 :

-XX:NewRatio=4 -XX:SurvivorRatio=8 -XX:+UseCompressedOops 
-XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+DisableExplicitGC 
-XX:+UseCMSInitiatingOccupancyOnly -XX:+CMSClassUnloadingEnabled 
-XX:+CMSScavengeBeforeRemark -XX:CMSInitiatingOccupancyFraction=68 
-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:logs/gc.log 

그것은 이미 당신과 상당히 유사하다. 모든 비율을 사용하는 것에 대한 좋은 점은 힙 크기를 쉽게 변경할 수 있고 일반적으로 적절하게 비율을 조정할 수 있다는 것입니다. 또 하나의주의 사항은 일반적으로 -XX:+UseCompressedOops은 64 비트 주소 지정을 32 비트로 줄임으로써 메모리를 40 % 적게 사용할 수 있다는 것입니다 (최대 32GB까지만 작동).

+0

Young 개체를 Tenured로 승격시키지 못하여 발생 된 Full GC는 존재하지 않는 "동시 모드 실패"로 로그에 나타납니다. 과거에는 그 중 많은 것을 보았습니다. 점유율 = 80은 세 심하게 조정 한 결과입니다. 내 요청은 거의 항상 <250ms 이내에 응답되므로 대부분의 에덴은 생존자에게 복사되는 데 10 % 미만으로 즉시 폐기됩니다. 이것의 약 1/4 ~ 1/2 정도는 다음주기에 버려지고, 그 이후에 더 많은 사본이 허용 되더라도 (따라서 TenuringThreshold = 3) 많은 양을 줄이지 않습니다. 에덴 공간의 5 % 미만이 종신직을 얻습니다. –

+0

분명히 나는 ​​너무 빨리 말했다. 나의 "occupancy fraction"을 60으로 낮추는 것은 정말로 이것을 멈추게했다. 아마도 JVM이 시작 이후 적어도 하나의 CMS 콜렉션을 시도하지 않는 한 "동시 모드 실패"로 간주되지 않을 것입니다 (왜 그런지는 모르겠지만 이해할 수는 없습니다). JVM 내부의 카운터조차도 로그 메시지 또는 아니오와 같이 카운트하지 않았습니다. ... 15-30MB를 3G의 새로운 Tenured 공간으로 옮기는 것이 왜 70 명을 수용하지만 65 명으로 작업하는 데 문제가 있습니까? 30MB는 3G의 1 %에 불과합니다. –