OutOfMemoryException trotz Verwendung von WeakHashMap

9

Wenn Sie nicht aufrufen System.gc(), löst das System eine OutOfMemoryException aus. Ich weiß nicht, warum ich System.gc()explizit anrufen muss; Die JVM sollte sich gc()selbst nennen , oder? Bitte beraten.

Folgendes ist mein Testcode:

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();
    }
}

Fügen Sie wie folgt hinzu -XX:+PrintGCDetails, um die GC-Informationen auszudrucken. Wie Sie sehen, versucht die JVM tatsächlich, einen vollständigen GC-Lauf durchzuführen, schlägt jedoch fehl. Ich kenne den Grund immer noch nicht. Es ist sehr seltsam, dass System.gc();das Ergebnis positiv ist, wenn ich die Zeile auskommentiere :

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
quelle
welche jdk version? Verwenden Sie irgendwelche -Xms- und -Xmx-Parameter? Auf welchem ​​Schritt hast du OOM?
Vladislav Kysliy
1
Ich kann dies auf meinem System nicht reproduzieren. Im Debug-Modus kann ich sehen, dass der GC seinen Job macht. Können Sie im Debug-Modus überprüfen, ob die Karte tatsächlich gelöscht wird oder nicht?
Magicmn
jre 1.8.0_212-b10 -Xmx200m Weitere Details finden Sie im von mir angehängten GC-Protokoll. thx
Dominic Peng

Antworten:

7

JVM ruft GC alleine an, aber in diesem Fall ist es zu spät. In diesem Fall ist nicht nur GC für das Löschen des Speichers verantwortlich. Kartenwerte sind stark erreichbar und werden von der Karte selbst gelöscht, wenn bestimmte Vorgänge darauf aufgerufen werden.

Hier ist die Ausgabe, wenn Sie GC-Ereignisse aktivieren (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 wird erst beim letzten Versuch ausgelöst, einen Wert in die Karte einzufügen.

WeakHashMap kann veraltete Einträge erst löschen, wenn Kartenschlüssel in einer Referenzwarteschlange vorkommen. Und die Kartenschlüssel treten erst in einer Referenzwarteschlange auf, wenn sie durch Müll gesammelt wurden. Die Speicherzuweisung für einen neuen Kartenwert wird ausgelöst, bevor die Karte die Möglichkeit hat, sich selbst zu löschen. Wenn die Speicherzuordnung fehlschlägt und GC auslöst, werden Kartenschlüssel gesammelt. Aber es ist zu wenig zu spät - es wurde nicht genügend Speicher freigegeben, um einen neuen Kartenwert zuzuweisen. Wenn Sie die Nutzlast reduzieren, verfügen Sie wahrscheinlich über genügend Speicher, um neue Kartenwerte zuzuweisen, und veraltete Einträge werden entfernt.

Eine andere Lösung könnte darin bestehen, Werte selbst in WeakReference zu verpacken. Auf diese Weise kann GC Ressourcen löschen, ohne darauf warten zu müssen, dass die Karte dies selbst tut. Hier ist die Ausgabe:

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)

Viel besser.

Tentakel
quelle
Vielen Dank für Ihre Antwort, scheint Ihre Schlussfolgerung richtig zu sein; während ich versuche, die Nutzlast von 1024 * 10000 auf 1024 * 1000 zu reduzieren; Der Code kann gut funktionieren. aber ich verstehe deine Erklärung immer noch nicht sehr; Wenn Sie Speicherplatz von WeakHashMap freigeben möchten, sollten Sie gc mindestens zweimal ausführen. Die erste Zeit besteht darin, Schlüssel von der Karte zu sammeln und sie in die Referenzwarteschlange aufzunehmen. Das zweite Mal ist es, Werte zu sammeln? Aber aus dem ersten Protokoll, das Sie tatsächlich zur Verfügung gestellt haben, hatte JVM bereits zweimal die volle GC genommen.
Dominic Peng
Sie sagen, dass "Kartenwerte stark erreichbar sind und von der Karte selbst gelöscht werden, wenn bestimmte Vorgänge darauf aufgerufen werden." Wo sind sie erreichbar?
Andronicus
1
In Ihrem Fall reicht es nicht aus, nur zwei GC-Läufe durchzuführen. Zuerst benötigen Sie einen GC-Lauf, das ist richtig. Der nächste Schritt erfordert jedoch eine gewisse Interaktion mit der Karte selbst. Was Sie suchen sollten, ist eine Methode, java.util.WeakHashMap.expungeStaleEntriesdie die Referenzwarteschlange liest und Einträge aus der Karte entfernt, wodurch Werte nicht erreichbar sind und erfasst werden müssen. Erst danach wird durch den zweiten Durchgang des GC Speicherplatz frei. expungeStaleEntrieswird in einer Reihe von Fällen aufgerufen, z. B. get / put / size oder so ziemlich alles, was Sie normalerweise mit einer Karte tun. Das ist der Haken.
Tentakel
1
@Andronicus, dies ist bei weitem der verwirrendste Teil von WeakHashMap. Es wurde mehrfach abgedeckt. stackoverflow.com/questions/5511279/…
Tentakel
2
@Andronicus Diese Antwort , insbesondere die zweite Hälfte, könnte ebenfalls hilfreich sein. Auch diese Fragen und Antworten
Holger
5

Die andere Antwort ist in der Tat richtig, ich habe meine bearbeitet. Als kleines Addendum G1GCwird dieses Verhalten im Gegensatz zu nicht zeigen ParallelGC; Das ist die Standardeinstellung unter java-8.

Was denkst du wird passieren, wenn ich dein Programm leicht ändere auf (laufe mit jdk-8mit -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
    }
}

Es wird gut funktionieren. Warum ist das so? Weil es Ihrem Programm gerade genug Raum zum Atmen gibt, damit neue Zuordnungen stattfinden können, bevor WeakHashMapdie Einträge gelöscht werden. Und die andere Antwort erklärt bereits, wie das passiert.

Jetzt G1GCwäre es ein bisschen anders. Wenn ein so großes Objekt zugewiesen wird ( normalerweise mehr als 1/2 MB ), wird dies als a bezeichnet humongous allocation. In diesem Fall wird eine gleichzeitige GC ausgelöst. Als Teil dieses Zyklus: Es wird eine junge Sammlung ausgelöst und eine Cleanup phaseinitiiert, die sich darum kümmert, das Ereignis auf dem zu veröffentlichen ReferenceQueue, damit WeakHashMapseine Einträge gelöscht werden.

Also für diesen Code:

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
    }
}

dass ich mit jdk-13 laufe (wo G1GCist die Standardeinstellung)

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

Hier ist ein Teil der Protokolle:

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

Das macht schon etwas anderes. Es startet ein concurrent cycle(erledigt, während Ihre Anwendung ausgeführt wird), weil es ein gab G1 Humongous Allocation. Im Rahmen dieses gleichzeitigen Zyklus wird ein junger GC-Zyklus durchgeführt (der Ihre Anwendung während der Ausführung stoppt ).

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

Als Teil dieses jungen GC räumt es auch humongous Regionen , hier ist der Defekt .


Sie können jetzt sehen, dass jdk-13nicht darauf gewartet wird, dass sich in der alten Region Müll ansammelt, wenn wirklich große Objekte zugewiesen werden, sondern ein gleichzeitiger GC-Zyklus ausgelöst wird, der den Tag rettet. im gegensatz zu jdk-8.

Vielleicht möchten Sie lesen, was DisableExplicitGCund / oder ExplicitGCInvokesConcurrentbedeuten, zusammen mit System.gcund verstehen, warum das Anrufen hier System.gctatsächlich hilft.

Eugene
quelle
1
Java 8 verwendet standardmäßig kein G1GC. Und die GC-Protokolle des OP zeigen auch deutlich, dass es für die alte Generation paralleles GC verwendet. Und für einen solchen nicht gleichzeitigen Sammler ist es so einfach wie in dieser Antwort beschrieben
Holger
@Holger Ich habe diese Antwort heute Morgen überprüft, nur um festzustellen, dass sie tatsächlich ParalleGCbearbeitet wurde. Es tut mir leid (und ich danke Ihnen), dass Sie mir das Gegenteil bewiesen haben.
Eugene
1
Die „gewaltige Zuordnung“ ist immer noch ein korrekter Hinweis. Bei einem nicht gleichzeitigen Kollektor bedeutet dies, dass der erste GC ausgeführt wird, wenn die alte Generation voll ist. Wenn also nicht genügend Speicherplatz zurückgefordert wird, ist dies fatal. Wenn Sie dagegen die Array-Größe reduzieren, wird ein junger GC ausgelöst, wenn in der alten Generation noch Speicher vorhanden ist, sodass der Kollektor Objekte heraufstufen und fortfahren kann. Für einen Concurrent Collector hingegen ist es normal, gc auszulösen, bevor der Heap erschöpft ist. Lassen -XX:+UseG1GCSie ihn also in Java 8 funktionieren, genauso wie -XX:+UseParallelOldGCer in neuen JVMs fehlschlägt.
Holger