“This is the 8th day of my participation in the Gwen Challenge.

The JVM runtime parameters were covered in the previous article, followed by Java GC logging.

1. GC log parameters

-verbose:gc

Output GC log information, to standard output by default

-XX:+PrintGC

Equivalent to -verbose: GC turns on simplified GC logging

-XX:+PrintGCDetails

The detailed log of memory collection is printed when garbage collection occurs, and the current allocation of memory regions is printed when the process exits

-XX:+PrintGCTimeStamps

Outputs the timestamp when GC occurs

-XX:+PrintGCDateStamps

Outputs the timestamp when GC occurs (in the form of a date, such as 2021-06-15T14:23:59.234+0800)

-XX:+PrintHeapAtGC

The heap information is printed before and after each GC

-Xloggc:<file>

Write the GC log to a file instead of printing it to standard output

GC log format

The GC classification

In the implementation of HotSpot VM, the GC is divided into two main types according to the collection region: Parial GC and Full GC.

Partial collection: Garbage collection that does not collect the entire Java heap. Which are divided into:

  1. Minor GC/Young GC: This is only garbage collection for the new generation (Eden\S0,S1)
  2. Major GC (Old GC) : Just Old GC.
    • Currently, only the CMS GC collects old-time behavior separately.
    • Note that there are many times when the Major GC is confused with the Full GC, and you need to be specific about whether it is old age or whole heap.
  3. Mixed GC: Collects garbage from the entire new generation and part of the old generation.
    • Currently, only the G1 GC has this behavior

Full GC: Collects the entire Java heap and method area garbage collection.

What conditions trigger the Full GC?

  1. There is not enough space in the old era
  2. Method area space is insufficient
  3. Call system.gc () explicitly
  4. The average size of data entered by the Minor GC into the old decade is greater than the memory available for the old decade
  5. Large objects go directly to the old age, where there is not enough space available

GC Log Classification

MinorGC

Allocation Failure indicates that this time GC is caused because there is not enough space in the young generation to store new data.

FullGC

GC log structure analysis

Garbage collector

  1. Using Serial collector the name of the New Generation is Default New Generation, so “[DefNew” is displayed.
  2. – The name of the collector using ParNew in the New Generation will change to “[ParNew”, meaning “Parallel New Generation”
  3. The use of the Parallel insane collector, known as the “[PSYoungGen” insane, is used in JDK1.7
  4. Using the Parallel Old Generation collector in the Old Generation name is “[ParOldGen”
  5. Using the G1 collector, it shows “garbage-first heap”

Before and after GC

The GC log format is: Memory usage before GC -> memory usage after GC [PSYoungGen: 5986K -> 696K] 5986K -> 704K (9216K)

In parentheses: young heap size before GC collection, size after GC collection, (total young heap size)

Parentheses: GC collects the size of the previous young generation and the old generation, and the size after the collection, (total size of the young generation and the old generation)

The GC time

There are three times in the GC log: User, SYS, and real

  1. User: The time taken by the process to execute user-mode code (outside the core). This is the actual CPU time used to execute this process, not counting other processes and the time this process blocked. In the case of garbage collection, represents the total CPU time used by the GC thread to execute.
  2. Sys: CPU time consumed by a process in kernel mode, that is, the CPU time used by the kernel to perform system mobilization or wait for system events
  3. Real: The clock time from start to finish of the program. This time includes the time slice used by other processes and the time the process is blocked (such as waiting for I/O to complete). For parallel GC, this number should be close to (user time + system time) divided by the number of threads used by the garbage collector.

Because of the multi-core nature of GC events, real time is less than sys + User time because multiple threads are doing GC concurrently. If real > sys + user is used, your application may have the following problems: heavy IO load or insufficient CPU.

Minor GC log parsing

2020-11-20T17:19:43.265- 0800:0.822: [GC (ALLOCATION FAILURE) [PSYOUNGGEN:76800K->8433K(89600K)] 76800K->8449K(294400K), 0.0088371 SECS] [TIMES:USER=0.02 SYS=0.01, REAL=0.01 SECS]
Copy the code

The 2020-11-20 T17: parts. 265-0800

The event date format is 2013-05-04T21:53:59.234+0800

0.822

The number of seconds that have elapsed since the Java virtual machine started when GC occurred

[GC (Allocation Failure)

A garbage collection occurs, and this is a Minor GC. It does not distinguish between new generation GC and old generation GC. The contents in parentheses are the causes of GC. The reason for this Allocation Failure is that there is not enough area in the new generation to store the data that needs to be allocated.

[PSYoungGen:76800K->8433K(89600K)]

  1. PSYoungGen: Indicates the region in which GC occurs, and the region name is closely related to the GC collector in use
    • Serial collector: Default New Generation Displays DefNew
    • ParNew collector: ParNew
    • Parallel Scanvenge collector: PSYoung
    • The old generation and the new generation are also related to the collector name
  2. 76800K->8433K(89600K) : Used capacity of the memory region before GC -> Capacity of the region after GC (total capacity of the region)
    • If it is a new generation, the total capacity will show 9/10 of the entire memory of the new generation, i.e. Eden + from/to area
    • If it is the old age total capacity is the total memory size, no change

76800K->8449K(294400K)

After displaying the size of the region’s GC, the size of the entire heap is displayed: used size of the heap before GC -> total size of the GC heap (total size of the heap) Total size of the heap = 9/10 New generation + old generation < the size of the initialized memory

, 0.0088371 secs]

The time, in seconds, taken for the entire GC

[Times: user sys = = 0.02 0.01, real = 0.01 secs]

  1. User: indicates the time spent by the CPU in user mode
  2. Sys: Refers to the time it takes the CPU to operate in kernel mode
  3. Real: Refers to the total time spent in this GC event

Full GC log profiling

2020-11-20T17:19:43.794- 0800:1.351: [FULL GC (METADATA THRESHOLD) [PSYOUNGGEN: 10082k->0k(89600k)] [PAROLDGEN: 32k->9638k(204800k)] 10114k->9638k(294400k), [METASPACE: 20158k->20156k(1067008k)], 0.0285388 SECS] [TIMES: USER=0.11, SYS=0.00, REAL=0.03 SECS]
Copy the code

The 2020-11-20 T17: parts. 794-0800

The format of the time and date is 2013-05-04T21:53:59.234+0800

1.351

The number of seconds that have elapsed since the Java virtual machine started when GC occurred

Full GC (Metadata GC Threshold)

  1. A garbage collection has occurred, and this is a FULL GC. It does not distinguish between Cenozoic GC and old GC
  2. The Metadata GC Threshold is the Metaspace section is out of use.
    • Full GC(Ergonomics): GC caused by JVM adaptive tuning
    • Full GC(System): The system.gc () method is called

[PSYoungGen: 10082k->0k(89600k)]

  1. PSYoungGen: Indicates the region in which GC occurs, and the region name is closely related to the GC collector in use
    • Serial collector: Default New Generation Displays DefNew
    • ParNew collector: ParNew
    • Parallel Scanvenge collector: PSYoung
    • The old generation and the new generation are also related to the collector name
  2. 10082K -> 0K (89600K) : Used capacity of the memory region before GC -> Capacity of the memory region after GC (total capacity of the region)
    • If it is a new generation, the total capacity will show 9/10 of the entire memory of the new generation, i.e. Eden + from/to area
    • If it is the old age total capacity is the total memory size, no change

[ParOldGen: 32k->9638k(204800k)]

No GC occurred in the old age region because this GC was caused by Metaspace

10114k->9638k(294400k)

After displaying the size of the region’s GC, the size of the entire heap is displayed: used size of the heap before GC -> total size of the GC heap (total size of the heap) Total size of the heap = 9/10 New generation + old generation < the size of the initialized memory

[Metaspace: 20158k->20156k(1067008k)]

Metaspace GC reclaims 2k space

0.0285388 secs

The time, in seconds, taken for the entire GC

[Times: user= 0.00, sys=0.00, real= 0.03secs]

  1. User: indicates the time spent by the CPU in user mode
  2. Sys: Refers to the time it takes the CPU to operate in kernel mode
  3. Real: Refers to the total time spent in this GC event

GC log analysis tool

GC log visualization tools GCeasy and GCviewer are used to analyze GC logs. Using the GC log visualization analysis tool, we can easily see the memory usage of JVM generations, the number of garbage collections, the reason for garbage collection, the amount of garbage collection time, throughput, and so on, which are very useful when we tune the JVM.

If you want to save GC logs to a file, you can use the following parameter: -xloggc :/path/to/gc.log then you can use some tools to analyze the GC logs.

GCeasy

GCeasy is an excellent online GC log analysis site

Gceasy is a…

GCViewer

Here’s an online GC log analyzer, and here’s an offline VERSION of GCViewer.

GCViewer is a free, open source analysis gadget for visually viewing garbage collector logs generated by SUN/Oracle,IBM,HP, and BEA Java virtual machines.

GCViewer is used to visualize Java VM options -verbose: GC and. NET generated data -xloggc :

. It also calculates performance metrics related to garbage collection (throughput, accumulated pauses, most frequent pauses, and so on).

Download the GCViewer tool

  1. Download the source code: github.com/chewiebug/G…
  2. Run the download version: github.com/chewiebug/G…

Just double-click gcView-1.3x.jar or run the Java JAR gcView-1.3x.jar (which requires running Java 1.8 VM) to launch gCViewer (GUI)

Four,

This section introduces Java GC log analysis, GC log parameters, GC log format, and GC log analysis tools.

Welcome everyone to pay attention to the public account (MarkZoe) to learn from each other and communicate with each other.