icon - line border java example

El montón de Java abrumado por objetos inalcanzables

Question

Hemos empezado a tener algunos problemas serios con nuestra aplicación Java EE. Específicamente, la aplicación ejecuta hasta el 99% del montón de la generación anterior en cuestión de minutos después del inicio. No se lanzan OOM, pero efectivamente la JVM no responde. El jstat muestra que la generación anterior no disminuye en tamaño en absoluto, no se realiza ninguna recolección de basura, y kill -3 dice:

Heap
 PSYoungGen      total 682688K, used 506415K [0xc1840000, 0xf3840000, 0xf3840000)
  eden space 546176K, 92% used [0xc1840000,0xe06cd020,0xe2da0000)
  from space 136512K, 0% used [0xe2da0000,0xe2da0000,0xeb2f0000)
  to   space 136512K, 0% used [0xeb2f0000,0xeb2f0000,0xf3840000)
 PSOldGen        total 1536000K, used 1535999K [0x63c40000, 0xc1840000, 0xc1840000)
  object space 1536000K, 99% used [0x63c40000,0xc183fff8,0xc1840000)

Las opciones de VM son:

-Xmx2300m -Xms2300m -XX:NewSize=800m -XX:MaxNewSize=800m -XX:SurvivorRatio=4 -XX:PermSize=256m -XX:MaxPermSize=256m -XX:+UseParallelGC -XX:ParallelGCThreads=4 

(Lo cambié de tener 2300m heap / 1800m new gen, como un intento de resolver el problema)

Tomé un montón de volcado de la JVM una vez que llegó al estado "sin memoria" (tardó una eternidad) y ejecuté Eclipse Memory Analyzer en él.

Los resultados son bastante divertidos. Alrededor de 200Mb está ocupado por objetos de todo tipo (hay algunos que poseen más que otros), pero el resto, 1.9Gb son todos inalcanzables (puede ser significativo decir que la mayoría está ocupada por objetos GSON, pero no creo que sea una indicación de algo, solo dice que batimos a través de muchos objetos GSON durante la operación del servidor).

¿Alguna explicación de por qué la máquina virtual tiene tantos objetos inalcanzables y es incapaz de recopilarlos?

JVM:

$ /0/bin/java -version
java version "1.6.0_37"
Java(TM) SE Runtime Environment (build 1.6.0_37-b06)
Java HotSpot(TM) Server VM (build 20.12-b01, mixed mode)

Cuando el sistema llega a este puesto, esto es lo que GC detallado sigue imprimiendo:

922.485: [GC [1 CMS-initial-mark: 511999K(512000K)] 1952308K(2048000K), 3.9069700 secs] [Times: user=3.91 sys=0.00, real=3.91 secs] 
926.392: [CMS-concurrent-mark-start]
927.401: [Full GC 927.401: [CMS927.779: [CMS-concurrent-mark: 1.215/1.386 secs] [Times: user=5.84 sys=0.13, real=1.38 secs] (concurrent mode failure): 511999K->511999K(512000K), 9.4827600 secs] 2047999K->1957315K(2048000K), [CMS Perm : 115315K->115301K(262144K)], 9.4829860 secs] [Times: user=9.78 sys=0.01, real=9.49 secs] 
937.746: [Full GC 937.746: [CMS: 512000K->511999K(512000K), 8.8891390 secs] 2047999K->1962252K(2048000K), [CMS Perm : 115302K->115302K(262144K)], 8.8893810 secs] [Times: user=8.89 sys=0.01, real=8.89 secs] 

Resuelto

Como lo sugirió Paul Bellora, esto fue causado por una cantidad demasiado grande de objetos creados dentro de la JVM, en un período de tiempo demasiado corto. La depuración se vuelve bastante tediosa en este punto. Lo que terminé haciendo, es, instrumentar las clases usando un agente JVM personalizado. La instrumentación contaría invocaciones de método y constructor. Luego se examinaron los conteos. Descubrí que una sola operación discreta crearía aproximadamente 2 millones de objetos y desencadenaría ciertos métodos individuales aproximadamente 1.5 millones de veces (no, no había bucles). La operación en sí fue identificada por ser lenta en comparación con otras. También puedes usar cualquier perfil de hotspot (algo como visualVM), pero tuve todo tipo de problemas con eso, así que terminé escribiendo el mío.

Todavía pienso que el comportamiento de la JVM es un misterio. Parece que el recolector de basura se detiene y no va a limpiar más memoria, pero el asignador de memoria espera que lo haga (y, por lo tanto, no se arrojan OOM). En su lugar, habría esperado que borrara toda esa memoria inalcanzable. Pero el comportamiento de la aplicación no estaría mucho mejor, ya que la mayoría del tiempo se habría gastado en recolectar basura de todos modos.

Answer 1

¿Alguna explicación de por qué la máquina virtual tiene tantos objetos inalcanzables y es incapaz de recopilarlos?

(Según nuestro intercambio en los comentarios), parece que esto no es una pérdida de memoria tradicional sino una lógica que continuamente genera spams de nuevos objetos, de manera que el GC se esfuerza por mantenerse al día con la arquitectura actual.

El culpable podría ser, por ejemplo, alguna solicitud de API que se realiza muchas, muchas veces, o está "atascada" en algún estado erróneo como el escenario de paginación infinita que describí. Lo que se reduce a cualquiera de estas situaciones es a millones de objetos gson de respuesta (que apuntan a que las String (que apuntan a char[] s)) se crean instancias y luego se vuelven elegibles para GC.

Como dije, debería intentar aislar las solicitudes de problemas, luego depurar y tomar medidas para decidir si se trata de un problema de escalabilidad o error por parte de su aplicación o una de sus bibliotecas.

Answer 2

Según las estadísticas que figuran en la lista, me resulta difícil creer que tenga 1.9G de datos inalcanzables. Se parece más a un GC Overhead Limit Reached .

Considerar

937.746: [Full GC 937.746: [CMS: 512000K-> 511999K (512000K), 8.8891390 secs] 2047999K-> 1962252K (2048000K), [CMS Perm: 115302K-> 115302K (262144K)], 8.8893810 siqu. 8,89 sys = 0,01, real = 8,89 segundos]

Si esto es cierto, entonces un GC completo libera 85 K de datos. Si tuviera 1.9G de código inalcanzable, vería 2047999 -> ~300000 .

también

object space 1536000K, 99% 

Implica que algo fue creado y almacenado de tal manera que escapó a un método y ahora vive probablemente para siempre.

Necesitaría ver más evidencia de que tiene 1.9G de datos inalcanzables que no sean simplemente informados.