G1GC Странное поведение

Я решил попробовать G1GC на своей установке Eclipse Mars RC3 для разработчиков JavaEE, но заметил очень странное поведение:

статистика GCViewer

Как видите, он выполнил почти 700 ПОЛНЫХ сборщиков мусора за жизненный цикл приложения и только 30 второстепенных сборщиков мусора. Также я заметил, что второстепенные сборщики мусора выполняются, когда приложение находится под нагрузкой - обычно, когда оно запускается и загружает много материала, в то время как полное сборщик мусора выполняется, когда оно находится в режиме ожидания. (Большую часть этих 11 часов оно простаивало!) Я ожидаю, что когда приложение ничего не делает, в сборщике мусора не будет необходимости, или, по крайней мере, это будет второстепенный сборщик мусора. Я также следил за потреблением памяти eclipse - во время простоя оно никогда не превышало 130-140 МБ, так что это еще одна причина, по которой эти полные сборщики мусора выглядят странно.

Вот моя конфигурация jvm eclipse.ini:

-server
-Xverify:none
-XX:+AggressiveOpts
-XX:+UseG1GC
-XX:MaxGCPauseMillis=100
-XX:+UseStringDeduplication
-XX:+UseCompressedOops
-XX:+UseCompressedClassPointers
-XX:MaxMetaspaceSize=256m
-Xloggc:/home/svetlin/software/eclipse/gc.log
-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-XX:+PrintGCDateStamps 
-XX:+UseGCLogFileRotation
-XX:NumberOfGCLogFiles=5
-XX:GCLogFileSize=20m
-Xms1g
-Xmx1g

Вот журнал GC: http://pastebin.com/sVBe4w1A

Версия Java: 64-разрядная серверная виртуальная машина OpenJDK (25.45-b02) для linux-amd64 JRE (1.8.0_45-internal-b14), собранная 17 мая 2015 г., 19:21:01, by buildd с gcc 4.9.2

Вы хоть представляете, почему G1GC выполняет полный сборщик мусора, когда очевидно, что сборщик мусора вообще не нужен?


java garbage-collection g1gc
person Svetlin Zarev    schedule 14.06.2015    source источник

Ответы (2)


arrow_upward
3
arrow_downward

Вы страдаете от System.gc() звонков, как видно из вашего журнала:

2015-06-14T14:56:23.682+0300: 12790,173: [Full GC (System.gc())  121M->118M(1024M), 0,4524898 secs]
   [Eden: 4096,0K(561,0M)->0,0B(561,0M) Survivors: 0,0B->0,0B Heap: 121,7M(1024,0M)->118,2M(1024,0M)], [Metaspace: 135216K->135216K(1177600K)]
 [Times: user=0,71 sys=0,00, real=0,45 secs]
2015-06-14T14:57:23.682+0300: 12850,174: [Full GC (System.gc())  121M->118M(1024M), 0,4732930 secs]
   [Eden: 3072,0K(561,0M)->0,0B(561,0M) Survivors: 0,0B->0,0B Heap: 121,2M(1024,0M)->118,2M(1024,0M)], [Metaspace: 135216K->135216K(1177600K)]
 [Times: user=0,73 sys=0,00, real=0,47 secs]
2015-06-14T14:58:28.684+0300: 12915,175: [Full GC (System.gc())  169M->118M(1024M), 0,4912699 secs]
   [Eden: 52,0M(561,0M)->0,0B(561,0M) Survivors: 0,0B->0,0B Heap: 169,9M(1024,0M)->118,8M(1024,0M)], [Metaspace: 135601K->135601K(1177600K)]
 [Times: user=0,74 sys=0,00, real=0,49 secs]

Звонки System.gc(), похоже, происходят раз в минуту. Вы запускаете какие-нибудь странные плагины, которые могут вызвать это?

В противном случае периодические вызовы System.gc() часто возникают из-за того, что их вызывает среда выполнения Java RMI. Я думаю, что в старых версиях Java это делалось каждую минуту, но теперь это число увеличилось до одного раза в час. Несмотря на это, попробуйте установить эти свойства, чтобы быть уверенным:

-Dsun.rmi.dgc.server.gcInterval=999999999
-Dsun.rmi.dgc.client.gcInterval=999999999

как параметры JVM.

person K Erlandsson    schedule 14.06.2015
comment
Лол, мне нужно было вручную заглянуть в журналы, а не использовать GCViewer. Интересно, однако, какой компонент вызывает System.gc() и почему. - person Svetlin Zarev; 14.06.2015

arrow_upward
2
arrow_downward

Все ваши полные сборщики мусора вызваны вызовами System.gc(). Ваш журнал GC показывает ровно 698 из них.

Таким образом, ваш дистрибутив Eclipse может содержать подключаемый модуль, который вызывает это количество вызовов System.gc(). Если вы не можете исправить эти вызовы, вы можете рассмотреть возможность использования опции виртуальной машины -XX:+DisableExplicitGC для подавления явных сборщиков мусора.

person Stefan Ferstl    schedule 14.06.2015