java - Cuestiones de JVM CMS recolección de basura

garbage-collection concurrent-mark-sweep

Question

Estoy viendo los siguientes síntomas en el archivo de registro de GC de una aplicación con el recopilador de barrido simultáneo:

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 preclean continúa 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 las 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 preclean concurrente-abortable nunca tiene la oportunidad de ejecutarse. Leí https://blogs.oracle.com/jonthecollector/entry/did_you_know que tenía una sugerencia de 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 compilar los registros del CMS GC, en particular esta línea:

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

No está claro a qué regiones de memoria se refieren esos números. Editar Encontrado un enlace a este http://www.sun.com/bigadmin/content/submitted/cms_gc_logs.jsp

Answer 1

[Veces: usuario = 0.00 sys = 0.01, real = 5.09 segs]

Intentaría investigar por qué CMS-concurrent-abortable-preclean-start no obtiene el tiempo de CPU del usuario ni del sistema en 5 segundos.

Mi sugerencia es comenzar desde una ''limpia'' de indicadores de inicio 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

luego verifica si el problema se reproduce y sigue 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

Aquí hay una buena explicación sobre este fenómeno:

Citar:

Entonces, cuando la carga del sistema es liviana (lo que significa que no habrá gc menor), el prelavado siempre expirará y el gc completo siempre fallará. la CPU es un desperdicio

No fallará Será menos paralelo (es decir, menos eficiente, y tendría un tiempo de pausa más largo, para un trabajo menor).

Así que, en general, esto parece ser una operación normal: el hilo solo espera que ocurra un GC menor durante 5 segundos, pero no hay un gran problema cuando esto no sucede: la JVM elige una estrategia diferente (menos eficiente) para continuar con el GC.