13

I'm running a Java program and I need to get how much time each it spent garbage collecting. I found these 2 JVM flags: -XX:+PrintGCApplicationConcurrentTime -XX:+PrintGCApplicationStoppedTime

but I'm not being able to find information about it. I suppose that PrintGCApplicationStoppedTime prints for how long the application time was in a STW, however I am not sure about -XX:+PrintGCApplicationConcurrentTime. Does it print for how long the application was executing concurrently with collection threads?

Thanks in advance.

franco
  • 297
  • 4
  • 9

2 Answers2

11

The names of these flags are not very accurate.

PrintGCApplicationStoppedTime shows how much time the application was stopped at safepoint. Most often safepoints are caused by stop-the-world phases of garbage collection, however, many other reasons exist.

PrintGCApplicationConcurrentTime is how much time the application worked without stopping, i.e. the time between two successive safepoints.

Community
  • 1
  • 1
apangin
  • 92,924
  • 10
  • 193
  • 247
  • Using these 2 flags I will get many application stopped times and many application concurrent times. Given your explanation I would assume that the sum of all these times would be the total execution time. However, this sum gives me ```Total execution time : 4.48secs Time application ran : 4.47secs Time application was stopped : 0.01secs``` and using the command `time` I get 13.97 seconds. I'm missing something here... – franco Mar 07 '16 at 20:11
  • @franco In my experiments `Application time` + `Stopped time` is actually equal to real execution time. Which output is correct in your case? Are you sure you sum up all the results? – apangin Mar 07 '16 at 21:18
  • yes, you are right! it is the same time (my fault). But I still have a question: for instance with the CMS or G1GC collector there are threads working concurrently with collector threads. This time is part of Application Concurrent Time, correct? – franco Mar 08 '16 at 11:41
  • 1
    @franco Yes, since concurrent GC is running out of safepoint pause, its time is counted within `Application Concurrent Time`. – apangin Mar 08 '16 at 12:56
0

You using those flags to know how long your application runs between garbage collections.

Eventually that can be calculated from the GC logs but a convenient way to see that information is with the command line flags -XX:+PrintGCApplicationStoppedTime and -XX:+PrintGCApplicationConcurrentTime.

Adding these to your command line produces output such as this:

Application time: 0.2863875 seconds
Total time for which application threads were stopped: 0.0225087 seconds
Application time: 0.1476791 seconds
Total time for which application threads were stopped: 0.0255697 seconds

The application ran (reported in the first line) for about 287 milliseconds and then was stopped for about 22 milliseconds (reported in the second line).

The flags can be used separately or together.

Johnny
  • 14,397
  • 15
  • 77
  • 118