Programmatically capture Full GC count

Question

I'm trying to capture the full GCs which occur in our Java application. So far I have two approaches, both with flaws:

1. Poll the GarbageCollectorMXBean objects every x seconds, then try to pull the GC time and the GC count since the last poll and try to detect how long a GC occurred. Unfortunately with this, we don't know if it's a Full GC.
2. Use javax.management.NotificationListener, the subscribe to the GarbageCollectorMXBean notifications. In theory, the application will then be notified when a GC occurs, with the text "end of major GC" and "end of minor GC" as well as a cause. The flaw of this approach is that the duration seems to be wildly incorrect (sometimes showing 898 seconds when the GC log will show .2 seconds) and there is the mysterious case "No GC" which seems to indicate no GC was actually performed (as there was no entry in the gc log).

A hybrid approach is possible where the GC MXBeans can be queried when I get a GC notification, then check if a GC has been performed. The downside of this is that the No GC cause might still trigger at the end of "major GC" and cause the logic to be more complex.

What I'm really after is the total amount of time the application has been paused due to GC operations. I figure that capturing a full GC will be adequate to indicate that the application has halted for a period of time, so that if we detect frequent GCs we know there is heavy usage or the application will run out of memory shortly. Is there a better solution to detecting GC time and whether there was 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 don't necessary have control over the JVM arguments they will set, we can only make recommendations. The idea is similar to flight recorder, but instead providing information in real time to administrators.

Answer 1

You can listen for GC notifications. See code below.

I'm crossposting this answer here since it seems relevant. Based on pointers given by @the8472 in this question I crafted a more complete sample for logging GC from inside JVM (and thus detecting/counting it). I hope this will save somebody some time :)

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);
    }
}