Closed
Description
I ran my application with the following JVM options:
-XX:+PrintGC
-XX:+PrintGCApplicationConcurrentTime
-XX:+PrintGCApplicationStoppedTime
-XX:+PrintGCDateStamps
-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
When I tried to load the result into the GCViewer, it produced a lot of warning messages like those:
INFO [DataReaderFacade]: GCViewer version 1.33 (2013-10-30T18:47:41+0100)
INFO [DataReaderFactory]: File format: Sun 1.6.x
INFO [DataReaderSun1_6_0]: Reading Sun / Oracle 1.4.x / 1.5.x / 1.6.x / 1.7.x format...
WARNING [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Application time' Line 1: 2014-03-06T16:37:00.805+0000: 0.308: Application time: 0.3076280 seconds
WARNING [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Total time for which application threads were stopped' Line 2: 2014-03-06T16:37:00.805+0000: 0.308: Total time for which application threads were stopped: 0.0000910 seconds
The GC output is as follows:
2014-03-06T16:37:00.805+0000: 0.308: Application time: 0.3076280 seconds
2014-03-06T16:37:00.805+0000: 0.308: Total time for which application threads were stopped: 0.0000910 seconds
2014-03-06T16:37:01.043+0000: 0.545: Application time: 0.2377720 seconds
2014-03-06T16:37:01.043+0000: 0.546: Total time for which application threads were stopped: 0.0001160 seconds
It looks like starting with Java7, JVM started to prepend timestamps to all "application stopped/concurrent time" lines. Java8 behaves in a similar way.
At best these log lines should be ignored by GCviewer, but ideally it would be great if it parsed and analysed them. It is not uncommon that the application is stopped for non-GC reason, and it would be great to have some statistics (with charts!) on stop/concurrent times, their distribution and any outliers.