Dieser Artikel beschreibt ausgewählte JVM-Tuning-Probleme mit ausgewählten JVM-Flags. Diese Behandlungen ermöglichten es, die unten beschriebene Anwendung zu optimieren. Ich garantiere jedoch nicht, dass sie in anderen Anwendungen funktionieren. Verwenden Sie keine JVM-Flags, wenn Sie nicht wissen, zu welchen Auswirkungen sie führen können!
Was ist Biased Lock?
Auszug aus der Oracle-Dokumentation:
Was ist Biased Lock
-XX:+UseBiasedLockingEnables a technique for improving the performance of uncontended synchronization. An object is "biased" toward the thread which first acquires its monitor via a monitorenter bytecode or synchronized method invocation; subsequent monitor-related operations performed by that thread are relatively much faster on multiprocessor machines. Some applications with significant amounts of uncontended synchronization may attain significant speedups with this flag enabled; some applications with certain patterns of locking may see slowdowns, though attempts have been made to minimize the negative impact.
Aktueller Status
Flagge -XX:+UseBiasedLocking ist in JDK 8-14 standardmäßig aktiviert, aber in JDK 15 bereits deaktiviert und nicht empfohlen (JA 374).
Warum kann eine solche Optimierung schädlich sein?
Zusätzlich zu dem bereits in der Dokumentation erwähnten Problem, d. h.:
(...) some applications with certain patterns of locking may see slowdowns (...)
Es gibt noch ein anderes Problem, das in Betracht gezogen werden muss. Ein voreingenommener Sperrrückruf ist eine Safepoint-Operation, für deren Ausführung eine Stop-the-World-Phase erforderlich ist. Diese Phase unterbricht die Arbeit der einzelnen Threads der Anwendung, was sich nachteilig auswirken kann.
JVM protokollieren
Der Unified Logger ermöglicht es Ihnen, Safepoint-Operationen mit xlog:Safepoint zu verfolgen, aber biased lock können auch mit xlog:BiasedLocking verfolgt werden.
[safepoint ] Application time: 0.1950250 seconds [safepoint ] Entering safepoint region: RevokeBias [biasedlocking ] Revoking bias with potentially per-thread safepoint: [biasedlocking ] Revoking bias of object 0x00000007efbe15d0, mark 0x00007fa06805d305, type org.springframework...<removed, sorry>, prototype header 0x0000000000000305, allow rebias 0, requesting thread 0x00007fa068064800 [biasedlocking ] Revoked bias of object biased toward live thread (0x00007fa06805d000) [biasedlocking ] Revoked bias of currently-unlocked object [safepoint ] Leaving safepoint region [safepoint ] Total time for which application threads were stopped: 0.0003424 seconds, Stopping threads took: 0.0000491 seconds
In diesem Log kannst du sehen, welche Objekte gesperrt waren biased lock, und wie viele Stop-the-World-Etappen du abschließen musstest, um abzusagen biased lock. Dies kann in einem Kreisdiagramm übersichtlich dargestellt werden. In der folgenden Grafik sehen wir Prozentsatz der Safepoint-Operationen.
Der Prozentsatz selbst ist normalerweise nicht wichtig — es lohnt sich, einen Blick auf die Ausführungsdauer einer bestimmten Phase zu werfen. Basierend auf dem Safepoints-Protokoll können Sie auch ein Kreisdiagramm für die einzelnen Ausführungszeiten erstellen Betrieb Safepoint.
Wenn wir numerische Daten bevorzugen, kann das Protokoll tabellarisch dargestellt werden:
In der fraglichen Klageschrift ist die Beschwerde biased lock erfordert:
(count(RevokeBias) + count(BulkRevokeBias)) / (totalCount)
Wenn wir die numerischen Daten ersetzen, erhalten wir:
(254389 + 11815) / 367681 = 72%
72% aller Phasen von Stop-the-World. Die Ausführungszeit dieser Phasen war wie folgt:
(totalTime(RevokeBias) + totalTime(BulkRevokeBias)) / (totalTimeOfSTW)
Wenn wir die numerischen Daten ersetzen, erhalten wir:
(51419,93 + 24277,09) / 523393,73 = 14%
14% Zeit für alle Stop-the-World-Phasen (ohne Zeit bis Safepoint).
Kontext: App optimiert
- JDK 11u4 Orakel
- SpringBoot mit integriertem Tomcat
- Webanwendung des Bundesstaats
- Mehrere Instanzen (20) auf jeweils 4 vCPUs
- Größe des Haufens: 8 GB
- Spitzennutzung von 17 bis 18 Uhr (Mo bis Fr)
- In der Anwendung gibt es fast keine Thread-Synchronisierung - die meisten Threads werden in Frameworks und JDK synchronisiert.
- Von 17:00 bis 18:00 Uhr arbeitet er ca. 200 Themen Java.
Erwartungen
Was erwarte ich von einer App mit deaktivierter voreingenommener Sperre:
- Ca. 72% weniger Stop-the-World-Phasen
- Ich gehe davon aus, dass die Arbeitszeit des Benutzers in der Anwendung um ca. 2% reduziert werden kann.
- Übrigens kann es: weniger Speicherverbrauch, weil es keinen Bug gibt JDK-8240723.
Zustand vor der Abstimmung: Spitzenauslastung
Daten zur Spitzenauslastung der Anwendungen ab Tag 1 für 4 Knoten:
Widerruf biased lock erfordert 14% alle Phasen von Stop-the-World.
Wie sieht die App aus der Sicht des Nutzers aus? Die durchschnittliche Bearbeitungszeit von Anfragen zu Spitzenzeiten beträgt ca. 410 ms.
Tuning
Das Optimieren einer Anwendung besteht einfach darin, eine bestimmte Option mithilfe von JVM-Argumenten zu deaktivieren:
-XX:-UseBiasedLocking
Zustand nach dem Tuning: Spitzenauslastung
Daten zur Spitzenauslastung der Anwendungen ab Tag 1 für 4 Knoten:
Wie sieht die App aus der Sicht des Nutzers aus? Die durchschnittliche Bearbeitungszeit von Anfragen zu Spitzenzeiten beträgt ca. 397 ms. Vergleich der schlechtesten Ergebnisse auf Knoten ohne biased lock mit den besten Ergebnissen von Knoten mit aktiviertem biased lock daraus folgt, dass der Knoten nach dem Tuning aus der Sicht des Benutzers unter 2% schneller. Die Ergebnisse wurden über einen Zeitraum von 1 Woche aufgezeichnet.
Befunde
- Verringerung der Anzahl der Stop-the-World-Phasen um 71%.
- Die Ausführungszeit der Stop-the-World-Phase wurde reduziert um 10%.
- Die Arbeitszeit des Benutzers in der Anwendung wurde um mindestens reduziert 2% (2-8%, im Durchschnitt etwa 3%).
- Der JVM-Prozess beanspruchte auf Computern mit deaktivierter Funktion weniger RAM biased lock.
Zusammenfassung
Dies ist die fünfte Anwendung, bei der ich die biased lock auf JVM 11 deaktiviert habe. In vier Fällen verbesserte die Deaktivierung der Sperre die Leistung In einem Fall ist die Produktivität gesunken..
