Problemas de rendimiento en una JVM

Infrastructure

20/08/2015 - avanttic

java

Si te dedicas a la administración de sistemas Middleware, tarde o temprano acabas encontrando problemas de rendimiento sobre las aplicaciones. Hay muchos factores que pueden afectar al rendimiento, como puede ser una aplicación mal desarrollada, consultas en base de datos con tiempo de ejecución elevado, latencias de comunicaciones y un largo etcétera. En el caso de WebLogic, las instancias no son otra cosa que un proceso Java y, como tal, una mala configuración también puede empeorar el rendimiento. En este post nos vamos a centrar en la configuración de la memoria de procesos Java.

¿Qué información necesitamos?

Para poder analizar el comportamiento de la memoria de procesos Java es imprescindible recoger las trazas de Garbage Collector (GC). Esto se configura en el arranque del proceso Java mediante unas variables.

Estas trazas aportan datos sobre:

Tiempo de ejecución de GC.
Estado de la memoria (young, old y permanent) antes y después de las limpiezas.
Si se han ejecutado Full GC (FGC) y cuánto han estado ejecutándose: este dato es especialmente importante puesto que durante un FGC la instancia se queda congelada.

Un ejemplo de esta información sería (en esta traza de ejecución no se han realizado FGC):

2015-08-19T00:49:03.965+0200: 9,759: [

GC pause

(young),

0,0176360 secs

]
   [Parallel Time: 15,7 ms, GC Workers: 2]
      [GC Worker Start (ms): Min: 9759,0, Avg: 9759,3, Max: 9759,6, Diff: 0,6]
      [Ext Root Scanning (ms): Min: 3,2, Avg: 3,5, Max: 3,7, Diff: 0,5, Sum: 7,0]
      [Update RS (ms): Min: 0,0, Avg: 0,0, Max: 0,0, Diff: 0,0, Sum: 0,0]
         [Processed Buffers: Min: 0, Avg: 6,5, Max: 13, Diff: 13, Sum: 13]
      [Scan RS (ms): Min: 0,0, Avg: 0,1, Max: 0,1, Diff: 0,1, Sum: 0,1]
      [Object Copy (ms): Min: 11,8, Avg: 11,8, Max: 11,8, Diff: 0,0, Sum: 23,6]
      [Termination (ms): Min: 0,0, Avg: 0,0, Max: 0,0, Diff: 0,0, Sum: 0,0]
      [GC Worker Other (ms): Min: 0,0, Avg: 0,0, Max: 0,0, Diff: 0,0, Sum: 0,1]
      [GC Worker Total (ms): Min: 15,1, Avg: 15,4, Max: 15,7, Diff: 0,6, Sum: 30,8]
      [GC Worker End (ms): Min: 9774,7, Avg: 9774,7, Max: 9774,7, Diff: 0,0]
   [Code Root Fixup: 0,1 ms]
   [Clear CT: 0,1 ms]
   [Other: 1,8 ms]
      [Choose CSet: 0,0 ms]
      [Ref Proc: 1,6 ms]
      [Ref Enq: 0,1 ms]
      [Free CSet: 0,1 ms]
   [

Eden: 89,0M(89,0M)->0,0B(89,0M) Survivors: 13,0M->13,0M Heap: 102,2M(2048,0M)->15,0M(2048,0M)

]
 [Times: user=0,03 sys=0,00, real=0,02 secs]

¿Cómo interpretamos esta información?

A pesar que las trazas de GC se pueden abrir con cualquier editor de texto, analizar estas trazas manualmente es muy tedioso y lento.

Hay varias herramientas que permiten ver esta información gráficamente y que, además, muestran estadísticas. La más comúnmente utilizada es GCViewer. Es un proyecto opensource que se mantiene vivo.

Antes de empezar

Explicar cómo ver si hay algún problema y cómo solucionarlo es un tema para el que se han escrito libros enteros, por lo que es imposible explicarlo en un post.

Aunque va a gustos, dejo algún libro que he utilizado como referencia (para mi opinión, de obligada lectura si te dedicas al sector):

“Java Performance: The Definitive Guide“, de Scott Oaks
“Java Performance“, de Charlie Hunt y Binu John (chapter 7: Tuning the JVM, Step by Step)

Antes de empezar, hay que tener muy en cuenta que:

Realizar un buen análisis es una tarea que no se realiza en un momento. En la mayoría de los casos estamos hablando de una semana de trabajo exhaustivo.
Una mala configuración puede empeorar el rendimiento. Puede llegar a ser peor el remedio que la enfermedad.

Resumiendo: ármate de paciencia y de buena documentación.

Ideas generales

¿Cada vez que se ejecuta un FGC es realmente necesario? En versiones anteriores de JDK, cada 60 segundos se ejecutaba, de forma sistemática, un FGC. Este comportamiento no es el deseado, pero se puede evitar añadiendo unas variables en el arranque del proceso Java.
Ampliar el tiempo entre ejecuciones de FGC puede sacar a la luz otros problemas. Los FGC ejecutados sin necesidad pueden estar ocultando leaks de memoria, que acabarían degradando aún más el rendimiento del proceso Java.
Aumentar los espacios de memoria (sea cual sea) provoca un aumento en el tiempo de ejecución de GC y FGC. A veces, menos es más.
La solución no tiene por qué venir únicamente del tuning de la VM. En algunos casos, pasa por el desarrollo de la aplicación que corre por encima (reducir los objetos en memoria y/o el tiempo de permanencia de estos objetos en memoria).
Si se observa que el espacio de memoria young se llena con facilidad y estos objetos se van promocionando a la old, para al poco tiempo borrarse de la old, una solución podría ser aumentar el tamaño de la zona Young en detrimento de la old con el objetivo de disminuir estas promociones a la zona old, además de disminuir el tiempo y frecuencia de los FGC.
Cada vez que se modifica un parámetro de configuración en el arranque, hay que volver a recolectar logs de GC para realizar una comparativa y ver si el cambio ha sido positivo.