Mensajes de registro de recolección de basura de Java

He configurado java para volcar la información de recolección de basura en los registros ( GC detallado ). No estoy seguro de lo que significan las entradas de recolección de basura en los registros. Una muestra de estas entradas se publica a continuación. He buscado en Google y no he encontrado explicaciones sólidas.

Tengo algunas conjeturas razonables, pero estoy buscando respuestas que brinden definiciones estrictas de lo que significan los números en las entradas, respaldados por fonts creíbles. Un +1 automático para todas las respuestas que citan la documentación del sol. Mis preguntas son:

  1. ¿A qué se refiere PSYoungGen? Supongo que tiene algo que ver con la generación anterior (¿más joven?), Pero ¿qué es exactamente?
  2. ¿Cuál es la diferencia entre la segunda tripleta de números y la primera?
  3. ¿Por qué se especifica un nombre (PSYoungGen) para el primer triplete de números pero no el segundo?
  4. ¿Qué significa cada número (tamaño de memoria) en el triplete? Por ejemplo, en 109884K-> 14201K (139904K), está la memoria antes del GC 109884k y luego se reduce a 14201K. ¿Cómo es el tercer número relevante? ¿Por qué necesitaríamos un segundo conjunto de números?

8109.128: [GC [PSYoungGen: 109884K-> 14201K (139904K)] 691015K-> 595332K (1119040K), 0.0454530 segs]

8112.111: [GC [PSYoungGen: 126649K-> 15528K (142336K)] 707780K-> 605892K (1121472K), 0.0934560 segundos]

8112.802: [GC [PSYoungGen: 130344K-> 3732K (118592K)] 720708K-> 607895K (1097728K), 0.0682690 segundos]

La mayor parte se explica en la Guía de sintonización de GC (que harías bien en leer de todos modos).

La opción de línea de comando -verbose:gc hace que se imprima información sobre la colección de montón y basura en cada colección. Por ejemplo, aquí se muestra desde una aplicación de servidor grande:

 [GC 325407K->83000K(776768K), 0.2300771 secs] [GC 325816K->83372K(776768K), 0.2454258 secs] [Full GC 267628K->83769K(776768K), 1.8479984 secs] 

Aquí vemos dos colecciones menores seguidas de una colección principal. Los números anteriores y posteriores a la flecha (p. Ej., 325407K->83000K de la primera línea) indican el tamaño combinado de los objetos vivos antes y después de la recolección de basura, respectivamente. Después de colecciones menores, el tamaño incluye algunos objetos que son basura (que ya no están vivos) pero que no pueden recuperarse. Estos objetos están contenidos en la generación titular, o se hace referencia a partir de las generaciones permanentes o permanentes.

El siguiente número entre paréntesis (por ejemplo, (776768K) nuevamente desde la primera línea) es el tamaño comprometido del montón: la cantidad de espacio utilizable para objetos Java sin solicitar más memoria del sistema operativo. Tenga en cuenta que este número no incluye uno de los espacios de supervivientes, ya que solo uno puede utilizarse en cualquier momento dado y tampoco incluye la generación permanente, que contiene los metadatos utilizados por la máquina virtual.

El último elemento de la línea (por ejemplo, 0.2300771 secs ) indica el tiempo necesario para realizar la recolección; en este caso, aproximadamente un cuarto de segundo.

El formato para la colección principal en la tercera línea es similar.

El formato de la salida producida por -verbose:gc está sujeto a cambios en versiones futuras.

No estoy seguro de por qué hay un PSYoungGen en el tuyo; ¿Cambiaste el recolector de basura?

  1. PSYoungGen se refiere al recolector de basura en uso para la colección menor. PS significa Parallel Scavenge.
  2. El primer conjunto de números son los tamaños antes / después de la generación joven y el segundo conjunto es para todo el montón. (El diagnóstico de un problema de recolección de basura detalla el formato)
  3. El nombre indica la generación y el recostackdor en cuestión, el segundo conjunto es para todo el montón.

Un ejemplo de GC completo asociado también muestra los colectores utilizados para las generaciones antiguas y permanentes:

 3.757: [Full GC [PSYoungGen: 2672K->0K(35584K)] [ParOldGen: 3225K->5735K(43712K)] 5898K->5735K(79296K) [PSPermGen: 13533K->13516K(27584K)], 0.0860402 secs] 

Finalmente, separando una línea de tu salida de registro de ejemplo:

 8109.128: [GC [PSYoungGen: 109884K->14201K(139904K)] 691015K->595332K(1119040K), 0.0454530 secs] 
  • 107Mb usado antes de GC, 14Mb usado después de GC, máximo tamaño de generación joven 137Mb
  • Heap de 675Mb utilizado antes de GC, heap de 581Mb utilizado después de GC, tamaño de heap máximo de 1 Gb
  • GC menor ocurrió 8109.128 segundos desde el inicio de la JVM y tomó 0.04 segundos

Solo quería mencionar que uno puede obtener el registro detallado de GC con el

 -XX:+PrintGCDetails 

parámetro. Luego verá la salida PSYoungGen o PSPermGen como en la respuesta.

También -Xloggc:gc.log parece generar el mismo resultado como -verbose:gc pero puede especificar un archivo de salida en el primero.

Ejemplo de uso:

 java -Xloggc:./memory.log -XX:+PrintGCDetails Memory 

Para visualizar mejor los datos, puede probar gcviewer (se puede encontrar una versión más reciente en github ).

¡Tenga cuidado de escribir los parámetros correctamente, olvidé el “+” y mi JBoss no se iniciará, sin ningún mensaje de error!