Penjelasan terperinci tentang log ParallelGC

Parameter permulaan 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"

Menetapkan parameter permulaan JVM

• -XX:+PrintGCDetails: Output maklumat terperinci GC, termasuk penggunaan memori timbunan selepas setiap kutipan sampah dan status sebelum dan selepas kutipan.
• -Xloggc:/home/gc.log: Simpan log GC ke fail /home/gc.log dan bukannya keluarkan ke konsol. Ini membolehkan log dianalisis selepas aplikasi dijalankan.
• -XX:+PrintGCDateStamps: Tambahkan cop tarikh pada setiap rekod log GC untuk memudahkan melihat masa pengumpulan sampah berlaku.
• -XX:+PrintGCTimeStamps: Tambahkan masa berlalu selepas permulaan JVM pada setiap log GC, dalam beberapa saat.
• -XX:+PrintHeapAtGC: Cetak status terperinci timbunan sebelum dan selepas kutipan sampah, termasuk peruntukan memori setiap generasi (generasi muda, generasi lama, metaspace).
• -XX:+UseParallelGC: Gunakan GC Parallel (pengumpul sampah selari) untuk meningkatkan prestasi dengan melaksanakan kutipan sampah selari dengan berbilang benang.

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

Masa jeda permohonan

Semasa proses GC, semua rangkaian permohonan digantung, yang dipanggil acara "Stop-The-World" (STW). Masa jeda secara langsung mempengaruhi prestasi dan responsif aplikasi.

Contoh log:

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

Jumlah masa untuk urutan aplikasi dihentikan:

• Jumlah masa urutan aplikasi digantung, berikut ialah 0.0015655 saat (~1.57 milisaat).

Menghentikan urutan diambil:

• Masa yang diluangkan untuk menjeda urutan, di sini 0.0000978 saat (kira-kira 0.098 milisaat).

GC (GC Kecil)

Contoh log

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

• Jenis GC: GC kecil, dicetuskan oleh kegagalan peruntukan memori (Kegagalan Peruntukan).
• Perubahan generasi muda: dikurangkan daripada 1466389K kepada 41915K, jumlah kapasiti 1492992K.
• Jumlah perubahan dalam ingatan timbunan: daripada 1538798K kepada 152295K, jumlah kapasiti 4114432K.
• Masa yang diambil: 0.0591035 saat (kira-kira 59 milisaat).

GC Penuh

Contoh log:

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]

• Jenis GC: GC penuh, dicetuskan oleh mekanisme penyesuaian JVM (Ergonomik).
• Perubahan generasi muda: daripada 26414K kepada 0K, menunjukkan bahawa generasi muda telah dikitar semula sepenuhnya.
• Perubahan generasi lama: dikurangkan daripada 2082863K kepada 300700K, membebaskan banyak memori.
• Jumlah perubahan dalam ingatan timbunan: daripada 2109278K kepada 300700K, jumlah kapasiti 4158464K.
• Perubahan metaspace: dikurangkan daripada 176015K kepada 174750K.
• Masa yang diambil: 0.6404574 saat (kira-kira 640 milisaat).

Status terperinci ingatan timbunan

Disebabkan oleh penggunaan parameter -XX:+PrintHeapAtGC, log GC akan mencetak status terperinci memori timbunan sebelum dan selepas setiap GC, termasuk kapasiti dan penggunaan setiap kawasan memori.

Contoh log:

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

• PSYoungGen (generasi muda):

  • jumlah (jumlah kapasiti): 1494528K.
  • digunakan: 1466389K.
  • ruang eden (kawasan Eden): kapasiti 1414656K, kadar penggunaan 100%.
  • dari angkasa (kawasan yang terselamat): Kapasiti 79872K, kadar penggunaan 64%.
  • ke angkasa (kawasan yang terselamat): kapasiti 78336K, tidak digunakan.

• ParOldGen (generasi lama):

  • jumlah (jumlah kapasiti): 2621440K.
  • digunakan: 72408K, kadar penggunaan adalah kira-kira 2%.

• Metaspace:

  • digunakan: 114761K.
  • kapasiti: 120350K.

Korespondensi antara parameter permulaan JVM dan log GC

Disebabkan menetapkan parameter permulaan JVM secara manual, log GC mengandungi maklumat lebih terperinci yang boleh membantu analisis mendalam:

• Peruntukan dan penggunaan memori:

  • Dengan -XX:+PrintHeapAtGC, anda boleh melihat status memori timbunan sebelum dan selepas setiap GC dan memahami peruntukan memori dan penggunaan setiap kawasan.

• Maklumat cap masa:

  • -XX:+CetakGCDateStamps dan -XX:+PrintGCTimeStamps memberikan maklumat masa yang tepat untuk memudahkan analisis titik masa dan selang peristiwa GC.

• Butiran acara GC:

  • -XX:+PrintGCDetails mengeluarkan maklumat terperinci seperti jenis peristiwa GC, sebab pencetus, status kitar semula memori dan penggunaan masa.

Atas ialah kandungan terperinci Penjelasan terperinci tentang log ParallelGC. Untuk maklumat lanjut, sila ikut artikel berkaitan lain di laman web China PHP!