Używam serwera Java, który używa CMS dla dzierżawionego kolektora. Działając pod obciążeniem, widzę młode kolekcje o każdej 1s i na stałe (równoczesne) co 5m. To jest dobre.CMS Java jest ignorowany i uzyskuje pełne GC Zamiast tego
Kiedy biegnę z rzeczywistym ruchu około 1/2 pojemności, mam młodych zbiory o każdy 4S i zwyczajnych (! Równoległe, zatrzymać świat!) O każdym 7m. Dlaczego JVM decyduje się na zrobienie pełnych zatrzymań na świecie zamiast korzystania z kolektora CMS?
Z gc.log można zobaczyć „Full GC” prowadzony i przejmując 3s, aby zakończyć. Tutaj nie ma awarii w trybie równoczesnym. Nic wyraźnie nie żąda kolekcji.
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]
Oto flagi 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
Coś ciekawego ... Po około 2800 sekundach (+/- 200s) CMS zaczyna być ponownie używany. Zazwyczaj 1 lub 2 próby zostają przerwane z przerwanym "trybem współbieżnym", a po tym wszystkim udane CMS. Ruch w tym czasie nie ulegał zmianie. 2415,457 - Pełne GC ... młodzi zbiory ... 2684,320 - CMS-początkowy znak (pierwszy znak CMS nigdzie w dzienniku) 2684,436 - Pełne GC (tryb równoległy przerwany) ... młody .. . ... kolejny CMS przerwany ... ... młody ... 3224,451 - CMS-początkowy znak 3234,855 - młody 3230,254 - CMS-uwaga 3231,972 - CMS-reset (zrobione) ... wszystko dobrze ... –
Według [kodu CMS] (http://cr.openjdk.java.net/~jrose/6863023/diff-04-to-05/raw_files/new/src/share/vm/gc_implementation /concurrentMarkSweep/concurrentMarkSweepGeneration.cpp), komunikat "przerwany w trybie współbieżnym" e występuje z powodu (a) 'GCCause :: is_user_requested_gc' lub (b)' GCCause :: is_serviceability_requested_gc'. Oznacza to, że przyczyną jest (a) '_java_lang_system_gc' lub' _jvmti_force_gc', lub (b) '_jvmti_force_gc',' _heap_inspection' lub '_heap_dump'.Wydaje się, że to samo może być źródłem zarówno pełnego GC, jak i przerw, ale żadna z nich nie powinna mieć miejsca. –
Oto pierwsze 8000 sekund [pliku logu GC] (http://www.backgroundexposure.com/gc.log.txt) z jednego serwera, jeśli jesteś zainteresowany. –