CODEWITHSUNDEEP
javaperformancegarbage-collectionjvm
Michael
Michael

Reputation: 42050

Measuring time spent on GC

Suppose I am testing a Java server application. I know how much time it takes to finish the test. Now I'd like to know how much was spent on GC during that test. How can I do it?

Upvotes: 16

Views: 21362

Answers (7)

Markus Weninger
Markus Weninger

Reputation: 12648

Similar to @Steve McLeod's answer that uses ManagementFactory, since Java 8 this can also be written in a single line using Java streams:

long collectionTime = ManagementFactory.getGarbageCollectorMXBeans().stream().mapToLong(mxBean -> mxBean.getCollectionTime()).sum();

Upvotes: 1

K Erlandsson
K Erlandsson

Reputation: 13696

Another convenient solution is to run jstat -gc (documentation) against your process when your tests are done. That will give you nice aggregated output on exactly how much time has been spent in GC during the lifetime of your JVM.

Upvotes: 4

Andrew Logvinov
Andrew Logvinov

Reputation: 21831

There are different GC algorithms that behave differently. I recently read a good article on the subject that I can recommend if you'd like to know more.

You can launch your application with the following command line options -verbose:gc -XX:+PrintGCDateStamps -XX:+PrintGCDetails and get information about GC.

Here's an example of the log message:

2012-12-17T03:02:15.590-0500: [GC [PSYoungGen: 40934K->2670K(29440K)] 48211K->14511K(73152K), 0.5745260 secs] [Times: user=0.08 sys=0.01, real=0.58 secs]

Upvotes: 1

meriton
meriton

Reputation: 70564

This performance metric is recorded by the JVM, and made accessible through JMX. For interactive monitoring, connect to the running JVM with JConsole, and in the "VM Summary" Tab it will say something like:

Garbage collector: Name = 'Copy', Collections = 26, Total time spent = 0.183 seconds Garbage collector: Name = 'MarkSweepCompact', Collections = 2, Total time spent = 0.168 seconds

You can also query JMX programatically.

Upvotes: 4

eis
eis

Reputation: 53472

Enable garbage collection logs. As documented, you can use -verbose:gc, -XX:+PrintGCDetails and -XX:+PrintGCTimeStamps flags. -Xloggc flag can be used to direct those to a file.

Resulting logs are human-readable, but for most benefit you probably want them to be run through an analyzer. Such tools are listed in this thread.

Upvotes: 1

Steve McLeod
Steve McLeod

Reputation: 52458

I guess that when GC (Garbage Collector) is working the application stops and resumes when GC finishes

I don't think that is a safe assumption. Are you sure the garbage collector is not working in parallel with your application code?

To measure the time spent in collecting garbage you can query the Garbage Collector MXBean.

Try this:

public static void main(String[] args)  {
    System.out.println("collectionTime = " + getGarbageCollectionTime());
}

private static long getGarbageCollectionTime() {
    long collectionTime = 0;
    for (GarbageCollectorMXBean garbageCollectorMXBean : ManagementFactory.getGarbageCollectorMXBeans()) {
        collectionTime += garbageCollectorMXBean.getCollectionTime();
    }
    return collectionTime;
}

Upvotes: 25

hvgotcodes
hvgotcodes

Reputation: 120198

The simplest way is to use the -Xloggc and -XX:-PrintGCTimeStamps options when starting up your JVM. I think it prints out how long garbage collection takes.

http://www.oracle.com/technetwork/java/javase/tech/vmoptions-jsp-140102.html

Upvotes: 7

Related Questions