Java Garbage Collection Mensajes de registro

Question

He configurado java para volcar la información de recolección de basura en los registros (verbose GC). 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 fuentes 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 secs]

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

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

Answer 1

La mayor parte se explica en el GC Tuning Guide (que haría bien en leer de todos modos).

La opción de línea de comandos -verbose:gc hace que la información sobre el montón y recolección de basura se va a imprimir en cada colección. Por ejemplo, aquí se muestra el resultado de 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 por una colección principal. Los números anteriores y posteriores a la flecha (por ejemplo, 325407K->83000K desde 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 en la línea (por ejemplo, 0.2300771 secs) indica el tiempo necesario para realizar la recopilació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 futuras versiones.

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

Answer 2

1. PSYoungGen hace referencia 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 son para todo el montón. (Diagnosing a Garbage Collection problem detalla el formato)
3. El nombre indica la generación y el recopilador en cuestión, el segundo conjunto es para todo el montón.

Un ejemplo de un GC completa asociada también muestra los colectores utilizados para los viejos y permanentes generaciones:

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

Finalmente, rompiendo una línea hacia abajo de la salida de ejemplo de registro:

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

• 107Mb utilizado antes de GC, 14Mb utilizado después de GC, max yo tamaño ung generación 137MB
• 675Mb montón utilizado antes GC, 581Mb montón utilizado después de la CG, 1Gb máximo tamaño de la pila
• GC menor se produjo 8109.128 segundos desde el inicio de la JVM y tomó 0,04 segundo

Answer 3

sólo quería mencionar que uno puede conseguir el registro detallado con la GC

-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 que se pueden tratar gcviewer (una versión más reciente se puede encontrar en github).

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