OutOfMemoryException a pesar de usar WeakHashMap

9

Si no llama System.gc(), el sistema lanzará una excepción OutOfMemoryException. No sé por qué necesito llamar System.gc()explícitamente; la JVM debería llamarse a gc()sí misma, ¿verdad? Por favor avise.

El siguiente es mi código de prueba:

public static void main(String[] args) throws InterruptedException {
    WeakHashMap<String, int[]> hm = new WeakHashMap<>();
    int i  = 0;
    while(true) {
        Thread.sleep(1000);
        i++;
        String key = new String(new Integer(i).toString());
        System.out.println(String.format("add new element %d", i));
        hm.put(key, new int[1024 * 10000]);
        key = null;
        //System.gc();
    }
}

De la siguiente manera, agregue -XX:+PrintGCDetailspara imprimir la información del GC; como ve, en realidad, la JVM intenta hacer una ejecución completa de GC, pero falla; Yo todavía no sé la razón. Es muy extraño que si descomento la System.gc();línea, el resultado es positivo:

add new element 1
add new element 2
add new element 3
add new element 4
add new element 5
[GC (Allocation Failure) --[PSYoungGen: 48344K->48344K(59904K)] 168344K->168352K(196608K), 0.0090913 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 
[Full GC (Ergonomics) [PSYoungGen: 48344K->41377K(59904K)] [ParOldGen: 120008K->120002K(136704K)] 168352K->161380K(196608K), [Metaspace: 5382K->5382K(1056768K)], 0.0380767 secs] [Times: user=0.09 sys=0.03, real=0.04 secs] 
[GC (Allocation Failure) --[PSYoungGen: 41377K->41377K(59904K)] 161380K->161380K(196608K), 0.0040596 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
[Full GC (Allocation Failure) [PSYoungGen: 41377K->41314K(59904K)] [ParOldGen: 120002K->120002K(136704K)] 161380K->161317K(196608K), [Metaspace: 5382K->5378K(1056768K)], 0.0118884 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
    at test.DeadLock.main(DeadLock.java:23)
Heap
 PSYoungGen      total 59904K, used 42866K [0x00000000fbd80000, 0x0000000100000000, 0x0000000100000000)
  eden space 51712K, 82% used [0x00000000fbd80000,0x00000000fe75c870,0x00000000ff000000)
  from space 8192K, 0% used [0x00000000ff800000,0x00000000ff800000,0x0000000100000000)
  to   space 8192K, 0% used [0x00000000ff000000,0x00000000ff000000,0x00000000ff800000)
 ParOldGen       total 136704K, used 120002K [0x00000000f3800000, 0x00000000fbd80000, 0x00000000fbd80000)
  object space 136704K, 87% used [0x00000000f3800000,0x00000000fad30b90,0x00000000fbd80000)
 Metaspace       used 5409K, capacity 5590K, committed 5760K, reserved 1056768K
  class space    used 576K, capacity 626K, committed 640K, reserved 1048576K
Dominic Peng
fuente
¿Qué versión jdk? ¿Utiliza algún parámetro -Xms y -Xmx? en qué paso tienes OOM?
Vladislav Kysliy
1
No puedo reproducir esto en mi sistema. En modo de depuración puedo ver que el GC está haciendo su trabajo. ¿Puede verificar en modo de depuración si el Mapa se está borrando o no?
magicmn
jre 1.8.0_212-b10 -Xmx200m Puede ver más detalles en gc log que adjunté; thx
Dominic Peng

Respuestas:

7

JVM llamará a GC por sí mismo, pero en este caso será demasiado poco y demasiado tarde. No es solo GC el responsable de borrar la memoria en este caso. Los valores del mapa son muy accesibles y el mapa los borra cuando se invocan ciertas operaciones en él.

Aquí está la salida si activa los eventos de GC (XX: + PrintGC):

add new element 1
add new element 2
add new element 3
add new element 4
add new element 5
add new element 6
add new element 7
[GC (Allocation Failure)  2407753K->2400920K(2801664K), 0.0123285 secs]
[GC (Allocation Failure)  2400920K->2400856K(2801664K), 0.0090720 secs]
[Full GC (Allocation Failure)  2400856K->2400805K(2590720K), 0.0302800 secs]
[GC (Allocation Failure)  2400805K->2400805K(2801664K), 0.0069942 secs]
[Full GC (Allocation Failure)  2400805K->2400753K(2620928K), 0.0146932 secs]
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space

GC no se activa hasta el último intento de poner valor en el mapa.

WeakHashMap no puede borrar las entradas obsoletas hasta que se produzcan claves de mapa en una cola de referencia. Y las claves del mapa no aparecen en una cola de referencia hasta que se recolectan basura. La asignación de memoria para el nuevo valor del mapa se activa antes de que el mapa tenga alguna posibilidad de borrarse. Cuando la asignación de memoria falla y desencadena GC, las claves del mapa se recopilan. Pero es demasiado poco, demasiado tarde: no se ha liberado suficiente memoria para asignar un nuevo valor de mapa. Si reduce la carga útil, probablemente termine con suficiente memoria para asignar un nuevo valor de mapa y se eliminarán las entradas obsoletas.

Otra solución podría ser envolver los valores en WeakReference. Esto permitirá que GC elimine recursos sin esperar que el mapa lo haga por sí mismo. Aquí está la salida:

add new element 1
add new element 2
add new element 3
add new element 4
add new element 5
add new element 6
add new element 7
[GC (Allocation Failure)  2407753K->2400920K(2801664K), 0.0133492 secs]
[GC (Allocation Failure)  2400920K->2400888K(2801664K), 0.0090964 secs]
[Full GC (Allocation Failure)  2400888K->806K(190976K), 0.1053405 secs]
add new element 8
add new element 9
add new element 10
add new element 11
add new element 12
add new element 13
[GC (Allocation Failure)  2402096K->2400902K(2801664K), 0.0108237 secs]
[GC (Allocation Failure)  2400902K->2400838K(2865664K), 0.0058837 secs]
[Full GC (Allocation Failure)  2400838K->1024K(255488K), 0.0863236 secs]
add new element 14
add new element 15
...
(and counting)

Mucho mejor.

tentáculo
fuente
Gracias por su respuesta, parece que su conclusión es correcta; mientras trato de reducir la carga útil de 1024 * 10000 a 1024 * 1000; el código puede funcionar bien; pero TODAVÍA no entiendo muy bien tu explicación; como su significado, si necesita liberar espacio de WeakHashMap, debe hacer gc dos veces al menos; el primer tiempo es recolectar claves del mapa y agregarlas a la cola de referencia; la segunda vez es recolectar valores? pero del primer registro que proporcionó, en realidad, JVM ya había tomado el gc completo dos veces;
Dominic Peng
Estás diciendo que "los valores del mapa son muy accesibles y el mapa los borra cuando se invocan ciertas operaciones". ¿De dónde son accesibles?
Andronicus
1
No será suficiente tener solo dos ejecuciones de GC en su caso. Primero necesita una ejecución de GC, eso es correcto. Pero el siguiente paso requerirá cierta interacción con el mapa en sí. Lo que debe buscar es un método java.util.WeakHashMap.expungeStaleEntriesque lea la cola de referencia y elimine las entradas del mapa, lo que hace que los valores sean inalcanzables y estén sujetos a recopilación. Solo después de eso, el segundo paso de GC liberará algo de memoria. expungeStaleEntriesse llama en varios casos como get / put / size o casi todo lo que normalmente haces con un mapa. Esa es la trampa.
tentáculo
1
@Andronicus, esta es, con mucho, la parte más confusa de WeakHashMap. Fue cubierto varias veces. stackoverflow.com/questions/5511279/…
tentáculo
2
@Andronicus esta respuesta , especialmente la segunda mitad, también podría ser útil. También este Q&A ...
Holger
5

La otra respuesta es correcta, yo edité la mía. Como una pequeña adición, G1GCno exhibirá este comportamiento, a diferencia de ParallelGC; cuál es el valor predeterminado en java-8.

¿Qué crees que pasará si cambio ligeramente tu programa a (ejecutar jdk-8con -Xmx20m)

public static void main(String[] args) throws InterruptedException {
    WeakHashMap<String, int[]> hm = new WeakHashMap<>();
    int i = 0;
    while (true) {
        Thread.sleep(200);
        i++;
        String key = "" + i;
        System.out.println(String.format("add new element %d", i));
        hm.put(key, new int[512 * 1024 * 1]); // <--- allocate 1/2 MB
    }
}

Funcionará bien. ¿Porqué es eso? Debido a que le da a su programa suficiente espacio para respirar para que ocurran nuevas asignaciones, antes de WeakHashMapborrar sus entradas. Y la otra respuesta ya explica cómo sucede eso.

Ahora, en G1GC, las cosas serían un poco diferentes. Cuando se asigna un objeto tan grande (más de 1/2 a MB por lo general ), esto se llamaría a humongous allocation. Cuando eso sucede , se activará un GC concurrente . Como parte de ese ciclo: se activará una colección joven y Cleanup phasese iniciará una que se encargará de publicar el evento en el ReferenceQueue, para que WeakHashMapborre sus entradas.

Entonces para este código:

public static void main(String[] args) throws InterruptedException {
    Map<String, int[]> hm = new WeakHashMap<>();
    int i = 0;
    while (true) {
        Thread.sleep(1000);
        i++;
        String key = "" + i;
        System.out.println(String.format("add new element %d", i));
        hm.put(key, new int[1024 * 1024 * 1]); // <--- 1 MB allocation
    }
}

que ejecuto con jdk-13 (donde G1GCes el valor predeterminado)

java -Xmx20m "-Xlog:gc*=debug" gc.WeakHashMapTest

Aquí hay una parte de los registros:

[2.082s][debug][gc,ergo] Request concurrent cycle initiation (requested by GC cause). GC cause: G1 Humongous Allocation

Esto ya hace algo diferente. Comienza un concurrent cycle(hecho mientras su aplicación se está ejecutando), porque había un G1 Humongous Allocation. Como parte de este ciclo concurrente, realiza un ciclo GC joven (que detiene la aplicación mientras se ejecuta)

 [2.082s][info ][gc,start] GC(0) Pause Young (Concurrent Start) (G1 Humongous Allocation)

Como parte de ese GC joven , también borra regiones gigantescas , aquí está el defecto .


Ahora puede ver que jdk-13no espera que se acumule basura en la región anterior cuando se asignan objetos realmente grandes, sino que desencadena un ciclo de GC concurrente , que salvó el día; a diferencia de jdk-8.

Es posible que desee leer qué DisableExplicitGCy / o ExplicitGCInvokesConcurrentsignificado, junto con System.gcy comprender por qué llamar System.gcrealmente ayuda aquí.

Eugene
fuente
1
Java 8 no usa G1GC por defecto. Y los registros de GC del OP también muestran claramente que está utilizando GC paralelo para la generación anterior. Y para un coleccionista no concurrente, es tan simple como se describe en esta respuesta
Holger,
@Holger Estuve revisando esta respuesta hoy por la mañana solo para darme cuenta de que es cierto ParalleGC, he editado y lo siento (y gracias) por demostrarme que estoy equivocado.
Eugene
1
La "asignación enorme" sigue siendo una pista correcta. Con un recopilador no concurrente, implica que el primer GC se ejecutará cuando la generación anterior esté llena, por lo que el hecho de no recuperar suficiente espacio lo hará fatal. Por el contrario, cuando reduce el tamaño de la matriz, se activará un GC joven cuando aún quede memoria en la generación anterior, por lo que el recopilador puede promover objetos y continuar. Para un recopilador concurrente, por otro lado, es normal activar gc antes de que se agote el montón, por lo -XX:+UseG1GCque debe funcionar en Java 8, al igual que -XX:+UseParallelOldGChace que falle en las nuevas JVM.
Holger