What is the best way to measure GC pause times?

Question

What is the best way to track the GC pause/stall times in a Java instance?

1. can it be retrieved from the Garbage Collector GarbageCollectorMXBean?
2. can it be read from gc.log?

Does gc.log have any additional information that the MXBean doesn't have? I would prefer option 1 because I want the instance to emit that metric to our monitoring system.

I have read through a few posts like this on SO, but I don't seem to be getting the right answer. I am specifically looking for the GC stall times and not the total time spent on GC.

Answer 1

Garbage Collection is not the only reason of JVM stop-the-world pauses.
You may want to count other reasons, too.

The first way to monitor safepoint pauses is to parse VM logs:

• for JDK 8 and earlier add -XX:+PrintGCApplicationStoppedTime JVM option;
• starting from JDK 9 add -Xlog:safepoint.

Then look for Total time for which application threads were stopped messages in the log file.

The second way is to use undocumented Hotspot internal MXBean:

sun.management.HotspotRuntimeMBean runtime =
        sun.management.ManagementFactoryHelper.getHotspotRuntimeMBean();

System.out.println("Safepoint time:  " + runtime.getTotalSafepointTime() + " ms");
System.out.println("Safepoint count: " + runtime.getSafepointCount());

It gives you the cumulative time of all JVM pauses. See the discussion in this answer.

Answer 2

I am specifically looking for the GC stall times

There are more to stall times than the GC itself. Time to acquire the safepoint is also an application stall and is only available as part logging, not through MXBeans

But really, if you're concerned about application stalls then neither GC pauses nor over safepoint time is what you should actually measure. You should measure the stalls themselves, e.g. via jhiccup