2016-06-17 4 views
2

Я испытываю редкие длинные GC-паузы с алгоритмом G1GC - 30+ секунд в течение месяца. Как только это произойдет, я перезапустил свой сервис, и эта задержка не повторится в течение следующих 1 месяца.Редкие длинные GC-паузы с G1GC

Я прикрепляю GC журнал.

2016-06-15T02:30:17.407-0400: 1702455.276: Total time for which application threads were stopped: 0.2900480 seconds 
2016-06-15T02:30:25.509-0400: 1702463.378: Total time for which application threads were stopped: 0.0018900 seconds 
2016-06-15T02:30:29.817-0400: 1702467.686: [GC pause (young) 
Desired survivor size 7340032 bytes, new threshold 15 (max 15) 
- age 1: 1903912 bytes, 1903912 total 
- age 2:  641440 bytes, 2545352 total 
- age 3:  455856 bytes, 3001208 total 
- age 4:  563544 bytes, 3564752 total 
- age 5: 1873368 bytes, 5438120 total 
- age 6:  326024 bytes, 5764144 total 
- age 7:  299144 bytes, 6063288 total 
- age 8:  304632 bytes, 6367920 total 
- age 9:  273160 bytes, 6641080 total 
- age 10:  309152 bytes, 6950232 total 
- age 11:  156824 bytes, 7107056 total 
- age 12:  135064 bytes, 7242120 total 
, 0.1199490 secs] 
    [Parallel Time: 118.2 ms, GC Workers: 4] 
     [GC Worker Start (ms): Min: 1702467686.7, Avg: 1702467686.8, Max: 1702467686.9, Diff: 0.2] 
     [Ext Root Scanning (ms): Min: 18.4, Avg: 20.2, Max: 24.6, Diff: 6.2, Sum: 80.7] 
     [Update RS (ms): Min: 75.5, Avg: 79.5, Max: 80.8, Diff: 5.3, Sum: 317.8] 
     [Processed Buffers: Min: 52, Avg: 61.0, Max: 70, Diff: 18, Sum: 244] 
     [Scan RS (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.3] 
     [Object Copy (ms): Min: 17.7, Avg: 18.1, Max: 18.6, Diff: 0.8, Sum: 72.3] 
     [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] 
     [GC Worker Other (ms): Min: 0.1, Avg: 0.1, Max: 0.1, Diff: 0.0, Sum: 0.4] 
     [GC Worker Total (ms): Min: 117.8, Avg: 117.9, Max: 118.0, Diff: 0.2, Sum: 471.6] 
     [GC Worker End (ms): Min: 1702467804.7, Avg: 1702467804.7, Max: 1702467804.7, Diff: 0.0] 
    [Code Root Fixup: 0.0 ms] 
    [Clear CT: 0.2 ms] 
    [Other: 1.6 ms] 
     [Choose CSet: 0.0 ms] 
     [Ref Proc: 0.3 ms] 
     [Ref Enq: 0.0 ms] 
     [Free CSet: 0.4 ms] 
    [Eden: 100.0M(100.0M)->0.0B(100.0M) Survivors: 9216.0K->9216.0K Heap: 2164.6M(2198.0M)->2065.5M(2198.0M)] 
[Times: user=0.48 sys=0.00, real=37.62 secs] 
2016-06-15T02:31:07.438-0400: 1702505.307: Total time for which application threads were stopped: 37.seconds 

2016-06-15T02:31:07.443-0400: 1702505.312: Total time for which application threads were stopped: 0.0034690 seconds 
2016-06-15T02:31:07.446-0400: 1702505.315: Total time for which application threads were stopped: 0.0018140 seconds 
2016-06-15T02:31:07.451-0400: 1702505.320: Total time for which application threads were stopped: 0.0020130 seconds 
2016-06-15T02:31:07.453-0400: 1702505.322: Total time for which application threads were stopped: 0.0015850 seconds 

Я использую ниже G1GC флагов:

-server -d64 -verbose:gc -Xms2g -Xmx4g -XX:+UseG1GC 
-XX:MaxGCPauseMillis=1500 -XX:G1HeapRegionSize=2 
-XX:+PrintFlagsFinal -XX:ParallelGCThreads=4 -XX:ConcGCThreads=2 
-XX:PermSize=64m -XX:MaxPermSize=256m -XX:+DisableExplicitGC 
-XX:+PrintGCDateStamps -XX:+DoEscapeAnalysis -XX:+PrintTenuringDistribution 
-XX:+PrintGCTimeStamps -XX:+PrintGCDetails 
-XX:+PrintGCApplicationStoppedTime -XX:+HeapDumpOnOutOfMemoryError 
-XX:HeapDumpPath=$PP_HOME -XX:+UseCompressedOops -XX:+AggressiveOpts" 

конфигурации машины:

Red Hat Enterprise Linux Server release 5.11 
Dual core CPU 
java version "1.7.0_45" 
Java(TM) SE Runtime Environment (build 1.7.0_45-b18) 
Java HotSpot(TM) 64-Bit Server VM (build 24.45-b08, mixed mode) 

Как мы можем найти причину для длительного GC из вышеупомянутых утверждений?

+0

Я очень сомневаюсь, что вы любезны найти коренные причины из этой информации. Вместо этого вам нужно включить трассировку GC; и изучать его выходные файлы. – GhostCat

+0

Что такое переключатель для включения трассировки? –

+1

похоже, что сам GC не занимает много процессорного времени, и по какой-то причине время стены слишком длинное, вы должны включить ведение протокола safepoint, см. Http://stackoverflow.com/a/33293324/1362755 – the8472

ответ

1

Обновление до последней версии Java 8 - вам должно быть не использовать G1 с Java 7, потому что в то время он не был готов к производству. Коэффициенты очень хорошие, что вы попали в исправленную ошибку. Да, там есть способы получить OpenJDK 8 на коробку RHEL 5. Да, ваше приложение будет значительно увеличиваться в скорости.

Кроме того, это:

-XX: MaxGCPauseMillis = 1500

и это:

-Xms2g -Xmx4g

бы предложить вам Арен» t работает в виде большой кучи, среда с низкой задержкой G1 - это desi для. С JRE, что старый, вам может быть лучше с параметрами по умолчанию (ParallelGC) и , возможно,, настраивая несколько вариантов сокращения времени паузы (пробег может варьироваться). Или CMS, которая была более зрелой, и с настройкой может быть довольно стабильной.

И, если вам нужно, ваше приложение достаточно критично, что 30-секундная пауза GC каждый месяц является проблемой, тогда вы, вероятно, можете позволить себе систему с RHEL 7 и более чем с двумя ядрами.

Смежные вопросы