Explication détaillée des journaux ParallelGC-javaDidacticiel-php.cn

ParallelGC 日志详解

Paramètres de démarrage de la JVM

JAVA_OPTS = "-Xms4G -Xmx4G -Xmn2G -XX:MetaspaceSize=512M -XX:MaxMetaspaceSize=512M -XX:+UseParallelGC -XX:+PrintGCDetails -Xloggc:/home/gc.log -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC"

Copier après la connexion

Définition des paramètres de démarrage de la JVM

-XX:+PrintGCDetails : affiche des informations détaillées sur le GC, y compris l'utilisation de la mémoire tas après chaque garbage collection et l'état avant et après la collecte.
-Xloggc:/home/gc.log : enregistrez les journaux GC dans le fichier /home/gc.log au lieu de les afficher sur la console. Cela permet d'analyser les journaux après l'exécution de l'application.
-XX:+PrintGCDateStamps : ajoutez un horodatage à chaque enregistrement du journal GC pour faciliter la visualisation de l'heure à laquelle le garbage collection a eu lieu.
-XX:+PrintGCTimeStamps : ajoutez le temps écoulé après le démarrage de la JVM à chaque journal GC, en secondes.
-XX:+PrintHeapAtGC : Imprimer l'état détaillé du tas avant et après le garbage collection, y compris l'allocation mémoire de chaque génération (jeune génération, ancienne génération, métaespace).
-XX:+UseParallelGC : utilisez Parallel GC (parallel garbage collector) pour améliorer les performances en exécutant le garbage collection en parallèle avec plusieurs threads.

Extrait de journal GC

OpenJDK 64-Bit Server VM (25.342-b07) for linux-amd64 JRE (1.8.0_342-b07), built on Jul 16 2022 09:19:19 by "openjdk" with gcc 4.4.7 20120313 (Red Hat 4.4.7-23)
Memory: 4k page, physical 8388608k(8386904k free), swap 0k(0k free)
CommandLine flags: -XX:CompressedClassSpaceSize=528482304 -XX:InitialHeapSize=4294967296 -XX:MaxHeapSize=4294967296 -XX:MaxMetaspaceSize=536870912 -XX:MaxNewSize=2147483648 -XX:MetaspaceSize=536870912 -XX:NewSize=2147483648 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC

2024-09-24T10:43:44.094+0800: 21.703: Total time for which application threads were stopped: 0.0015655 seconds, Stopping threads took: 0.0000978 seconds
{Heap before GC invocations=11 (full 0):
 PSYoungGen      total 1494528K, used 1466389K [0x0000000790800000, 0x00000007f0800000, 0x00000007f0800000)
  eden space 1414656K, 100% used [0x0000000790800000,0x00000007e6d80000,0x00000007e6d80000)
  from space 79872K, 64% used [0x00000007eba00000,0x00000007eec85748,0x00000007f0800000)
  to   space 78336K, 0% used [0x00000007e6d80000,0x00000007e6d80000,0x00000007eba00000)
 ParOldGen       total 2621440K, used 72408K [0x00000006f0800000, 0x0000000790800000, 0x0000000790800000)
  object space 2621440K, 2% used [0x00000006f0800000,0x00000006f4eb60e0,0x0000000790800000)
 Metaspace       used 114761K, capacity 120350K, committed 120576K, reserved 1155072K
  class space    used 13324K, capacity 14260K, committed 14336K, reserved 1048576K
2024-09-24T10:43:44.149+0800: 21.759: [GC (Allocation Failure) [PSYoungGen: 1466389K->41915K(1492992K)] 1538798K->152295K(4114432K), 0.0591035 secs] [Times: user=0.16 sys=0.01, real=0.06 secs]
Heap after GC invocations=11 (full 0):
 PSYoungGen      total 1492992K, used 41915K [0x0000000790800000, 0x00000007f0800000, 0x00000007f0800000)
  eden space 1414656K, 0% used [0x0000000790800000,0x0000000790800000,0x00000007e6d80000)
  from space 78336K, 53% used [0x00000007e6d80000,0x00000007e966ee58,0x00000007eba00000)
  to   space 78336K, 0% used [0x00000007ebb80000,0x00000007ebb80000,0x00000007f0800000)
 ParOldGen       total 2621440K, used 110380K [0x00000006f0800000, 0x0000000790800000, 0x0000000790800000)
  object space 2621440K, 4% used [0x00000006f0800000,0x00000006f73cb088,0x0000000790800000)
 Metaspace       used 114761K, capacity 120350K, committed 120576K, reserved 1155072K
  class space    used 13324K, capacity 14260K, committed 14336K, reserved 1048576K
}
2024-09-24T10:43:44.209+0800: 21.818: Total time for which application threads were stopped: 0.0593724 seconds, Stopping threads took: 0.0000333 seconds


{Heap before GC invocations=906 (full 2):
 PSYoungGen      total 2065920K, used 2041627K [0x0000000760800000, 0x00000007e0800000, 0x00000007e0800000)
  eden space 2034688K, 100% used [0x0000000760800000,0x00000007dcb00000,0x00000007dcb00000)
  from space 31232K, 22% used [0x00000007de980000,0x00000007df046e10,0x00000007e0800000)
  to   space 31232K, 0% used [0x00000007dcb00000,0x00000007dcb00000,0x00000007de980000)
 ParOldGen       total 2097152K, used 2080736K [0x00000006e0800000, 0x0000000760800000, 0x0000000760800000)
  object space 2097152K, 99% used [0x00000006e0800000,0x000000075f7f8060,0x0000000760800000)
 Metaspace       used 176015K, capacity 189742K, committed 191104K, reserved 1218560K
  class space    used 19024K, capacity 21351K, committed 21632K, reserved 1048576K
2024-09-24T14:14:45.047+0800: 11571.644: [GC (Allocation Failure) [PSYoungGen: 2041627K->26414K(2061312K)] 4122363K->2109278K(4158464K), 0.0208053 secs] [Times: user=0.07 sys=0.00, real=0.02 secs]
Heap after GC invocations=906 (full 2):
 PSYoungGen      total 2061312K, used 26414K [0x0000000760800000, 0x00000007e0800000, 0x00000007e0800000)
  eden space 2034688K, 0% used [0x0000000760800000,0x0000000760800000,0x00000007dcb00000)
  from space 26624K, 99% used [0x00000007dcb00000,0x00000007de4cba70,0x00000007de500000)
  to   space 33792K, 0% used [0x00000007de700000,0x00000007de700000,0x00000007e0800000)
 ParOldGen       total 2097152K, used 2082863K [0x00000006e0800000, 0x0000000760800000, 0x0000000760800000)
  object space 2097152K, 99% used [0x00000006e0800000,0x000000075fa0be58,0x0000000760800000)
 Metaspace       used 176015K, capacity 189742K, committed 191104K, reserved 1218560K
  class space    used 19024K, capacity 21351K, committed 21632K, reserved 1048576K
}
{Heap before GC invocations=907 (full 3):
 PSYoungGen      total 2061312K, used 26414K [0x0000000760800000, 0x00000007e0800000, 0x00000007e0800000)
  eden space 2034688K, 0% used [0x0000000760800000,0x0000000760800000,0x00000007dcb00000)
  from space 26624K, 99% used [0x00000007dcb00000,0x00000007de4cba70,0x00000007de500000)
  to   space 33792K, 0% used [0x00000007de700000,0x00000007de700000,0x00000007e0800000)
 ParOldGen       total 2097152K, used 2082863K [0x00000006e0800000, 0x0000000760800000, 0x0000000760800000)
  object space 2097152K, 99% used [0x00000006e0800000,0x000000075fa0be58,0x0000000760800000)
 Metaspace       used 176015K, capacity 189742K, committed 191104K, reserved 1218560K
  class space    used 19024K, capacity 21351K, committed 21632K, reserved 1048576K
2024-09-24T14:14:45.068+0800: 11571.665: [Full GC (Ergonomics) [PSYoungGen: 26414K->0K(2061312K)] [ParOldGen: 2082863K->300700K(2097152K)] 2109278K->300700K(4158464K), [Metaspace: 176015K->174750K(1218560K)], 0.6404574 secs] [Times: user=1.88 sys=0.00, real=0.64 secs]
Heap after GC invocations=907 (full 3):
 PSYoungGen      total 2061312K, used 0K [0x0000000760800000, 0x00000007e0800000, 0x00000007e0800000)
  eden space 2034688K, 0% used [0x0000000760800000,0x0000000760800000,0x00000007dcb00000)
  from space 26624K, 0% used [0x00000007dcb00000,0x00000007dcb00000,0x00000007de500000)
  to   space 33792K, 0% used [0x00000007de700000,0x00000007de700000,0x00000007e0800000)
 ParOldGen       total 2097152K, used 300700K [0x00000006e0800000, 0x0000000760800000, 0x0000000760800000)
  object space 2097152K, 14% used [0x00000006e0800000,0x00000006f2da7140,0x0000000760800000)
 Metaspace       used 174750K, capacity 187618K, committed 191104K, reserved 1218560K
  class space    used 18827K, capacity 20997K, committed 21632K, reserved 1048576K
}

Copier après la connexion

Temps de pause de l'application

Pendant le processus GC, tous les threads de l'application sont suspendus, ce que l'on appelle l'événement "Stop-The-World" (STW). Le temps de pause affecte directement les performances et la réactivité de l'application.

Exemple de journal :

2024-09-24T10:43:44.094+0800: 21.703: Total time for which application threads were stopped: 0.0015655 seconds, Stopping threads took: 0.0000978 seconds

Copier après la connexion

Durée totale pendant laquelle les threads de l'application ont été arrêtés :

La durée totale pendant laquelle le thread de l'application a été suspendu, ici est de 0,0015655 secondes (~1,57 millisecondes).

L'arrêt des discussions a pris :

Le temps passé à mettre le fil en pause, ici 0,0000978 secondes (environ 0,098 millisecondes).

GC (GC Mineur)

Exemple de journal

2024-09-24T10:43:44.149+0800: 21.759: [GC (Allocation Failure) [PSYoungGen: 1466389K->41915K(1492992K)] 1538798K->152295K(4114432K), 0.0591035 secs]

Copier après la connexion

Type GC : GC mineur, déclenché par un échec d'allocation de mémoire (Allocation Failure).
Changements de jeune génération : réduit de 1466389K à 41915K, capacité totale 1492992K.
Changement total de la mémoire tas : de 1538798K à 152295K, capacité totale 4114432K.
Temps pris : 0,0591035 secondes (environ 59 millisecondes).

GC complet

Exemple de journal :

2024-09-24T14:14:45.068+0800: 11571.665: [Full GC (Ergonomics) [PSYoungGen: 26414K->0K(2061312K)] [ParOldGen: 2082863K->300700K(2097152K)] 2109278K->300700K(4158464K), [Metaspace: 176015K->174750K(1218560K)], 0.6404574 secs]

Copier après la connexion

Type GC : Full GC, déclenché par le mécanisme adaptatif JVM (Ergonomie).
Changement de jeune génération : de 26414K à 0K, indiquant que la jeune génération a été entièrement recyclée.
Changements d'ancienne génération : réduit de 2082863K à 300700K, libérant beaucoup de mémoire.
Changement total de la mémoire tas : de 2109278K à 300700K, capacité totale 4158464K.
Changement de métaespace : réduit de 176015K à 174750K.
Temps pris : 0,6404574 secondes (environ 640 millisecondes).

État détaillé de la mémoire du tas

En raison de l'utilisation du paramètre -XX:+PrintHeapAtGC, le journal GC imprimera l'état détaillé de la mémoire tas avant et après chaque GC, y compris la capacité et l'utilisation de chaque zone mémoire.

Exemple de journal :

Heap before GC invocations=11 (full 0):
 PSYoungGen      total 1494528K, used 1466389K [0x0000000790800000, 0x00000007f0800000, 0x00000007f0800000)
  eden space 1414656K, 100% used [0x0000000790800000,0x00000007e6d80000,0x00000007e6d80000)
  from space 79872K, 64% used [0x00000007eba00000,0x00000007eec85748,0x00000007f0800000)
  to   space 78336K, 0% used [0x00000007e6d80000,0x00000007e6d80000,0x00000007eba00000)
 ParOldGen       total 2621440K, used 72408K [0x00000006f0800000, 0x0000000790800000, 0x0000000790800000)
  object space 2621440K, 2% used [0x00000006f0800000,0x00000006f4eb60e0,0x0000000790800000)
 Metaspace       used 114761K, capacity 120350K, committed 120576K, reserved 1155072K
  class space    used 13324K, capacity 14260K, committed 14336K, reserved 1048576K

Copier après la connexion

PSYoungGen (jeune génération) :
- total (capacité totale) : 1494528K.
- utilisé : 1466389K.
- Espace Eden (zone Eden) : capacité 1414656K, taux d'utilisation 100%.
- depuis l'espace (zone Survivant) : Capacité 79872K, taux d'utilisation 64%.
- vers l'espace (Zone Survivant) : capacité 78336K, inutilisée.
ParOldGen (ancienne génération) :
- total (capacité totale) : 2621440K.
- utilisé : 72408K, le taux d'utilisation est d'environ 2 %.
Métaespace :
- utilisé : 114761K.
- capacité : 120350K.

Correspondance entre les paramètres de démarrage de la JVM et les logs GC

En raison de la définition manuelle des paramètres de démarrage de la JVM, les journaux GC contiennent des informations plus détaillées qui peuvent faciliter une analyse approfondie :

Allocation et utilisation de la mémoire :
- Avec -XX:+PrintHeapAtGC, vous pouvez afficher l'état de la mémoire du tas avant et après chaque GC et comprendre l'allocation de mémoire et l'utilisation de chaque zone.
Informations d'horodatage :
- -XX:+PrintGCDateStamps et -XX:+PrintGCTimeStamps fournissent des informations temporelles précises pour faciliter l'analyse des points temporels et des intervalles des événements GC.
Détails de l'événement GC :
- -XX:+PrintGCDetails affiche des informations détaillées telles que le type d'événement GC, la raison du déclenchement, l'état de recyclage de la mémoire et la consommation de temps.

Ce qui précède est le contenu détaillé de. pour plus d'informations, suivez d'autres articles connexes sur le site Web de PHP en chinois!