DZone
Thanks for visiting DZone today,
Edit Profile
  • Manage Email Subscriptions
  • How to Post to DZone
  • Article Submission Guidelines
Sign Out View Profile
  • Post an Article
  • Manage My Drafts
Over 2 million developers have joined DZone.
Log In / Join
Please enter at least three characters to search
Refcards Trend Reports
Events Video Library
Refcards
Trend Reports

Events

View Events Video Library

Zones

Culture and Methodologies Agile Career Development Methodologies Team Management
Data Engineering AI/ML Big Data Data Databases IoT
Software Design and Architecture Cloud Architecture Containers Integration Microservices Performance Security
Coding Frameworks Java JavaScript Languages Tools
Testing, Deployment, and Maintenance Deployment DevOps and CI/CD Maintenance Monitoring and Observability Testing, Tools, and Frameworks
Culture and Methodologies
Agile Career Development Methodologies Team Management
Data Engineering
AI/ML Big Data Data Databases IoT
Software Design and Architecture
Cloud Architecture Containers Integration Microservices Performance Security
Coding
Frameworks Java JavaScript Languages Tools
Testing, Deployment, and Maintenance
Deployment DevOps and CI/CD Maintenance Monitoring and Observability Testing, Tools, and Frameworks

The software you build is only as secure as the code that powers it. Learn how malicious code creeps into your software supply chain.

Apache Cassandra combines the benefits of major NoSQL databases to support data management needs not covered by traditional RDBMS vendors.

Generative AI has transformed nearly every industry. How can you leverage GenAI to improve your productivity and efficiency?

Modernize your data layer. Learn how to design cloud-native database architectures to meet the evolving demands of AI and GenAI workloads.

Related

  • Real-World Garbage Collection Scenarios and Solutions
  • Different Garbage Collectors in Java: Exploring the Options
  • Java Z Garbage Collector (ZGC): Revolutionizing Memory Management
  • How Java Apps Litter Beyond the Heap

Trending

  • Dropwizard vs. Micronaut: Unpacking the Best Framework for Microservices
  • Building an AI/ML Data Lake With Apache Iceberg
  • Advancing Robot Vision and Control
  • Simplifying Multi-LLM Integration With KubeMQ
  1. DZone
  2. Coding
  3. Languages
  4. Understanding the Java Garbage Collection Log

Understanding the Java Garbage Collection Log

To diagnose any memory problems, the Garbage Collection log file is the best place to start. Take a look at the anatomy of a GC log file in this helpful article.

By 
Ram Lakshmanan user avatar
Ram Lakshmanan
DZone Core CORE ·
Updated May. 05, 16 · Tutorial
Likes (39)
Comment
Save
Tweet
Share
198.0K Views

Join the DZone community and get the full member experience.

Join For Free

To diagnose any memory problems, the Garbage Collection log file is the best place to start. It provides several interesting statistics:

  • When the scavenge (or Young generation) GC ran?
  • When the full GC ran?
  • How many scavenge GCs and Full GCs ran? Did they run repeatedly? In what interval?
  • After the GC process ran, how much memory was reclaimed in Young, Old, and Permanent/Metaspace generations?
  • How long did the GC run?
  • How long did JVM pause when Full GC run?
  • What was the total allocated memory in each generation?
  • How many objects were promoted to old generation?

How to Generate GC Log File?

In order to understand the GC log, you first need to generate one. Passing the following system properties to your JVM would generate GC logs.

-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:<file-path>

where file-path: Garbage Collection log file path.


Example:

-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/opt/app/gc.log


-XX:+PrintGCDateStamps would print the absolute time stamp in the log statement (i.e. “2014-11-18T16:39:25.303-0800”).

-XX:+PrintGCDetails property would print the details of how much memory is reclaimed in each generation.

Passing the above system properties would generate a Garbage Collection log file that would look like:

2014-11-18T16:39:25.512-0800: 76.592: [Full GC [PSYoungGen: 26560K->0K(233024K)] [PSOldGen: 632024K->658428K(699072K)] 658584K->658428K(932096K) [PSPermGen: 2379K->2379K(21248K)], 3.0978612 secs] [Times: user=3.09 sys=0.00, real=3.10 secs] 

2014-11-18T16:39:31.536-0800: 82.616: [Full GC [PSYoungGen: 116544K->0K(233024K)] [PSOldGen: 658428K->684832K(699072K)] 774972K->684832K(932096K) [PSPermGen: 2379K->2379K(21248K)], 3.2582136 secs] [Times: user=3.23 sys=0.03, real=3.26 secs] 

2014-11-18T16:39:37.728-0800: 88.808: [Full GC [PSYoungGen: 116544K->12164K(233024K)] [PSOldGen: 684832K->699071K(699072K)] 801376K->711236K(932096K) [PSPermGen: 2379K->2379K(21248K)], 3.4230220 secs] [Times: user=3.40 sys=0.02, real=3.42 secs] 
:
:
Heap
 PSYoungGen total 233024K, used 116544K [0x00000000eaab0000, 0x0000000100000000, 0x0000000100000000)
 eden space 116544K, 100% used [0x00000000eaab0000,0x00000000f1c80000,0x00000000f1c80000)
 from space 116480K, 0% used [0x00000000f1c80000,0x00000000f1c80000,0x00000000f8e40000)
 to space 116480K, 0% used [0x00000000f8e40000,0x00000000f8e40000,0x0000000100000000)
 PSOldGen total 699072K, used 699071K [0x00000000c0000000, 0x00000000eaab0000, 0x00000000eaab0000)
 object space 699072K, 99% used [0x00000000c0000000,0x00000000eaaafff0,0x00000000eaab0000)
 PSPermGen total 21248K, used 2409K [0x00000000bae00000, 0x00000000bc2c0000, 0x00000000c0000000)
 object space 21248K, 11% used [0x00000000bae00000,0x00000000bb05a740,0x00000000bc2c0000)

Anatomy of GC Log Statement

2014-11-18T16:39:37.728-0800: 88.808: [Full GC [PSYoungGen: 116544K->12164K(233024K)] [PSOldGen: 684832K->699071K(699072K)] 801376K->711236K(932096K) [PSPermGen: 2379K->2379K(21248K)], 3.4230220 secs] [Times: user=3.40 sys=0.02, real=3.42 secs]

Let’s pick apart this log statement and examine each field in it:

2014-11-18T16:39:37.728-0800 – Time stamp at which GC ran.

Full GC – Type of GC. It could be either ‘Full GC’ or ‘GC’.

[PSYoungGen: 116544K->12164K(233024K)] – After the GC ran the young generation, space came down from 116544k (i.e. 113mb) to 12164k (i.e. 12mb). Total allocated young generation space is 233024k (i.e.227mb).

[PSOldGen: 684832K->699071K(699072K)] – After the GC ran the old generation space increased from 684832k (i.e. 669mb) to 699071k (i.e. 682mb) and total allocated old generation space is 669072k (i.e. 682mb). In this case after the GC event, old generation's space increased and didn't decrease, which isn't the case always. Here size has increased because all objects in Old generation are actively referenced + objects from young generation are promoted to old generation. Thus you are seeing the increase in the old generation size.

801376K->711236K(932096K) – After the GC ran, overall memory came down from 801376k to 711236k. Total allocated memory space is 932096k (i.e. 910mb).

[PSPermGen: 2379K->2379K(21248K)] – After the GC ran, there was no drop in perm generation space.

3.4230220 secs – the GC took 3.42 seconds to complete.

[Times: user=3.40 sys=0.02, real=3.42 secs] – Real is wall clock time (time from start to finish of the call). This is all elapsed time including time slices used by other processes and time the process spends blocked (for example if it is waiting for I/O to complete).

User is the amount of CPU time spent in user-mode code (outside the kernel) within the process. This is only actual CPU time used in executing the process. Other processes, and the time the process spends blocked, do not count towards this figure.

Sys is the amount of CPU time spent in the kernel within the process. This means executing CPU time spent in system calls within the kernel, as opposed to library code, which is still running in user-space. Like user, this is only CPU time used by the process.

In your case, if the CPU time (3.4 sec) is considerably higher than the real time passed (3.42 Sec), we can conclude that the GC was run using multiple threads. To learn more about the difference between each of these Times, please check out this article.

Image title

Fig: Anatomy of a Garbage Collection Log Statement

Tools to Analyze GC Logs

Depending on the JVM version and the GC algorithm that you use, the GC log format will differ. I have seen 30+ different version of GC logs. It’s tedious to analyze GC logs in a text editor. I highly recommend using http://gceasy.io/ - a universal online Garbage collection analysis tool. It's a free tool that analyzes the Garbage collection logs and provides telemetrics, potential Garbage Collection problems, and Memory problems, and it provides solutions to these problems, as well.

garbage collection Garbage (computer science) Java (programming language) CPU time

Opinions expressed by DZone contributors are their own.

Related

  • Real-World Garbage Collection Scenarios and Solutions
  • Different Garbage Collectors in Java: Exploring the Options
  • Java Z Garbage Collector (ZGC): Revolutionizing Memory Management
  • How Java Apps Litter Beyond the Heap

Partner Resources

×

Comments
Oops! Something Went Wrong

The likes didn't load as expected. Please refresh the page and try again.

ABOUT US

  • About DZone
  • Support and feedback
  • Community research
  • Sitemap

ADVERTISE

  • Advertise with DZone

CONTRIBUTE ON DZONE

  • Article Submission Guidelines
  • Become a Contributor
  • Core Program
  • Visit the Writers' Zone

LEGAL

  • Terms of Service
  • Privacy Policy

CONTACT US

  • 3343 Perimeter Hill Drive
  • Suite 100
  • Nashville, TN 37211
  • support@dzone.com

Let's be friends:

Likes
There are no likes...yet! 👀
Be the first to like this post!
It looks like you're not logged in.
Sign in to see who liked this post!