Hace un tiempo escribimos un post sobre optimización de memoria Java en contenedores Docker. En este post nos escribisteis un comentario muy interesante relacionado con el impacto que pueden tener las pausas del Garbage Collector (GC) en el comportamiento de una aplicación.

Este comentario nos ha animado a escribir este post, donde explicaremos cómo el GC puede afectar al rendimiento de nuestra aplicación y cómo podemos mejorarlo eligiendo el tipo de GC adecuado.

Entendiendo cómo funciona el Garbage Collector

El GC juega un papel fundamental dentro de la JVM, ya que se encarga de liberar memoria Heap ocupada por objetos que ya no están en uso en nuestra aplicación.

Normalmente actúa cuando nuestra aplicación está alcanzando niveles en el consumo de memoria Heap cercanos al máximo disponible, momento en el cual comienza un ciclo de GC.

El GC funciona siguiendo un algoritmo Mark and Sweep. En primera instancia, en la fase de “Mark”, el algoritmo analiza las referencias de objetos de la memoria Heap marcando los objetos que son alcanzables, es decir, accesibles por nuestra aplicación. En la fase de “Sweep” el GC reclama el espacio de memoria Heap ocupado por objetos basura (no alcanzables), permitiendo que ese espacio quede libre para nuevos objetos de la aplicación.

Este mecanismo permite a los desarrolladores olvidarse por completo de la gestión de memoria, lo que en contrapartida hace perder control sobre la memoria, pudiendo impactar negativamente en el rendimiento de las aplicaciones.

Si bien el GC es un mecanismo implícito, Java ofrece diferentes tipos de GC. Escoger el GC óptimo para cada escenario nos permite mejorar el rendimiento de nuestras aplicaciones.

Serial Collector

Es el GC más simple de todos. Se caracteriza por suspender todos los hilos de la aplicación, para seguidamente ejecutar el algoritmo Mark and Sweep en un único hilo de ejecución. Estas pausas en la aplicación generadas por el GC se conocen como “stop the world”.

Serial GC

Parallel Collector

Este GC es similar al anterior, con la principal diferencia de que el GC ejecuta el algoritmo Mark and Sweep en múltiples hilos de ejecución. Si bien sigue existiendo una pausa en la aplicación causada por el GC, el tiempo de esta se reduce considerablemente comparándolo con el Serial Collector.

Parallel GC

Este tipo de GC también es conocido por el nombre de “Throughput Collector”, ya que está diseñado para que la aplicación pueda ofrecer un alto nivel de throughput.

Concurrent Collector

El Concurrent Collector se ejecuta la mayor parte del tiempo concurrentemente con la ejecución de la aplicación. Este GC no libera a la aplicación de pausas y requiere de dos pausas cortas en comparación con las generadas por los GCs anteriores.

Concurrent GC

En la primera pausa se ejecuta la fase de “Mark” en los GC roots, que son los objetos siempre alcanzables por la JVM a partir de los cuales se generan referencias a otros objetos en forma de árbol.

La fase de “Mark” continúa concurrentemente con la ejecución de la aplicación, esta vez partiendo de los GC roots y marcando los objetos conectados. Al estar marcándose objetos al mismo tiempo que se ejecutan hilos de la aplicación, también se registran los nuevos cambios que puedan haberse realizado sobre objetos ya marcados.

La segunda y última pausa se encarga de realizar el marcado final sobre aquellos objetos nuevos que se hayan podido crear.

Aplicación Java de partida

En nuestro anterior post vimos cómo limitando la memoria Heap de nuestra aplicación Java pudimos reducir significativamente la memoria total necesaria. Al monitorizar nuestra aplicación tras la optimización de memoria comprobamos que el throughput se mantenía igual que antes de la optimización, aún habiendo una mayor presencia del GC debido a la necesidad de mantener el consumo de memoria Heap por debajo del límite establecido.

En este escenario no encontramos la necesidad de realizar ninguna optimización relacionada con el GC. Ahora bien, ¿qué ocurre si escalamos la misma aplicación e incrementamos su carga?

Para este post, hemos escalado la memoria de la aplicación para que pueda dar soporte a 300 usuarios simultáneamente activos, lo cual supone el triple de usuarios que en el escenario anterior.

Hay que tener en cuenta que el tipo de GC del cual partimos en nuestra aplicación es el Parallel Collector, que es el GC por defecto en Java 8.

¿Cómo vamos a monitorizar nuestra aplicación?

En primer lugar, vamos a definir cada una de las herramientas que vamos a utilizar para monitorizar nuestra aplicación:

  • Apache JMeter: para realizar una prueba de carga sobre nuestra aplicación y visualizar de forma gráfica el rendimiento de la aplicación.
  • JConsole: para visualizar de forma gráfica el consumo de memoria Heap y CPU de nuestra aplicación durante la prueba.
  • GCViewer: para visualizar de forma gráfica los logs generados por el Garbage Collector durante la prueba.

Configurando JMeter

Para realizar nuestra prueba de carga vamos a partir del mismo proyecto JMeter que usamos en nuestro anterior post. La única diferencia es que vamos a modificar las Thread Properties estableciendo 300 usuarios simultáneos en vez de 100.

JMeter screenshot

Una vez guardado el proyecto con la propiedad actualizada, vamos a configurar JMeter para que genere dashboards visuales del rendimiento de nuestra aplicación durante la prueba de carga. Afortunadamente existe documentación oficial en donde se explica cómo configurar la generación de dashboards en JMeter.

Configurando JConsole

Para poder monitorizar nuestra aplicación con JConsole primero tenemos que activar las Java Management Extensions (JMX). Os animo a echar un vistazo a nuestro anterior post , donde explico paso a paso cómo hacerlo y cómo conectar JConsole a nuestra aplicación.

Configurando logs del GC

GCViewer se alimenta de un fichero de logs del GC, por tanto, antes de usar GCViewer tenemos que configurar la JVM para obtener logs del rendimiento del GC.

Para este fin usaremos los siguientes flags de la JVM:

  • -XX:+PrintGCDetails: Activa la generación de logs detallados del GC.
  • -Xloggc:/tmp/gc/gc.log: Nos permite especificar la ruta del fichero donde escribir los logs del GC.

Ya tenemos todo lo necesario para poder ejecutar nuestra prueba de carga y visualizar el rendimiento de nuestra aplicación.

¡Vamos allá!

Monitorizando nuestra aplicación de partida

Una vez ejecutada la prueba de carga y habiendo esperado a que esta finalice, ya tendremos disponible la información que buscamos para entender cómo se ha comportado nuestra aplicación durante la prueba.

En primer lugar, vamos a ver en JConsole información sobre el consumo de memoria Heap:

JConsole Heap parallel GC

Como se puede ver, el consumo de memoria Heap asciende hasta estabilizarse cerca de 512Mb. Este comportamiento se debe a que a medida que avanza la prueba de carga, la memoria Heap se va ocupando con nuevos objetos, terminando por estabilizarse cerca del límite establecido (512Mb). Los picos en la gráfica se deben a la acción del GC.

El siguiente paso es analizar cómo se ha comportado el throughput de la aplicación. Esta información la podemos obtener a través de los dashboards generados por JMeter:

JMeter throughput parallel GC

Como se puede observar, el throughput asciende hasta unas 175 transacciones/segundo, cayendo aproximadamente en el séptimo minuto de la prueba a unas 70 transacciones/segundo. El motivo de esta caída puede ser una pausa causada por el GC, que recordemos que es de tipo Parallel. Esta hipótesis la validaremos cuando analicemos los logs del GC.

Para aquellas aplicaciones en donde necesitemos un throughput alto y constante, caídas como esta pueden ser inaceptables.

Para obtener información sobre el comportamiento del GC, abrimos el fichero de logs generado en GCViewer:

GCViewer parallel GC 1

Cada línea vertical negra marca el inicio y final de un ciclo completo de GC. Podemos ver cómo a medida que avanza la prueba se incrementa la frecuencia de ciclos de GC.

Las áreas azules corresponden al total de memoria Heap utilizada en cada momento. Cuanto mayor es la memoria Heap en uso, más ciclos de GC son necesarios para liberar espacio.

Las líneas en gris oscuro que se ven en la parte inferior de la gráfica corresponden a los tiempos de recolección del GC. Podemos ver cómo en mitad de la gráfica los tiempos de recolección ascienden notablemente, ¿estará esto relacionado con la caída de throughput?

GCViewer permite ampliar la gráfica para situarnos en un intervalo de tiempo más acotado. Lo que vamos a hacer es situarnos aproximadamente en el séptimo minuto de nuestra prueba, con el fin de validar nuestra hipótesis relacionada con la caída del throughput debida a una posible pausa del GC.

Debemos tener en cuenta que las fechas y horas que muestra GCViewer en el cronograma superior no corresponden con las de la prueba de carga, si no que se muestran como si la prueba hubiera comenzado en el momento de abrir el fichero de logs en GCViewer. Afortunadamente, conociendo el intervalo de tiempo, es fácil situarnos donde queremos.

GCViewer parallel GC 2

Hemos habilitado una opción de GCViewer que permite ver con líneas de color verde los tiempos del GC, ya que al haber ampliado la gráfica la información puede ser más confusa.

Viendo la gráfica comprobamos que nos encontramos en el momento en el que el tiempo de recolección del GC asciende de forma notable, que además coincide con la bajada en el throughput de nuestra aplicación.

Teniendo en cuenta lo anterior, confirmamos que nuestra hipótesis es cierta y que, por tanto, el throughput de nuestra aplicación se ha visto notablemente afectado puntualmente por el tipo de GC.

GCViewer también nos ofrece una tabla con datos agregados sobre el rendimiento del GC. El throughput que aquí se indica corresponde al porcentaje de tiempo que la aplicación no ha estado ocupada con el GC, en nuestro caso 84,35%.

GCViewer parallel GC 3

Guardar toda la información que hemos obtenido es muy útil, de cara a optimizaciones posteriores sobre el GC. De esta forma, podremos contrastar los rendimientos del GC optimizado con el escenario inicial.

Seguramente os estéis preguntando, ¿qué vamos a hacer exactamente con el GC de nuestra aplicación?

Como comenté anteriormente, en algunos escenarios no podemos permitirnos bajadas de throughput como la que hemos experimentado. Sin embargo, el promedio de throughput que hemos obtenido, sumado al porcentaje de tiempo que la aplicación no ha estado ocupada con el GC, pueden ser resultados más que aceptables en otros escenarios.

Vamos a suponer que necesitamos que nuestra aplicación pueda mantener un buen nivel de throughput de forma constante, quizás no tan alto como el que puede llegar a ofrecer el Parallel Collector, pero sin experimentar bajadas sustanciales. Estoy seguro de que muchos de vosotros ya estaréis pensando que tal vez lo que necesitemos sea el Concurrent Collector.

Monitorizando nuestra aplicación con Concurrent Collector

Hemos de tener en cuenta que para beneficiarnos de este tipo de GC, necesitamos disponer de múltiples CPUs en nuestro equipo, de lo contrario este no sería el GC adecuado para nuestro escenario.

Por otro lado, debido a la creación de nuevos objetos y cambios en las referencias entre objetos que pueden ocurrir concurrentemente con la recolección de basura, este GC requiere de un trabajo adicional que se traduce en un incremento en el consumo de recursos.

Teniendo en claro lo anterior, ¡Vamos a ver cómo se comporta este GC en nuestra aplicación!

En primer lugar, es necesario indicar de forma explícita a la JVM que use el Concurrent Collector, para que no asigne el GC por defecto, que recordemos que en nuestro caso sería el Parallel Collector. La JVM pone a nuestra disposición un flag concreto para esta finalidad: -XX:+UseConcMarkSweepGC.

Una vez realizada la prueba de carga sobre nuestra aplicación con Concurrent Collector, vamos a analizar las gráficas en este nuevo escenario. Comenzamos con el consumo de memoria Heap:

JConsole Heap concurrent GC

Como se puede observar, el consumo de memoria asciende siguiendo una tendencia similar al escenario anterior hasta aproximarse al máximo (512Mb), con la diferencia de que los ascensos y descensos de consumo de memoria son más cortos, debidos a la limpieza concurrente con la ejecución de la aplicación.

Vamos a ver el comportamiento del throughput de la aplicación y si, gracias al Concurrent Collector, hemos logrado evitar caídas de throughput significativas:

JMeter throughput concurrent GC

Observando la gráfica podemos afirmar que durante la prueba de carga el throughput se ha mantenido en valores máximos un poco más bajos de los que obtuvimos con el Parallel Collector, pero con la principal ventaja de que no hemos experimentado ninguna caída significativa.

Vamos a abrir GCViewer para ver en detalle cómo se ha comportado el Concurrent Collector:

GCViewer concurrent GC 1

Lo primero que seguramente os llame la atención de esta gráfica son las líneas verticales de color turquesa. Estas líneas marcan las recolecciones realizadas concurrentemente por el GC, que recordemos que no existen en el Parallel Collector.

Aquí podemos apreciar de nuevo los ascensos y descensos de consumo de memoria Heap más atenuados que en el Parallel Collector debidos a las recolecciones concurrentes.

Otro aspecto que llama la atención de la gráfica son las líneas negras que marcan el inicio y final de los ciclos de GC. Como se puede apreciar, en este GC los ciclos, especialmente al principio de la prueba, se extienden más en el tiempo.

A diferencia de lo que ocurría con el Parallel Collector, no encontramos registrado ningún ascenso sustancial en los tiempos del GC.

Por último, vamos a revisar la tabla de datos agregados de rendimiento del GC:

GCViewer concurrent GC 2

El throughput, que en el Parallel Collector era de 84,35%, aquí es de 75,73%, lo que demuestra que ha habido una ligera mayor ocupación del GC en nuestra aplicación.

¿Qué Garbage Collector elegimos?

Como comenté anteriormente, depende del escenario en el que nos encontremos y de los requisitos que queramos que cumpla nuestra aplicación.

Con el Parallel Collector nuestra aplicación puede llegar a ofrecer en determinados instantes un nivel de throughput muy alto, aunque no sostenible en el tiempo, ya que podemos experimentar bajadas significativas debidas a pausas del GC como la que hemos visto en la prueba de carga.

Por otro lado, con el Concurrent Collector conseguimos mantener un throughput un poco más bajo de forma sostenida, aunque con un incremento en el consumo de CPU. A continuación se muestra una gráfica del consumo de CPU del Concurrent Collector durante la prueba de carga:

JConsole CPU concurrent GC

Y a continuación, la misma gráfica usando Parallel Collector:

JConsole CPU parallel GC

Como se puede apreciar comparando las dos gráficas, con el Concurrent Collector encontramos varios picos de consumo de CPU por encima del 30%, llegando algunos incluso a estar por encima del 40%. Por otro lado, con el Parallel Collector, en pocas ocasiones el consumo de CPU se sitúa por encima del 30%.

Teniendo en cuenta el análisis que hemos llevado a cabo usando dos tipos diferentes de GCs, es cuestión de decidir qué opción nos conviene más dado nuestro escenario

Si no necesitamos un nivel de throughput especialmente alto y lo que buscamos es que este sea sostenido en el tiempo entonces el Concurrent Collector es una buena opción, siempre que podamos asumir el incremento adicional en el uso de CPU

Si por el contrario buscamos maximizar el nivel de throughput de nuestra aplicación, aún pudiendo ocasionarse bajadas significativas, o no podemos asumir el consumo adicional de CPU del Concurrent Collector, optar por el Parallel Collector es una gran idea.

Para terminar…

En este post hemos llevado a cabo un análisis sobre el rendimiento de una aplicación Java usando diferentes tipos de GC.

En primer lugar, hemos partido de una aplicación de ejemplo que usaba Parallel Collector como GC y hemos monitorizado el impacto de este GC en el rendimiento de la aplicación mediante una prueba de carga, encontrando un alto nivel de throughput pero con una bajada significativa debida a una pausa del GC.

Después, hemos cambiado el GC de la aplicación por el Concurrent Collector y hemos vuelto a ejecutar la misma prueba de carga sobre la aplicación para monitorizarla de nuevo, encontrando un nivel de throughput un poco más bajo pero sostenible en el tiempo.

Finalmente, hemos contrastado los resultados obtenidos y hemos identificado cuáles son los puntos fuertes y débiles de cada GC a tener en cuenta de cara a escoger el óptimo para nuestro escenario.

Hay que tener en cuenta que los resultados obtenidos en este análisis son concretos de nuestra aplicación de ejemplo. En otras aplicaciones podremos encontrar resultados completamente diferentes usando los mismos GCs, por lo que os aconsejo que llevéis a cabo análisis similares en vuestras aplicaciones para encontrar el tipo de GC que mejor se adapte a vuestro escenario.

Decidimos escribir este post a raíz de un comentario que recibimos en otro post, por lo que os animo a que compartáis vuestras opiniones y experiencias en la sección de comentarios. ¡Tal vez nos deis otra gran idea para escribir otro post! 😉