21 Gc Log Reading and Analysis Bonus Chapter Visualization Tools

21 GC Log Reading and Analysis Bonus Chapter- Visualization Tools #

Through our previous study, we found that GC logs are often large in size, and analyzing them manually is very time-consuming. Due to the complexity of various GC algorithms, their log formats are not always compatible with each other.

Is there any tool to reduce our repetitive work? Surely, there are existing solutions. For example, GCEasy, GCViewer, and so on.

In this section, we will introduce some tools that can help us achieve more with less effort.

GCEasy Tool #

GCEasy is developed and supported by the company Tier1app. This company mainly provides three analysis tools:

  • GCEasy, accessible at https://gceasy.io/, is an online GC log analysis tool that supports various versions of GC log formats.
  • FastThread, official website at https://fastthread.io/, is a thread analysis tool, which we will discuss in detail later.
  • HeapHero, official website at https://heaphero.io/, is, as the name suggests, a Heap Dump analysis tool.

Among these tools, GCEasy can be used to analyze and locate GC and memory performance issues and supports the following three modes:

  • Online analysis on the official website (free), which we will mainly introduce in this section.
  • API interface call (paid plan).
  • Local installation (enterprise paid plan).

Feature Introduction #

As a commercial product, GCEasy naturally has excellent analysis capabilities and result reports.

  • It can analyze GC logs and JStat logs.
  • It supports file upload (free).
  • It supports pasting log text (free).
  • It supports downloading result reports (paid plan).
  • It supports sharing links (free).
  • It supports API calls (paid plan).
  • The enterprise version supports local installation (enterprise paid plan).
  • The paid plan can be free to try: that is, the result can be downloaded for trial now.

Test Case #

Here, we will still use the example code demonstrated earlier, with some minor modifications to make it run for about 30 seconds.

Assuming the program is started with the following parameters:

-XX:+UseParallelGC
-Xms512m
-Xmx512m
-Xloggc:gc.demo.log
-XX:+PrintGCDetails
-XX:+PrintGCDateStamps

Then, we will get a GC log file gc.demo.log.

Online Usage Example #

Open the page https://gceasy.io/, choose to upload a file or paste text:

img

For example, use the gc.demo.log file we generated earlier, and then click the “Analyze” button on the page to generate an analysis report.

If the log content is large, we can also paste or upload a portion of GC logs for analysis.

1. Overall Report

img

It is detected that there are memory issues.

2. JVM Memory Size Analysis

img

This provides detailed charts on memory allocation.

3. Distribution of GC Pause Time

Key performance indicators: average GC pause time is 45.7ms, maximum pause time is 70.0ms. The vast majority of GC pause times fall between 30~60ms, accounting for 89%.

img

4. Memory Usage Statistics After GC

Heap memory usage after GC execution.

img

5. Summary Statistics of GC Situations

It can be seen that Full GC is the main cause of performance impact.

img

img

6. Memory Allocation Speed

The faster the memory allocation speed, the more frequently objects are created in our program.

img

7. Information about Memory Leaks, Long Pauses, Safe Points, etc.

No memory leaks were detected.

img

8. Summary of GC Causes

We can see the reasons for GC occurrences, among which 566 instances were self-adjusted by the GC strategy (Ergonomics), and 32 instances were due to allocation failures.

img

9. Other Information

img You can see that two tools are introduced here:

  • fastThread, official website: https://fastthread.io/, we will have a specific chapter to introduce it later.
  • HeapHero, official website: https://heaphero.io/, as the name suggests, this is a Java & Android Heap Dump Analyzer.

Using tools well will naturally amplify your abilities.

API Calls #

We can also use API calls, and the example provided by the official website is as follows:

curl -X POST --data-binary @./my-app-gc.log
https://api.gceasy.io/analyzeGC?apiKey={API_KEY_SENT_IN_EMAIL}
--header "Content-Type:text"

With API support, we can use the tool programmatically or through automated scripts.

Of course, if there is an upload API, there must be a download API as well. This article does not provide detailed information, but you can refer to the official documentation if you are interested.

GCViwer Tool #

Next, let’s introduce a powerful open-source analysis tool: GCViwer.

The GitHub homepage of the GCViewer project is:

https://github.com/chewiebug/GCViewer

Downloading and Installing #

Then, on the releases page of the GitHub project, find and download the latest version, for example: gcviewer-1.36.jar.

For Mac systems, you can directly download the packaged application: gcviewer-1.36-dist-mac.zip. After downloading and extracting it, when opening it for the first time, a security warning may appear. In this case, you may need to go to the security settings and check “Allow”, for example:

img

Test Case #

First, obtain the GC log file, as explained above for GCEasy.

Starting GCViewer #

You can start the GCViewer tool for analysis using the command line:

java -jar gcviewer_1.3.4.jar

The new version supports starting it directly with the java command. Older versions may require adding the path of the GC log file to the end. After starting the tool, you will see a graphical interface similar to the following:

img

Then, click the corresponding button in the graphical interface to open the log file. The current version supports single GC log files, multiple GC log files, and network URLs.

Of course, if you don’t want to use the graphical interface or can’t use it, you can also add program arguments after the command to directly output the analysis results to a file.

For example, execute the following command:

java -jar gcviewer-1.36.jar /xxxx/gc.demo.log summary.csv chart.png

This will summarize the information into the summary.csv file in the current directory and automatically save the graphical information as chart.png.

Result Report #

Open a GC log file in the graphical interface.

img

In the above figure, the Chart area shows a graphical representation of the GC events, including the sizes of each memory pool and the GC events. There are two visual indicators: the blue line represents the utilization of the heap memory, and the black bars represent the duration of GC pauses. The View menu can provide information on what each color represents.

img

From the previous figure, it can be seen that shortly after the program starts, most of the heap memory is consumed, making it difficult to allocate new objects, resulting in frequent Full GC events. This indicates that the program may have a memory leak or the allocated memory space is insufficient.

The graph also shows the frequency and duration of GC pauses. It can be observed that the GC runs continuously without interruption.

There are also three tabs on the right side that display different summary information:

img

Useful information in the “Summary” tab includes:

  • “Throughput”: The percentage of time spent on effective work compared to the time spent on GC.
  • “Number of GC pauses”: The number of GC pauses.
  • “Number of full GC pauses”: The number of Full GC pauses.

In the above example, the throughput is 13.03%, which means that 86.97% of CPU time is spent on GC. It is evident that the system is in a poor state - valuable CPU time is not used for actual work but is spent on garbage collection. The reason is simple: we only allocated 512MB of heap memory to the program.

Another interesting section is the “Pause” tab:

img

The “Pause” section shows the total time, average, minimum, and maximum duration of GC pauses, separated into total, minor, and major pauses. These statistics can quickly determine if the pause time needs to be optimized when optimizing the latency of the program.

Furthermore, we can obtain specific information: the cumulative pause time is 26.89 seconds, and there were 599 GC pauses in the total runtime of 30 seconds, which is exceptionally high.

For more detailed information on GC pauses, please refer to the “Event details” tab in the main interface:

img

From the “Event details” tab, all important GC events in the log can be seen, including the number of minor and major GC pauses, as well as concurrent GC executions.

In this example, one obvious finding is that Full GC pauses significantly affected both throughput and latency, with 569 Full GC pauses accounting for 26.58 seconds (out of a total runtime of 30 seconds).

GCViewer can quickly reveal abnormal GC behaviors through its graphical interface. In general, visual information can quickly reveal the following symptoms:

  • Low throughput: When the throughput of an application drops to an unacceptable level, the proportion of effective time for real business processing decreases significantly. The specific “tolerable” level depends on the specific scenario. From experience, a throughput of less than 90% should raise concerns and may require GC optimization.
  • Long pause time for individual GCs: If there is one GC pause that takes too long, it will affect the latency of the program. For example, if the latency requirement specifies that a transaction should be completed within 1000ms, it cannot tolerate any GC pause exceeding 1000 milliseconds.
  • High heap memory usage: If the old generation space remains almost full after a Full GC, it will significantly degrade program performance and may indicate insufficient resources or memory leaks. This symptom can have a serious impact on throughput.

Graphical presentation of GC log information is truly a blessing in the industry. It provides the same information as reading and analyzing lengthy and complex GC logs, but in a user-friendly graphical interface. However, while the graphical interface presents important information in a user-friendly manner, some details may still need to be sought from the log file.