Si tuviste la suerte de acudir a la charla de @alotor en el Codemotion 2014, descubrimos muchas maneras de monitorizar la actividad del Garbage Collector y obtener un log de salida que poder analizar para tratar de detectar problemas de rendimiento.
Configurar el Garbage Collector para que nos de esta salida es bastante sencillo. En mi caso el entorno es el siguiente:
Eclipse Kepler + Java 7 + Tomcat 7
He modificado la configuración de arranque del Tomcat para añadirle los siguientes parámetros:
Con estos parámetros la salida que obtenemos es la siguiente salida en nuestra consola:
Text | | copy code | | ? |
1 | [GC [PSYoungGen: 72686K->5110K(72704K)] 86900K->32995K(159744K), 0.0176918 secs] [Times: user=0.03 sys=0.02, real=0.02 secs] |
2 | [GC [PSYoungGen: 72694K->17904K(148992K)] 100579K->47708K(236032K), 0.0199841 secs] [Times: user=0.03 sys=0.02, real=0.02 secs] |
3 | [GC [PSYoungGen: 148976K->21989K(153088K)] 178780K->70001K(240128K), 0.0362913 secs] [Times: user=0.11 sys=0.00, real=0.03 secs] |
4 | [GC [PSYoungGen: 153061K->34787K(283136K)] 201073K->100969K(370176K), 0.0318076 secs] [Times: user=0.08 sys=0.00, real=0.04 secs] |
5 | [Full GC [PSYoungGen: 34787K->0K(283136K)] [ParOldGen: 66182K->49354K(117248K)] 100969K->49354K(400384K) [PSPermGen: 18093K->18089K(36352K)], 0.1232627 secs] [Times: user=0.34 sys=0.00, real=0.11 secs] |
6 | [GC [PSYoungGen: 248320K->48632K(296960K)] 297674K->103225K(414208K), 0.0427160 secs] [Times: user=0.11 sys=0.01, real=0.06 secs] |
7 | [GC [PSYoungGen: 296952K->58861K(387072K)] 351545K->127707K(504320K), 0.0549142 secs] [Times: user=0.11 sys=0.03, real=0.05 secs] |
8 | [GC [PSYoungGen: 387053K->36470K(401920K)] 455899K->142959K(519168K), 0.0577764 secs] [Times: user=0.16 sys=0.00, real=0.06 secs] |
Pues si esta es la cara que se te queda al ver lo que el Garbage Collector escupe en tu consola estás leyendo el post adecuado. Como decía, en el Codemotion @alotor nos enseño una diapo en la que al menos pudimos saber relacionar las trazas con los tipos de procesos del Garbage Collector (recolección de jóvenes y STW stop the world) como se ve en la siguiente imagen:
Dado que es un tema extenso se tocaron unos cuantos temas más sin profundizar en demasía aunque dejando el camino trillado para poder seguir investigando sobre el Garbage Collector.
Vamos a analizar el detalle de la salida con el siguiente ejemplo para ver qué está queriendo decir el Garbage Collector:
Text | | copy code | | ? |
1 | [GC [PSYoungGen: 387053K->36470K(401920K)] 455899K->142959K(519168K), 0.0577764 secs] [Times: user=0.16 sys=0.00, real=0.06 secs] |
Descripción de la salida del Garbage Collector
[GC [PSYoungGen: 387053K->36470K(401920K)]
GC indica el que el Garbage Collector que ha entrado en acción no es un [Full GC] ya que en ese caso aparecería ese tipo indicado como se puede ver en el ejemplo de más arriba.
PSYoungGen nos dice que tipo de collector se emplea. PSYoungGen es el recolector de jóvenes.
387053K indica el tamaño de la región de jóvenes antes de la ejecución del Garbage Collector.
36470K indica valor posterior a la ejecución del GC que ocupa la región de jóvenes. Cuánto menor sea su número mejor puesto que significará que ha liberado más espacio de memoria.
401920K valor máximo de memoria que puede ocupar la región de jóvenes.
455899K->142959K(519168K), 0.0577764 secs]
455899K tamaño total ocupado en el heap antes de la ejecución del Garbage Collector.
142959K tamaño resultante de la ejecución de GC.
519168K valor del tamaño máximo del heap.
0.0577764 secs tiempo invertido en realizar la operación de liberación de espacio de memoria heap.
conclusiones
Como hemos podido ver es mucho más sencillo ahora entender un poco qué es lo que ocurre y hace el Garbage Collector cuando añadimos los parámetros necesarios para tracear su actividad.
¡ Todos los comentarios son bien recibidos !
Deja tu comentario