Von Traumcodes und mehr: Exkursionen in die Deduplikation mit Java

Dr. Heinz Kabutz

© Shutterstock.com/OLaLa Merkel

Wann werden Strings dedupliziert? Wie können wir herausfinden, ob sie in unserer Anwendung Vorteile bringen? Wie hoch sind die Kosten bezüglich der CPU? Wir versuchen zu zeigen, wie wir in der Deduplikationsstatistik der JVM die Antworten finden können.

Nach meinem Talk auf der jPrime 2019, fragte mich jemand, wie er erkennen könne, wie effektiv die Stringdeduplikation in seiner Anwendung sein würde. Für diese Messung finde ich den Blick auf die Response Rates und den Speicherverbrauch am effektivsten. Denn was hilft es letztlich, wenn wir Speicher gespart haben, aber unsere Performance schlechter ist? Speicher ist billig. Andererseits führt weniger Speicherverbrauch zu einer geringeren Zahl an erreichbaren Objekten und kann uns daher eine höhere Geschwindigkeit bieten.

Nachdem ich mich fragte, wie ich mir die Deduplikationsdaten ansehen könnte, erinnerte ich mich an das Flag -XX:+PrintStringDeduplicationStatistics in Java 8. In Java 9 mit Unified Logging veränderte es sich zu -Xlog:stringdedup*=debug. Jedes Mal, wenn die Deduplikation ausgelöst wird, wird eine Menge nützlicher Informationen ausgeworfen (Listing 1)

Concurrent String Deduplication (90.162s)
Concurrent String Deduplication 72.0B->24.0B(48.0B)
    avg 59.8% (90.162s, 90.162s) 0.020ms
  Last Exec: 0.020ms, Idle: 16740.738ms, Blocked: 0/0.000ms
    Inspected:               3
      Skipped:               0(  0.0%)
      Hashed:                0(  0.0%)
      Known:                 0(  0.0%)
      New:                   3(100.0%)     72.0B
    Deduplicated:            2( 66.7%)     48.0B( 66.7%)
      Young:                 2(100.0%)     48.0B(100.0%)
      Old:                   0(  0.0%)      0.0B(  0.0%)
  Total Exec: 3/1.014ms, Idle: 3/89992.409ms, Blocked: 0/0.000ms
    Inspected:            8457
      Skipped:               0(  0.0%)
      Hashed:              610(  7.2%)
      Known:              5640( 66.7%)
      New:                2817( 33.3%)     86.7K
    Deduplicated:         1810( 64.3%)     51.8K( 59.8%)
      Young:              1810(100.0%)     51.8K(100.0%)
      Old:                   0(  0.0%)      0.0B(  0.0%)
  Table
    Memory Usage: 187.7K
    Size: 4096, Min: 1024, Max: 16777216
    Entries: 6644, Load: 162.2%, Cached: 0, Added: 6645, Removed: 1
    Resize Count: 2, Shrink Threshold: 2730(66.7%),
    Grow Threshold: 8192(200.0%)
    Rehash Count: 0, Rehash Threshold: 120, Hash Seed: 0x0
    Age Threshold: 3
  Queue
    Dropped: 0 

Jedes Mal, wenn ein Young GC (auch Scavenge oder Partial GC genannt) ausgelöst wird, erhöht sich das Alter unserer Survivors. Wenn sie die Tenuring-Schwelle erreichen, werden sie von den jüngeren zu den älteren Regionen verschoben. Standardmäßig werden Strings dedupliziert, wenn sie das Alter 3 erreichen, also bei ihrem dritten Young GC. Wir wollen das nicht früher tun, denn Deduplikation kostet wertvolle CPU-Zyklen. Wenn der String nicht bis ins hohe Alter überlebt, braucht man auch nicht versuchen, Speicher zu sparen. Falls aus irgendeinem Grund der String vorzeitig zu Old befördert wird, wird er auch früher dedupliziert.

Treffen Sie Dr. Heinz Kabutz auf dem Extreme Java Camp!
Das Extreme Java Camp besteht aus zwei Intensivseminaren, die umfassendes und aktuellstes Know-how zu fortgeschrittenen Java-Themen und zu Java Concurrency Performance vermitteln. Es ist ein einzigartiges Hands-on-Training mit hervorragend strukturierten Vorträgen und einer Fülle an praktischen Übungen. Auch die erfahrensten Java-Profis werden intensiv angeregt und gefordert.

Weitere Infos gibt es auf der der Webseite des Extreme Java Camps!

Der DeduplicationExplorer

Um all das auszuprobieren, entwickelte ich meinen DeduplicationExplorer. Er wird euch am meisten nutzen, wenn ihr ihn selbst ausführt. Die Verbindung wird via telnet localhost 8080 hergestellt. Dann können Texte und Befehle an ihn gesendet werden. Der gesamte Text wird in einer ArrayList gespeichert. Das sind die Befehle, die wir unterstützen:

  • print: zeigt die Strings in der Liste, zusammen mit den Value-Array-Referenzen
  • clear: löscht die Strings aus der Liste
  • ygc: erzeugt ein Young GC
  • fgc: erzeugt ein Full GC
  • close: schließt die Verbindung

In Listing 2 ist der Code für den DeduplicationExplorer zu sehen. Ich empfehle euch, ihn selbst auszuführen.

import java.io.*;
import java.lang.management.*;
import java.lang.reflect.*;
import java.net.*;
import java.util.*;

// Java8:
//   -XX:+UseG1GC
//   -XX:+UseStringDeduplication
//   -XX:+PrintStringDeduplicationStatistics
//   -verbose:gc
// Java11:
//   -XX:+UseStringDeduplication
//   -Xlog:stringdedup*=debug
//   -verbose:gc
public class DeduplicationExplorer {
  public static void main(String... args) throws IOException {
    List<String> lines = new ArrayList<>();
    Socket socket = new ServerSocket(8080).accept();
    PrintStream out = new PrintStream(
        socket.getOutputStream(), true);
    out.println("Commands: clear, print, ygc, fgc, close");
    BufferedReader in = new BufferedReader(
        new InputStreamReader(
            socket.getInputStream()));
    String line;
    while ((line = in.readLine()) != null) {
      System.out.println(line);
      switch (line) {
        case "clear": lines.clear(); break;
        case "print": print(lines); break;
        case "ygc": youngGC(); break; // young GC
        case "fgc": System.gc(); break; // full GC
        case "close": return;
        default: lines.add(line);
      }
    }
  } 

  private static void youngGC() {
    long collectionCount = YOUNG_GC.getCollectionCount();
    do {
      // array is too big to be eliminated with escape analysis
      byte[] bytes = new byte[1024];
    } while (YOUNG_GC.getCollectionCount() == collectionCount);
  } 

  private static void print(List<String> lines) {
    System.out.println("lines:");
    lines.forEach(DeduplicationExplorer::print);
  } 

  private static void print(String line) {
    try {
      System.out.printf("\t\"%s\" - %s%n", line, VALUE.get(line));
    } catch (IllegalAccessException e) {
      throw new IllegalStateException(e);
    }
  } 

  private final static Field VALUE; 

  static {
    try {
      VALUE = String.class.getDeclaredField("value");
      VALUE.setAccessible(true);
    } catch (NoSuchFieldException e) {
      throw new Error(e);
    }
  } 

  private final static GarbageCollectorMXBean YOUNG_GC; 

  static {
    YOUNG_GC = ManagementFactory.getGarbageCollectorMXBeans()
        .stream()
        .filter(pool -> pool.getName().equals(
            "G1 Young Generation"))
        .findFirst()
        .orElseThrow(() -> new Error("Could not find G1 Young " +
            "Generation Garbage Collector MXBean"));
  }
}

Beispielsweise öffnete ich das Oracle OpenJDK 12.0.1 mit den folgenden Flags:

-XX:+UseStringDeduplication -Xlog:stringdedup*=debug -verbose:gc

Dann stellte ich die Verbindung mit telnet localhost 8080 her und sendete es:

hello
hello
hello
print

In der Ausgabe des Programms erschien Folgendes:

hello
hello
hello
print
lines:
  "hello" - [B@5d099f62
  "hello" - [B@37f8bb67
  "hello" - [B@49c2faae

Wie man sieht, hat jeder der drei Strings sein eigenes byte[]. Die Hexadezimalzahl ist der Identity Hash Code, eine zufällige Zahl, die ziemlich einzigartig ist.

Als Nächstes senden wir den Befehl fgc – Full GC. In unserem DeduplicationExplorer sehen wir das GC-Event und die Deduplikationsstatistiken. Wenn wir nun den print-Befehl senden, werden wir sehen, dass alle Strings auf das gleiche byte[] verweisen. Wenn wir die ArrayList durch den clear-Befehl leeren und dann durch fgc ein Full GC ausgeben lassen, wird das geteilte byte[] eingesammelt. Senden wir anschließend „hello“ noch dreimal und rufen wir fgc und print auf, werden wir so etwas erhalten:

fgc
    *snip* GC output and deduplication statistics *snip*
print
lines:
  "hello" - [B@2e0fa5d3
  "hello" - [B@2e0fa5d3
  "hello" - [B@2e0fa5d3

Falls der String schon in der JVM als Konstante existierte, wird das die Basis unseres geteilten byte[] sein. Lasst uns zum Beispiel clear eingeben und dann den String main dreimal senden, gefolgt von print. Wir erhalten Folgendes:

clear
main
main
main
print
lines:
  "main" - [B@5010be6
  "main" - [B@685f4c2e
  "main" - [B@7daf6ecc

Wenn wir nun fgc und print ausgeben lassen, sehen wir dies hier:

fgc
    *snip* GC output and deduplication statistics *snip*
print
lines:
  "main" - [B@1f7e245f
  "main" - [B@1f7e245f
  "main" - [B@1f7e245f

Dieses byte[] ist keines derjenigen, die wir zuvor vom BufferedReader gelesen hatten. Und wenn wir erneut clear eingeben, nochmals main senden und anschließend ein fgc und ein print ausgeben lassen, werden wir wieder das Folgende sehen:

print
lines:
  "main" - [B@1f7e245f

Da wir eine Methode namens main in unserer JVM haben, teilen sich alle Strings dessen byte[].

Young GC

Bislang haben wir uns nur um Full GC gekümmert. Allerdings habe ich auch Unterstützung für das Auslösen eines Young GC durch den Befehl ygc eingebaut. Ich bin ziemlich stolz auf diesen Code, den ich um 5 Uhr morgens im Halbschlaf in Gedanken schrieb, bevor ich wieder einschlief. Für gewöhnlich funktioniert mein im Traum geschriebener Code nicht, aber dieser tut es! Zuerst finde ich den Garbage Collector MXBean für die G1 Young Generation. Dann führe ich die Schleife aus, während die Collection Count gleich ist, und weise 1 kByte Arrays zu. Escape Analysis wird die Heap Allocation nicht entfernen, da die Arrays größer als 64 sind. Mein Traumcode ist in Listing 2 zu sehen.

private static void youngGC() {
  long collectionCount = YOUNG_GC.getCollectionCount();
  do {
    // array is too big to be eliminated with escape analysis
    byte[] bytes = new byte[1024];
  } while (YOUNG_GC.getCollectionCount() == collectionCount);
} 

private final static GarbageCollectorMXBean YOUNG_GC; 

static {
  YOUNG_GC = ManagementFactory.getGarbageCollectorMXBeans()
    .stream()
    .filter(pool -> pool.getName().equals(
      "G1 Young Generation"))
    .findFirst()
    .orElseThrow(() -> new Error("Could not find G1 Young " +
      "Generation Garbage Collector MXBean"));
}

Nun geben wir die folgenden Befehle ein:

hello
hello
hello
ygc
hello
ygc
hello
ygc
print

Jedes Mal, wenn wir ygc senden, erscheint ein „Pause Young (Normal)“ in der Konsole. Nach dem dritten ygc sehen wir, dass auch die Deduplikationsstatistik erscheint. Die Ausgabe von print sieht nun so aus:

print
lines:
  "hello" - [B@5d099f62
  "hello" - [B@5d099f62
  "hello" - [B@5d099f62
  "hello" - [B@37f8bb67
  "hello" - [B@49c2faae

Demnach wurden die ersten drei hello-Strings dedupliziert, jedoch nicht die übrigen beiden. Geben wir noch einmal ygc und print ein, wird es zu:

print
lines:
  "hello" - [B@5d099f62
  "hello" - [B@5d099f62
  "hello" - [B@5d099f62
  "hello" - [B@5d099f62
  "hello" - [B@49c2faae

Und mit dem nächsten ygc gibt print dies aus:

print
lines:
  "hello" - [B@5d099f62
  "hello" - [B@5d099f62
  "hello" - [B@5d099f62
  "hello" - [B@5d099f62
  "hello" - [B@5d099f62

Alles funktioniert so wie es soll.

-XX:+AlwaysTenure

Ein eher seltsames Flag in OpenJDK ist -XX:+AlwaysTenure. Effektiv eliminiert es die Survivor Spaces und befördert alle Survivors von Young zu Old. Obwohl ihr es nicht unbedingt in der Produktion einsetzen solltet, macht das Einschalten in unserem Experiment Spaß. Wir senden nun das Folgende:

hello
hello
hello
ygc
print

Wir werden eine ähnliche Ausgabe erhalten wie bei dem Aufruf von System.gc():

hello
hello
hello
ygc
[154.162s][info][gc] GC(0) Pause Young (Normal)
        *snip* GC output and deduplication statistics *snip*
print
lines:
  "hello" - [B@5d099f62
  "hello" - [B@5d099f62
  "hello" - [B@5d099f62

Herzliche Grüße aus Kreta
Heinz

Verwandte Themen:

Geschrieben von
Dr. Heinz Kabutz
Dr. Heinz Kabutz
Dr. Heinz Kabutz ist regelmäßiger Referent auf allen wichtigen Java-Konferenzen mit den Schwerpunkten Java Concurrency und Performance. Kabutz schreibt den beliebten „The Java Specialists’ Newsletter“, der von Zehntausenden von begeisterten Fans in über 140 Ländern gelesen wird.
Kommentare

Hinterlasse einen Kommentar

Hinterlasse den ersten Kommentar!

avatar
4000
  Subscribe  
Benachrichtige mich zu: