JVM CMS recolección de basura Cuestiones

Question

que estoy viendo los síntomas siguientes en el archivo de registro de GC de una aplicación con el colector de marca y barrido concurrente:

4031.248: [CMS-concurrent-preclean-start] 
4031.250: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
4031.250: [CMS-concurrent-abortable-preclean-start] 
CMS: abort preclean due to time 4036.346: [CMS-concurrent-abortable-preclean: 0.159/5.096 secs] [Times: user=0.00 sys=0.01, real=5.09 secs] 
4036.346: [GC[YG occupancy: 55964 K (118016 K)]4036.347: [Rescan (parallel) , 0.0641200 secs]4036.411: [weak refs processing, 0.0001300 secs]4036.411: [class unloading, 0.0041590 secs]4036.415: [scrub symbol & string tables, 0.0053220 secs] [1 CMS-remark: 16015K(393216K)] 71979K(511232K), 0.0746640 secs] [Times: user=0.08 sys=0.00, real=0.08 secs] 

El proceso de limpieza previa sigue abortando continuamente. Intenté ajustar CMSMaxAbortablePrecleanTime a 15 segundos, desde el valor predeterminado de 5, pero eso no ha ayudado. Las opciones de JVM actuales son los siguientes ...

Djava.awt.headless=true 
-Xms512m 
-Xmx512m 
-Xmn128m 
-XX:MaxPermSize=128m 
-XX:+HeapDumpOnOutOfMemoryError 
-XX:+UseParNewGC 
-XX:+UseConcMarkSweepGC 
-XX:BiasedLockingStartupDelay=0 
-XX:+DoEscapeAnalysis 
-XX:+UseBiasedLocking 
-XX:+EliminateLocks 
-XX:+CMSParallelRemarkEnabled 
-verbose:gc 
-XX:+PrintGCTimeStamps 
-XX:+PrintGCDetails 
-XX:+PrintHeapAtGC 
-Xloggc:gc.log 
-XX:+CMSClassUnloadingEnabled 
-XX:+CMSPermGenPrecleaningEnabled 
-XX:CMSInitiatingOccupancyFraction=50 
-XX:ReservedCodeCacheSize=64m 
-Dnetworkaddress.cache.ttl=30 
-Xss128k 

Parece que el concurrente abortable-limpieza previa nunca tiene la oportunidad de correr. Leí https://blogs.oracle.com/jonthecollector/entry/did_you_know que sugería habilitar CMSScavengeBeforeRemark, pero los efectos secundarios de la pausa no parecían ideales. ¿Alguien podría ofrecer alguna sugerencia?

También me preguntaba si alguien tenía una buena referencia para los registros de Grokking CMS GC, en particular, esta línea:

[1 CMS-remark: 16015K(393216K)] 71979K(511232K), 0.0746640 secs] 

No está claro en qué regiones de memoria esos números se hace referencia. Editar encontrado un enlace a esta http://www.sun.com/bigadmin/content/submitted/cms_gc_logs.jsp

Answer 1

[Tiempos: user = 0.00 sys = 0.01 = 5.09 reales, seg]

yo intentaría investigar por qué CMS-concurrent-abortable-preclean-start no recibe ni el usuario ni sys tiempo de CPU en 5 segundos.

Mi sugerencia es a partir de un Banderas de inicio 'limpias' JVM CMS como

-Djava.awt.headless=true 
-Xms512m 
-Xmx512m 
-Xmn128m 
-Xss128k 
-XX:MaxPermSize=128m 
-XX:+UseConcMarkSweepGC 
-XX:+HeapDumpOnOutOfMemoryError 
-Xloggc:gc.log 
-XX:+PrintGCTimeStamps 
-XX:+PrintGCDetails 
-XX:+PrintHeapAtGC 

a continuación, comprobar si el problema se reproduce y seguir ajustando un parámetro a la vez.

Answer 2

Como alguien ya ha mencionado, el primer paso sería aumentar CMSInitiatingOccupancyFraction.

Como segundo paso, usaría la bandera -XX:-PrintTenuringDistribution y me aseguraré de que no haya una promoción prematura de la generación joven a la anterior. Esto llevaría a referencias antiguas que podrían llevar a una fase preclean abortable más larga. Si hay una promoción tan prematura, intente ajustar la relación entre el eden y los espacios de conducta.

Answer 3

Hay una buena explicación here sobre este fenómeno:

Cita:

Por eso, cuando la carga del sistema es la luz (lo que significa que no habrá gc menor), limpieza previa será siempre time out y full gc siempre fallarán . la CPU es un desperdicio

No fallará. Será menos paralelo (es decir, menos eficiente, y tendrá un tiempo de pausa mayor, por un trabajo menor).

Así que en general: este parece ser el funcionamiento normal - el hilo simplemente espera a que un GC menor que suceda durante 5 segundos, pero no hay gran problema cuando esto no sucede: la JVM elige una diferente (menos eficiente) estrategia para continuar con el GC.