How to find application pause time from GC log files

I'm new to the garbage collection, Plz, someone helps me get answers to my next questions with a clear explanation

I want to find the application pause time and suspension count from GC log files for different JVMs:

  • Sun
  • Jockit
  • Ibm

different versions.

a. For SUN, I use the JVM options

-Xloggc:gc.log -verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -XX:+UseParNewGC -XX:+PrintGCDetails -XX:+UseConcMarkSweepGC -XX:+CMSIncrementalMode

C. For JRockit, I use the JVM options

-Xms100m -Xmx100m -Xns50m -Xss200k -Xgc:genconpar -Xverbose:gc -Xverboselog:gc_jrockit.log

My questions

Q1. What is the application pause time and why is it happening.

Q2. How to say by looking at the logs that a suspension has occurred.

Q3. . Application pause time = GC Times amount.

For instance:

2013-09-06T23: 35: 23.382-0700: [GC 150.505: [BoyNew Desired survivor size 50331648 bytes, new threshold 2 (max. 15) - age 1: 28731664 bytes, 28731664 total - age 2: 28248376 bytes, 56980040 total: 688128K-> 98304K (688128K), 0.2166700 sec.] 697655K-> 163736K (10387456K), 0.2167900 seconds ] [Time: user = 0.44 sys = 0.04, real = 0.22 s ]

2013-09-06T23: 35: 28.044-0700: 155.167: [GC 155.167: [BoyNew Desired survivor size 50331648 bytes, new threshold 15 (max. 15) - age 1: 22333512 bytes, 22333512 total - age 2: 27468336 byte, 49801848 total: 688128K-> 71707K (688128K), 0.0737140 sec.] 753560K-> 164731K (10387456K), 0.0738410 sec. ] [Time: user = 0.30 sys = 0.02, real = 0.07 s]

suspimeTime = 0.2167900 secs + 0.0738410 secs

I am. If yes, then I need to add all the time for each gc.

II. If Plz does not explain to me the detailed data for these magazines, we believe that this happened, and those that are not taken into account for different collectors with magazines

Q4. Can we say that GC times "0.2167900, 0.0738410" are equal to GC Pauses, i.e. TotalGCPause = 0.2167900 + 0.0738410

Q5. You can calculate the suspension time using only the flags above, or we need to enable additional flags, such as -XX:+PrintGCApplicationStoppedTime for SUN

Q6. I saw how the dyna tool tracks its calculation of pause and count times for SUN using the -XX:+PrintGCApplicationStoppedTime flag -XX:+PrintGCApplicationStoppedTime

+4
source share
1 answer

If you need the most accurate information about the time during which your application was stopped due to GC activity, you should go with -XX:+PrintGCApplicationStoppedTime .

-XX:+PrintGCApplicationStoppedTime allows printing the number of application threads of time as a result of internal HotSpot VM operation (GC operations and security operations).

But for the practical daily use of the information provided by the GC protocols is enough. You can use the approach described in your question 3. to determine the time spent in the GC.

+1
source

Source: https://habr.com/ru/post/1501663/


All Articles