Programmatically capture total GC count
I am trying to capture the full GCs that are encountered in our Java application. So far I have two approaches, both with drawbacks:
- Poll the GarbageCollectorMXBean objects every x seconds, then try to print the GC time and GC counter since the last poll and try to determine how long the GC has been going on. Unfortunately with this, we don't know if this is Full GC.
- Use javax.management.NotificationListener, subscribe to GarbageCollectorMXBean notifications. In theory, the application would be notified when a GC occurs, with the text "end of major GC" and "end of minor GC", as well as the reason. The downside to this approach is that the duration seems wildly wrong (sometimes showing 898 seconds when the GC log shows .2 seconds) and there is a mysterious "No GC" case that seems to indicate that the GC was not actually executed ( as there was no entry in the gc log).
A hybrid approach is possible where GC MXBeans can be requested when I receive a GC notification and then check if the GC has been executed. The downside to this is that the reason for the missing GC can still run at the end of the "main GC" and cause more complex logic.
What I really need is the total amount of time the app has been suspended due to GC operations. I believe that capturing a full GC will be sufficient to indicate that the application has stopped for a certain period of time, so if we find frequent GCs we know that it is heavy use or the application will soon run out of memory. Is there a better solution for determining the GC time and was there a full GC?
Edit . To be clear, I would like to capture this information inside the given JVM. This JVM is controlled by a separate team, and we do not need control over the JVM arguments they set, we can make recommendations. The idea is similar to a flight recorder, but instead provides real-time information to administrators.
source to share
If you are using Hotspot GC beans then you can use the new / old distinction rather than parallel / full. But this is enough in most cases.
In this case, I would poll and use the before / after information #LastGCInfo
from the respective generation:
For example, java.lang:type=GarbageCollector,name=PS Scavenge
this is the younger generation and the java.lang:type=GarbageCollector,name=PS MarkSweep
old generation when ParallelOld is enabled.
With the CMS, you see parallel collections and full collections in java.lang:type=GarbageCollector,name=ConcurrentMarkSweep
(but hopefully there will never be a full collection :)
This is a GC and VM specification, so you need some heuristics to support all platforms.
I think finer-scale monitoring is only possible with Flight Recorder events, but I have no experience with that.
source to share
If you can access the JVM filesystem in question, you can tell the JVM to register garbage collection information.
There are several flags for Oracle Java 8 (from http://docs.oracle.com/javase/8/docs/technotes/tools/unix/java.html#BABFAFAE )
-XX: + PrintGC
Allows to print messages in each GC. This option is disabled by default.
-XX: + PrintGCApplicationConcurrentTime
Allows you to print how much time has passed since the last pause (e.g. GC pause). This option is disabled by default.
-XX: + PrintGCApplicationStoppedTime
Lets you print how long the pause has paused (for example, the GC pause). This option is disabled by default.
-XX: + PrintGCDateStamps
Includes date stamp printing on each GC. This option is disabled by default.
-XX: + PrintGCDetails
Lets print verbose messages in each GC. This option is disabled by default.
-XX: + PrintGCTaskTimeStamps
Lets you print timestamps for each individual GC workflow task. This option is disabled by default.
-XX: + PrintGCTimeStamps
Allows printing timestamps on each GC. This option is disabled by default.
source to share
You can listen to GC notifications. See code below.
I am crossing this answer here as it seems relevant. Based on the pointers given by @ the8472 in this question . I created a more complete sample for registering GC from within the JVM (and thus discovered / counted it). Hope this saves a little :)
package fi.pelam.gclogutil;
import java.lang.management.*;
import java.util.Map;
import javax.management.openmbean.CompositeData;
import javax.management.*;
import com.sun.management.GarbageCollectionNotificationInfo;
import com.sun.management.GcInfo;
public class GcLogUtil {
static public void startLoggingGc() {
// http://www.programcreek.com/java-api-examples/index.php?class=javax.management.MBeanServerConnection&method=addNotificationListener
// https://docs.oracle.com/javase/8/docs/jre/api/management/extension/com/sun/management/GarbageCollectionNotificationInfo.html#GARBAGE_COLLECTION_NOTIFICATION
for (GarbageCollectorMXBean gcMbean : ManagementFactory.getGarbageCollectorMXBeans()) {
try {
ManagementFactory.getPlatformMBeanServer().
addNotificationListener(gcMbean.getObjectName(), listener, null,null);
} catch (Exception e) {
e.printStackTrace();
}
}
}
static private NotificationListener listener = new NotificationListener() {
@Override
public void handleNotification(Notification notification, Object handback) {
if (notification.getType().equals(GarbageCollectionNotificationInfo.GARBAGE_COLLECTION_NOTIFICATION)) {
// https://docs.oracle.com/javase/8/docs/jre/api/management/extension/com/sun/management/GarbageCollectionNotificationInfo.html
CompositeData cd = (CompositeData) notification.getUserData();
GarbageCollectionNotificationInfo gcNotificationInfo = GarbageCollectionNotificationInfo.from(cd);
GcInfo gcInfo = gcNotificationInfo.getGcInfo();
System.out.println("GarbageCollection: "+
gcNotificationInfo.getGcAction() + " " +
gcNotificationInfo.getGcName() +
" duration: " + gcInfo.getDuration() + "ms" +
" used: " + sumUsedMb(gcInfo.getMemoryUsageBeforeGc()) + "MB" +
" -> " + sumUsedMb(gcInfo.getMemoryUsageAfterGc()) + "MB");
}
}
};
static private long sumUsedMb(Map<String, MemoryUsage> memUsages) {
long sum = 0;
for (MemoryUsage memoryUsage : memUsages.values()) {
sum += memoryUsage.getUsed();
}
return sum / (1024 * 1024);
}
}
source to share