gcviewer-1.35-SNAPSHOT throws warnings "Unknown gc type"

[krishna81m]

Just gave it a try and ended up getting lot of warnings.
java -jar gcviewer-1.35-SNAPSHOT.jar gc.log.0 summary.csv chart.png -t CSV_TS

gc logs generated as follows: /usr/java/jre1.7.0_51//bin/java -ea -javaagent:/usr/share/dse/cassandra/lib/jamm-0.2.5.jar -XX:+UseThreadPriorities -XX:ThreadPriorityPolicy=42 -Xms14G -Xmx14G -XX:+HeapDumpOnOutOfMemoryError -XX:NewRatio=2 -XX:MaxTenuringThreshold=10 -XX:+DisableExplicitGC -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+CMSParallelRemarkEnabled -XX:SurvivorRatio=8 -XX:CMSInitiatingOccupancyFraction=75 -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseTLAB -XX:+UseCondCardMark -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -XX:+PrintTenuringDistribution -XX:+PrintGCApplicationStoppedTime -XX:+PrintPromotionFailure -XX:PrintFLSStatistics=1 -Xloggc:/var/log/cassandra/gc.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=64M

WARNING: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'concurrent mark-sweep generation total' Line 309835: concurrent mar
k-sweep generation total 9786752K, used 6660868K [0x00000005a58a0000, 0x00000007fae00000, 0x00000007fae00000)
Jan 16, 2015 1:41:06 AM com.tagtraum.perf.gcviewer.imp.DataReaderSun1_6_0 read
WARNING: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'concurrent-mark-sweep perm gen total' Line 309836: concurrent-mark-
sweep perm gen total 83968K, used 51110K [0x00000007fae00000, 0x0000000800000000, 0x0000000800000000)
Jan 16, 2015 1:41:06 AM com.tagtraum.perf.gcviewer.imp.DataReaderSun1_6_0 read
WARNING: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.ArrayIndexOutOfBoundsException) Line 309837: }
Jan 16, 2015 1:41:06 AM com.tagtraum.perf.gcviewer.imp.DataReaderSun1_6_0 read
WARNING: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'GCHeap after GC invocations=' Line 309892: 2015-01-10T22:38:37.116+0
000: 81720.358: [GCHeap after GC invocations=4682 (full 16):
Jan 16, 2015 1:41:06 AM com.tagtraum.perf.gcviewer.imp.DataReaderSun1_6_0 read
WARNING: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'par new generation total' Line 309893: par new generation total
4404032K, used 63139K [0x000000047ae00000, 0x00000005a58a0000, 0x00000005a58a0000)
Jan 16, 2015 1:41:06 AM com.tagtraum.perf.gcviewer.imp.DataReaderSun1_6_0 read
WARNING: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'eden space' Line 309894: eden space 3914752K, 0% used [0x0000000
47ae00000, 0x000000047ae00000, 0x0000000569d00000)
Jan 16, 2015 1:41:06 AM com.tagtraum.perf.gcviewer.imp.DataReaderSun1_6_0 read
WARNING: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'from space' Line 309895: from space 489280K, 12% used [0x00000005
69d00000, 0x000000056daa8eb8, 0x0000000587ad0000)
Jan 16, 2015 1:41:07 AM com.tagtraum.perf.gcviewer.imp.DataReaderSun1_6_0 read
WARNING: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'to space' Line 309896: to space 489280K, 0% used [0x00000005
87ad0000, 0x0000000587ad0000, 0x00000005a58a0000)
Jan 16, 2015 1:41:07 AM com.tagtraum.perf.gcviewer.imp.DataReaderSun1_6_0 read
WARNING: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'concurrent mark-sweep generation total' Line 309897: concurrent mar
k-sweep generation total 9786752K, used 6663249K [0x00000005a58a0000, 0x00000007fae00000, 0x00000007fae00000)
Jan 16, 2015 1:41:07 AM com.tagtraum.perf.gcviewer.imp.DataReaderSun1_6_0 read
WARNING: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'concurrent-mark-sweep perm gen total' Line 309898: concurrent-mark-
sweep perm gen total 83968K, used 51110K [0x00000007fae00000, 0x0000000800000000, 0x0000000800000000)

[chewiebug]

I'd be very interested in your go.log.0. It looks like PrintHeapAtGC prints unexpected output.

[krishna81m]

Unable to attach, so pasting lines as is again:

2015-01-09T23:56:44.894+0000: 8.135: Total time for which application threads were stopped: 0.0000930 seconds
2015-01-09T23:56:44.895+0000: 8.137: Total time for which application threads were stopped: 0.0000910 seconds
2015-01-09T23:56:44.896+0000: 8.137: Total time for which application threads were stopped: 0.0000660 seconds
2015-01-09T23:56:44.896+0000: 8.137: Total time for which application threads were stopped: 0.0000860 seconds
2015-01-09T23:56:44.897+0000: 8.139: Total time for which application threads were stopped: 0.0001390 seconds
2015-01-09T23:56:44.898+0000: 8.140: Total time for which application threads were stopped: 0.0000650 seconds
2015-01-09T23:56:44.900+0000: 8.142: Total time for which application threads were stopped: 0.0004630 seconds
2015-01-09T23:56:44.903+0000: 8.145: Total time for which application threads were stopped: 0.0000580 seconds
2015-01-09T23:56:44.905+0000: 8.146: Total time for which application threads were stopped: 0.0000690 seconds
2015-01-09T23:56:44.906+0000: 8.147: Total time for which application threads were stopped: 0.0000570 seconds
2015-01-09T23:56:44.906+0000: 8.148: Total time for which application threads were stopped: 0.0000640 seconds
2015-01-09T23:56:44.931+0000: 8.173: Total time for which application threads were stopped: 0.0000710 seconds
2015-01-09T23:56:44.951+0000: 8.192: Total time for which application threads were stopped: 0.0001000 seconds
2015-01-09T23:56:44.951+0000: 8.193: Total time for which application threads were stopped: 0.0000940 seconds
2015-01-09T23:56:44.961+0000: 8.203: Total time for which application threads were stopped: 0.0000750 seconds
2015-01-09T23:56:44.974+0000: 8.215: Total time for which application threads were stopped: 0.0000980 seconds
2015-01-09T23:56:44.975+0000: 8.217: Total time for which application threads were stopped: 0.0000550 seconds
2015-01-09T23:56:44.976+0000: 8.218: Total time for which application threads were stopped: 0.0000750 seconds
2015-01-09T23:56:44.986+0000: 8.228: Total time for which application threads were stopped: 0.0001010 seconds
2015-01-09T23:56:45.000+0000: 8.242: Total time for which application threads were stopped: 0.0001000 seconds
2015-01-09T23:56:45.001+0000: 8.243: Total time for which application threads were stopped: 0.0000420 seconds
2015-01-09T23:56:45.011+0000: 8.253: Total time for which application threads were stopped: 0.0000780 seconds
2015-01-09T23:56:45.040+0000: 8.282: Total time for which application threads were stopped: 0.0001270 seconds
2015-01-09T23:56:45.335+0000: 8.577: Total time for which application threads were stopped: 0.0002190 seconds
2015-01-09T23:56:46.336+0000: 9.577: Total time for which application threads were stopped: 0.0002540 seconds
2015-01-09T23:56:46.569+0000: 9.811: Total time for which application threads were stopped: 0.0002750 seconds
2015-01-09T23:56:47.570+0000: 10.811: Total time for which application threads were stopped: 0.0002140 seconds
2015-01-09T23:56:47.972+0000: 11.214: Total time for which application threads were stopped: 0.0002360 seconds
2015-01-09T23:56:48.973+0000: 12.214: Total time for which application threads were stopped: 0.0002760 seconds
2015-01-09T23:56:50.786+0000: 14.028: Total time for which application threads were stopped: 0.0002230 seconds
2015-01-09T23:56:50.818+0000: 14.059: Total time for which application threads were stopped: 0.0000760 seconds
2015-01-09T23:56:50.818+0000: 14.060: Total time for which application threads were stopped: 0.0000620 seconds
2015-01-09T23:56:50.836+0000: 14.077: Total time for which application threads were stopped: 0.0001140 seconds
2015-01-09T23:56:50.844+0000: 14.086: Total time for which application threads were stopped: 0.0000810 seconds
2015-01-09T23:56:50.850+0000: 14.091: Total time for which application threads were stopped: 0.0003140 seconds
2015-01-09T23:56:50.855+0000: 14.097: Total time for which application threads were stopped: 0.0000730 seconds
2015-01-09T23:56:50.868+0000: 14.110: Total time for which application threads were stopped: 0.0000670 seconds
{Heap before GC invocations=0 (full 0):
 par new generation   total 4404032K, used 3914752K [0x000000047ae00000, 0x00000005a58a0000, 0x00000005a58a0000)
  eden space 3914752K, 100% used [0x000000047ae00000, 0x0000000569d00000, 0x0000000569d00000)
  from space 489280K,   0% used [0x0000000569d00000, 0x0000000569d00000, 0x0000000587ad0000)
  to   space 489280K,   0% used [0x0000000587ad0000, 0x0000000587ad0000, 0x00000005a58a0000)
 concurrent mark-sweep generation total 9786752K, used 0K [0x00000005a58a0000, 0x00000007fae00000, 0x00000007fae00000)
 concurrent-mark-sweep perm gen total 21248K, used 19013K [0x00000007fae00000, 0x00000007fc2c0000, 0x0000000800000000)
2015-01-09T23:56:50.872+0000: 14.114: [GCBefore GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1252704256
Max   Chunk Size: 1252704256
Number of Blocks: 1
Av.  Block  Size: 1252704256
Tree      Height: 1
Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 0
Max   Chunk Size: 0
Number of Blocks: 0
Tree      Height: 0
2015-01-09T23:56:50.872+0000: 14.114: [ParNew
Desired survivor size 250511360 bytes, new threshold 10 (max 10)
- age   1:   21552952 bytes,   21552952 total
: 3914752K->21242K(4404032K), 0.0250820 secs] 3914752K->21242K(14190784K)After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1252687872
Max   Chunk Size: 1252687872
Number of Blocks: 1
Av.  Block  Size: 1252687872
Tree      Height: 1
After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 0
Max   Chunk Size: 0
Number of Blocks: 0
Tree      Height: 0
, 0.0252550 secs] [Times: user=0.30 sys=0.00, real=0.02 secs] 
Heap after GC invocations=1 (full 0):
 par new generation   total 4404032K, used 21242K [0x000000047ae00000, 0x00000005a58a0000, 0x00000005a58a0000)
  eden space 3914752K,   0% used [0x000000047ae00000, 0x000000047ae00000, 0x0000000569d00000)
  from space 489280K,   4% used [0x0000000587ad0000, 0x0000000588f8e938, 0x00000005a58a0000)
  to   space 489280K,   0% used [0x0000000569d00000, 0x0000000569d00000, 0x0000000587ad0000)
 concurrent mark-sweep generation total 9786752K, used 0K [0x00000005a58a0000, 0x00000007fae00000, 0x00000007fae00000)
 concurrent-mark-sweep perm gen total 21248K, used 19013K [0x00000007fae00000, 0x00000007fc2c0000, 0x0000000800000000)
}
2015-01-09T23:56:50.897+0000: 14.139: Total time for which application threads were stopped: 0.0255420 seconds
2015-01-09T23:56:50.898+0000: 14.140: Total time for which application threads were stopped: 0.0001050 seconds
2015-01-09T23:56:50.898+0000: 14.140: Total time for which application threads were stopped: 0.0001010 seconds
2015-01-09T23:56:50.898+0000: 14.140: Total time for which application threads were stopped: 0.0000670 seconds
2015-01-09T23:56:50.898+0000: 14.140: Total time for which application threads were stopped: 0.0000840 seconds
2015-01-09T23:56:50.898+0000: 14.140: Total time for which application threads were stopped: 0.0000800 seconds
2015-01-09T23:56:50.899+0000: 14.140: Total time for which application threads were stopped: 0.0000850 seconds
2015-01-09T23:56:50.899+0000: 14.140: Total time for which application threads were stopped: 0.0001000 seconds
2015-01-09T23:56:50.899+0000: 14.140: Total time for which application threads were stopped: 0.0000660 seconds
2015-01-09T23:56:50.899+0000: 14.141: Total time for which application threads were stopped: 0.0000610 seconds
2015-01-09T23:56:50.899+0000: 14.141: Total time for which application threads were stopped: 0.0000600 seconds
2015-01-09T23:56:50.899+0000: 14.141: Total time for which application threads were stopped: 0.0000750 seconds
2015-01-09T23:56:50.899+0000: 14.141: Total time for which application threads were stopped: 0.0000630 seconds
2015-01-09T23:56:50.899+0000: 14.141: Total time for which application threads were stopped: 0.0000630 seconds
2015-01-09T23:56:50.899+0000: 14.141: Total time for which application threads were stopped: 0.0000550 seconds
2015-01-09T23:56:50.899+0000: 14.141: Total time for which application threads were stopped: 0.0000580 seconds
2015-01-09T23:56:50.899+0000: 14.141: Total time for which application threads were stopped: 0.0000540 seconds
2015-01-09T23:56:50.900+0000: 14.141: Total time for which application threads were stopped: 0.0000550 seconds
2015-01-09T23:56:50.900+0000: 14.141: Total time for which application threads were stopped: 0.0000490 seconds
2015-01-09T23:56:50.900+0000: 14.141: Total time for which application threads were stopped: 0.0000520 seconds
2015-01-09T23:56:50.900+0000: 14.142: Total time for which application threads were stopped: 0.0003300 seconds
2015-01-09T23:56:50.900+0000: 14.142: Total time for which application threads were stopped: 0.0000380 seconds
2015-01-09T23:56:50.900+0000: 14.142: Total time for which application threads were stopped: 0.0000560 seconds
2015-01-09T23:56:50.900+0000: 14.142: Total time for which application threads were stopped: 0.0000610 seconds
2015-01-09T23:56:50.900+0000: 14.142: Total time for which application threads were stopped: 0.0000500 seconds
2015-01-09T23:56:50.901+0000: 14.142: Total time for which application threads were stopped: 0.0000690 seconds
2015-01-09T23:56:50.901+0000: 14.142: Total time for which application threads were stopped: 0.0000670 seconds
2015-01-09T23:56:50.901+0000: 14.142: Total time for which application threads were stopped: 0.0000730 seconds
2015-01-09T23:56:50.901+0000: 14.143: Total time for which application threads were stopped: 0.0000580 seconds
2015-01-09T23:56:50.901+0000: 14.143: Total time for which application threads were stopped: 0.0000610 seconds
2015-01-09T23:56:50.901+0000: 14.143: Total time for which application threads were stopped: 0.0000630 seconds
2015-01-09T23:56:50.901+0000: 14.143: Total time for which application threads were stopped: 0.0000620 seconds
2015-01-09T23:56:50.901+0000: 14.143: Total time for which application threads were stopped: 0.0000500 seconds
2015-01-09T23:56:50.901+0000: 14.143: Total time for which application threads were stopped: 0.0000580 seconds
2015-01-09T23:56:50.901+0000: 14.143: Total time for which application threads were stopped: 0.0000610 seconds
2015-01-09T23:56:50.902+0000: 14.143: Total time for which application threads were stopped: 0.0000650 seconds
2015-01-09T23:56:50.902+0000: 14.143: Total time for which application threads were stopped: 0.0000530 seconds
2015-01-09T23:56:50.902+0000: 14.143: Total time for which application threads were stopped: 0.0000470 seconds
2015-01-09T23:56:50.902+0000: 14.144: Total time for which application threads were stopped: 0.0000760 seconds
2015-01-09T23:56:50.902+0000: 14.144: Total time for which application threads were stopped: 0.0000830 seconds
2015-01-09T23:56:50.902+0000: 14.144: Total time for which application threads were stopped: 0.0002230 seconds
2015-01-09T23:56:50.904+0000: 14.145: Total time for which application threads were stopped: 0.0000670 seconds
2015-01-09T23:56:50.904+0000: 14.145: Total time for which application threads were stopped: 0.0000730 seconds
2015-01-09T23:56:50.904+0000: 14.146: Total time for which application threads were stopped: 0.0000550 seconds
2015-01-09T23:56:50.904+0000: 14.146: Total time for which application threads were stopped: 0.0000530 seconds
2015-01-09T23:56:50.904+0000: 14.146: Total time for which application threads were stopped: 0.0000610 seconds
2015-01-09T23:56:50.905+0000: 14.146: Total time for which application threads were stopped: 0.0000640 seconds
2015-01-09T23:56:50.905+0000: 14.147: Total time for which application threads were stopped: 0.0000710 seconds
2015-01-09T23:56:50.905+0000: 14.147: Total time for which application threads were stopped: 0.0000720 seconds
2015-01-09T23:56:50.905+0000: 14.147: Total time for which application threads were stopped: 0.0000480 seconds
2015-01-09T23:56:50.911+0000: 14.153: Total time for which application threads were stopped: 0.0000740 seconds
2015-01-09T23:56:50.918+0000: 14.159: Total time for which application threads were stopped: 0.0000690 seconds
2015-01-09T23:56:50.918+0000: 14.159: Total time for which application threads were stopped: 0.0000590 seconds
2015-01-09T23:56:50.918+0000: 14.160: Total time for which application threads were stopped: 0.0000430 seconds
2015-01-09T23:56:50.918+0000: 14.160: Total time for which application threads were stopped: 0.0000500 seconds
2015-01-09T23:56:50.918+0000: 14.160: Total time for which application threads were stopped: 0.0000330 seconds
2015-01-09T23:56:50.918+0000: 14.160: Total time for which application threads were stopped: 0.0000470 seconds
2015-01-09T23:56:50.918+0000: 14.160: Total time for which application threads were stopped: 0.0000490 seconds
2015-01-09T23:56:50.918+0000: 14.160: Total time for which application threads were stopped: 0.0000490 seconds
2015-01-09T23:56:50.918+0000: 14.160: Total time for which application threads were stopped: 0.0000510 seconds
2015-01-09T23:56:50.919+0000: 14.160: Total time for which application threads were stopped: 0.0000560 seconds
2015-01-09T23:56:50.919+0000: 14.160: Total time for which application threads were stopped: 0.0002060 seconds
2015-01-09T23:56:50.923+0000: 14.164: Total time for which application threads were stopped: 0.0000800 seconds
2015-01-09T23:56:50.923+0000: 14.165: Total time for which application threads were stopped: 0.0000770 seconds
2015-01-09T23:56:50.927+0000: 14.169: Total time for which application threads were stopped: 0.0000900 seconds
2015-01-09T23:56:50.932+0000: 14.174: Total time for which application threads were stopped: 0.0000710 seconds
2015-01-09T23:56:50.937+0000: 14.179: Total time for which application threads were stopped: 0.0000770 seconds
2015-01-09T23:56:50.948+0000: 14.190: Total time for which application threads were stopped: 0.0001050 seconds
2015-01-09T23:56:50.949+0000: 14.191: Total time for which application threads were stopped: 0.0000480 seconds
2015-01-09T23:56:50.955+0000: 14.196: Total time for which application threads were stopped: 0.0000770 seconds
2015-01-09T23:56:50.963+0000: 14.205: Total time for which application threads were stopped: 0.0001330 seconds
2015-01-09T23:56:50.968+0000: 14.209: Total time for which application threads were stopped: 0.0000790 seconds
2015-01-09T23:56:50.975+0000: 14.217: Total time for which application threads were stopped: 0.0000720 seconds
2015-01-09T23:56:50.980+0000: 14.222: Total time for which application threads were stopped: 0.0000550 seconds
2015-01-09T23:56:50.982+0000: 14.224: Total time for which application threads were stopped: 0.0001020 seconds
2015-01-09T23:56:50.990+0000: 14.231: Total time for which application threads were stopped: 0.0000980 seconds
2015-01-09T23:56:50.995+0000: 14.236: Total time for which application threads were stopped: 0.0002400 seconds
2015-01-09T23:56:51.744+0000: 14.986: Total time for which application threads were stopped: 0.0003500 seconds
2015-01-09T23:56:51.800+0000: 15.042: Total time for which application threads were stopped: 0.0002970 seconds
2015-01-09T23:56:52.157+0000: 15.398: Total time for which application threads were stopped: 0.0001770 seconds
2015-01-09T23:56:52.157+0000: 15.398: [GC [1 CMS-initial-mark: 0K(9786752K)] 2518487K(14190784K), 0.0728220 secs] [Times: user=0.07 sys=0.00, real=0.07 secs] 
2015-01-09T23:56:52.230+0000: 15.472: Total time for which application threads were stopped: 0.0731200 seconds
2015-01-09T23:56:52.230+0000: 15.472: [CMS-concurrent-mark-start]
2015-01-09T23:56:52.237+0000: 15.479: [CMS-concurrent-mark: 0.006/0.007 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 
2015-01-09T23:56:52.237+0000: 15.479: [CMS-concurrent-preclean-start]
2015-01-09T23:56:52.264+0000: 15.506: [CMS-concurrent-preclean: 0.027/0.027 secs] [Times: user=0.05 sys=0.00, real=0.03 secs] 
2015-01-09T23:56:52.264+0000: 15.506: [CMS-concurrent-abortable-preclean-start]
2015-01-09T23:56:53.231+0000: 16.473: Total time for which application threads were stopped: 0.0014990 seconds
2015-01-09T23:56:54.232+0000: 17.474: Total time for which application threads were stopped: 0.0003570 seconds
{Heap before GC invocations=1 (full 1):
 par new generation   total 4404032K, used 3935994K [0x000000047ae00000, 0x00000005a58a0000, 0x00000005a58a0000)
  eden space 3914752K, 100% used [0x000000047ae00000, 0x0000000569d00000, 0x0000000569d00000)
  from space 489280K,   4% used [0x0000000587ad0000, 0x0000000588f8e938, 0x00000005a58a0000)
  to   space 489280K,   0% used [0x0000000569d00000, 0x0000000569d00000, 0x0000000587ad0000)
 concurrent mark-sweep generation total 9786752K, used 0K [0x00000005a58a0000, 0x00000007fae00000, 0x00000007fae00000)
 concurrent-mark-sweep perm gen total 21248K, used 20465K [0x00000007fae00000, 0x00000007fc2c0000, 0x0000000800000000)
2015-01-09T23:56:56.048+0000: 19.290: [GCBefore GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1252687872
Max   Chunk Size: 1252687872
Number of Blocks: 1
Av.  Block  Size: 1252687872
Tree      Height: 1
Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 0
Max   Chunk Size: 0
Number of Blocks: 0
Tree      Height: 0
2015-01-09T23:56:56.048+0000: 19.290: [ParNew2015-01-09T23:56:56.082+0000: 19.323: [CMS-concurrent-abortable-preclean: 2.462/3.817 secs] [Times: user=8.78 sys=3.18, real=3.81 secs] 

Desired survivor size 250511360 bytes, new threshold 10 (max 10)
- age   1:  180656512 bytes,  180656512 total
- age   2:   12061336 bytes,  192717848 total
: 3935994K->193774K(4404032K), 0.0648380 secs] 3935994K->193774K(14190784K)After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1252687872
Max   Chunk Size: 1252687872
Number of Blocks: 1
Av.  Block  Size: 1252687872
Tree      Height: 1
After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 0
Max   Chunk Size: 0
Number of Blocks: 0
Tree      Height: 0
, 0.0653210 secs] [Times: user=1.16 sys=0.01, real=0.07 secs] 
Heap after GC invocations=2 (full 1):
 par new generation   total 4404032K, used 193774K [0x000000047ae00000, 0x00000005a58a0000, 0x00000005a58a0000)
  eden space 3914752K,   0% used [0x000000047ae00000, 0x000000047ae00000, 0x0000000569d00000)
  from space 489280K,  39% used [0x0000000569d00000, 0x0000000575a3ba70, 0x0000000587ad0000)
  to   space 489280K,   0% used [0x0000000587ad0000, 0x0000000587ad0000, 0x00000005a58a0000)
 concurrent mark-sweep generation total 9786752K, used 0K [0x00000005a58a0000, 0x00000007fae00000, 0x00000007fae00000)
 concurrent-mark-sweep perm gen total 21248K, used 20465K [0x00000007fae00000, 0x00000007fc2c0000, 0x0000000800000000)
}
2015-01-09T23:56:56.114+0000: 19.356: Total time for which application threads were stopped: 0.0671230 seconds
2015-01-09T23:56:56.114+0000: 19.356: [GC[YG occupancy: 227366 K (4404032 K)]2015-01-09T23:56:56.114+0000: 19.356: [Rescan (parallel) , 0.0138510 secs]2015-01-09T23:56:56.128+0000: 19.370: [weak refs processing, 0.0000410 secs]2015-01-09T23:56:56.128+0000: 19.370: [class unloading, 0.0018880 secs]2015-01-09T23:56:56.130+0000: 19.372: [scrub symbol table, 0.0025550 secs]2015-01-09T23:56:56.133+0000: 19.374: [scrub string table, 0.0008870 secs] [1 CMS-remark: 0K(9786752K)] 227366K(14190784K), 0.0205520 secs] [Times: user=0.27 sys=0.00, real=0.02 secs] 
2015-01-09T23:56:56.135+0000: 19.377: Total time for which application threads were stopped: 0.0210750 seconds
2015-01-09T23:56:56.135+0000: 19.377: [CMS-concurrent-sweep-start]
CMS: Large Block: 0x00000005a58c0000; Proximity: 0x0000000000000000 -> 0x00000005a58bfac8
CMS: Large block 0x00000005a58c0000
CMS: Large Block: 0x00000007fc2c0000; Proximity: 0x0000000000000000 -> 0x00000007fc28adf8
CMS: Large block 0x0000000000000000
2015-01-09T23:56:56.141+0000: 19.383: [CMS-concurrent-sweep: 0.006/0.006 secs] [Times: user=0.03 sys=0.00, real=0.00 secs] 
2015-01-09T23:56:56.141+0000: 19.383: Total time for which application threads were stopped: 0.0002570 seconds
2015-01-09T23:56:56.143+0000: 19.385: [CMS-concurrent-reset-start]
2015-01-09T23:56:56.172+0000: 19.413: [CMS-concurrent-reset: 0.029/0.029 secs] [Times: user=0.06 sys=0.00, real=0.02 secs] 
2015-01-09T23:56:57.142+0000: 20.383: Total time for which application threads were stopped: 0.0001820 seconds
2015-01-09T23:56:58.143+0000: 21.384: Total time for which application threads were stopped: 0.0010800 seconds
{Heap before GC invocations=2 (full 1):
 par new generation   total 4404032K, used 4108526K [0x000000047ae00000, 0x00000005a58a0000, 0x00000005a58a0000)
  eden space 3914752K, 100% used [0x000000047ae00000, 0x0000000569d00000, 0x0000000569d00000)
  from space 489280K,  39% used [0x0000000569d00000, 0x0000000575a3ba70, 0x0000000587ad0000)
  to   space 489280K,   0% used [0x0000000587ad0000, 0x0000000587ad0000, 0x00000005a58a0000)
 concurrent mark-sweep generation total 9786752K, used 0K [0x00000005a58a0000, 0x00000007fae00000, 0x00000007fae00000)
 concurrent-mark-sweep perm gen total 34100K, used 20483K [0x00000007fae00000, 0x00000007fcf4d000, 0x0000000800000000)
2015-01-09T23:57:00.042+0000: 23.284: [GCBefore GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1252687872
Max   Chunk Size: 1252687872
Number of Blocks: 1
Av.  Block  Size: 1252687872
Tree      Height: 1
Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1645056
Max   Chunk Size: 1645056
Number of Blocks: 1
Av.  Block  Size: 1645056
Tree      Height: 1
2015-01-09T23:57:00.043+0000: 23.284: [ParNew
Desired survivor size 250511360 bytes, new threshold 1 (max 10)
- age   1:  313722536 bytes,  313722536 total
- age   2:  175041520 bytes,  488764056 total
- age   3:   12025392 bytes,  500789448 total
: 4108526K->489280K(4404032K), 2.8108720 secs] 4108526K->856104K(14190784K)After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1205727830
Max   Chunk Size: 1205727830
Number of Blocks: 1
Av.  Block  Size: 1205727830
Tree      Height: 1
After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1645056
Max   Chunk Size: 1645056
Number of Blocks: 1
Av.  Block  Size: 1645056
Tree      Height: 1
, 2.8113310 secs] [Times: user=16.12 sys=1.16, real=2.82 secs] 
Heap after GC invocations=3 (full 1):
 par new generation   total 4404032K, used 489280K [0x000000047ae00000, 0x00000005a58a0000, 0x00000005a58a0000)
  eden space 3914752K,   0% used [0x000000047ae00000, 0x000000047ae00000, 0x0000000569d00000)
  from space 489280K, 100% used [0x0000000587ad0000, 0x00000005a58a0000, 0x00000005a58a0000)
  to   space 489280K,   0% used [0x0000000569d00000, 0x0000000569d00000, 0x0000000587ad0000)
 concurrent mark-sweep generation total 9786752K, used 366824K [0x00000005a58a0000, 0x00000007fae00000, 0x00000007fae00000)
 concurrent-mark-sweep perm gen total 34100K, used 20483K [0x00000007fae00000, 0x00000007fcf4d000, 0x0000000800000000)
}
2015-01-09T23:57:02.854+0000: 26.096: Total time for which application threads were stopped: 2.8119830 seconds
2015-01-09T23:57:02.880+0000: 26.121: Total time for which application threads were stopped: 0.0002870 seconds
2015-01-09T23:57:02.895+0000: 26.137: Total time for which application threads were stopped: 0.0060630 seconds
2015-01-09T23:57:04.896+0000: 28.138: Total time for which application threads were stopped: 0.0004580 seconds
2015-01-09T23:57:06.898+0000: 30.139: Total time for which application threads were stopped: 0.0012890 seconds
{Heap before GC invocations=3 (full 1):
 par new generation   total 4404032K, used 4404032K [0x000000047ae00000, 0x00000005a58a0000, 0x00000005a58a0000)
  eden space 3914752K, 100% used [0x000000047ae00000, 0x0000000569d00000, 0x0000000569d00000)
  from space 489280K, 100% used [0x0000000587ad0000, 0x00000005a58a0000, 0x00000005a58a0000)
  to   space 489280K,   0% used [0x0000000569d00000, 0x0000000569d00000, 0x0000000587ad0000)
 concurrent mark-sweep generation total 9786752K, used 366824K [0x00000005a58a0000, 0x00000007fae00000, 0x00000007fae00000)
 concurrent-mark-sweep perm gen total 34100K, used 20899K [0x00000007fae00000, 0x00000007fcf4d000, 0x0000000800000000)
2015-01-09T23:57:07.619+0000: 30.860: [GCBefore GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1205727830
Max   Chunk Size: 1205727830
Number of Blocks: 1
Av.  Block  Size: 1205727830
Tree      Height: 1
Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1645056
Max   Chunk Size: 1645056
Number of Blocks: 1
Av.  Block  Size: 1645056
Tree      Height: 1
2015-01-09T23:57:07.619+0000: 30.861: [ParNew
Desired survivor size 250511360 bytes, new threshold 10 (max 10)
- age   1:  184289592 bytes,  184289592 total
: 4404032K->423626K(4404032K), 0.3447260 secs] 4770856K->1233591K(14190784K)After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1148135010
Max   Chunk Size: 1148135010
Number of Blocks: 1
Av.  Block  Size: 1148135010
Tree      Height: 1
After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1645056
Max   Chunk Size: 1645056
Number of Blocks: 1
Av.  Block  Size: 1645056
Tree      Height: 1
, 0.3452080 secs] [Times: user=5.21 sys=0.02, real=0.34 secs] 
Heap after GC invocations=4 (full 1):
 par new generation   total 4404032K, used 423626K [0x000000047ae00000, 0x00000005a58a0000, 0x00000005a58a0000)
  eden space 3914752K,   0% used [0x000000047ae00000, 0x000000047ae00000, 0x0000000569d00000)
  from space 489280K,  86% used [0x0000000569d00000, 0x0000000583ab29d0, 0x0000000587ad0000)
  to   space 489280K,   0% used [0x0000000587ad0000, 0x0000000587ad0000, 0x00000005a58a0000)
 concurrent mark-sweep generation total 9786752K, used 809964K [0x00000005a58a0000, 0x00000007fae00000, 0x00000007fae00000)
 concurrent-mark-sweep perm gen total 34100K, used 20899K [0x00000007fae00000, 0x00000007fcf4d000, 0x0000000800000000)
}
2015-01-09T23:57:07.964+0000: 31.206: Total time for which application threads were stopped: 0.3461110 seconds
2015-01-09T23:57:08.966+0000: 32.208: Total time for which application threads were stopped: 0.0014640 seconds
2015-01-09T23:57:09.966+0000: 33.208: Total time for which application threads were stopped: 0.0003690 seconds
2015-01-09T23:57:11.968+0000: 35.210: Total time for which application threads were stopped: 0.0016350 seconds
{Heap before GC invocations=4 (full 1):
 par new generation   total 4404032K, used 4338378K [0x000000047ae00000, 0x00000005a58a0000, 0x00000005a58a0000)
  eden space 3914752K, 100% used [0x000000047ae00000, 0x0000000569d00000, 0x0000000569d00000)
  from space 489280K,  86% used [0x0000000569d00000, 0x0000000583ab29d0, 0x0000000587ad0000)
  to   space 489280K,   0% used [0x0000000587ad0000, 0x0000000587ad0000, 0x00000005a58a0000)
 concurrent mark-sweep generation total 9786752K, used 809964K [0x00000005a58a0000, 0x00000007fae00000, 0x00000007fae00000)
 concurrent-mark-sweep perm gen total 34100K, used 20920K [0x00000007fae00000, 0x00000007fcf4d000, 0x0000000800000000)
2015-01-09T23:57:12.671+0000: 35.913: [GCBefore GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1148135010
Max   Chunk Size: 1148135010
Number of Blocks: 1
Av.  Block  Size: 1148135010
Tree      Height: 1
Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1645056
Max   Chunk Size: 1645056
Number of Blocks: 1
Av.  Block  Size: 1645056
Tree      Height: 1
2015-01-09T23:57:12.671+0000: 35.913: [ParNew
Desired survivor size 250511360 bytes, new threshold 1 (max 10)
- age   1:  353171168 bytes,  353171168 total
- age   2:  147032624 bytes,  500203792 total
: 4338378K->489280K(4404032K), 0.7500100 secs] 5148343K->1780814K(14190784K)After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1086999941
Max   Chunk Size: 1086999941
Number of Blocks: 1
Av.  Block  Size: 1086999941
Tree      Height: 1
After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1645056
Max   Chunk Size: 1645056
Number of Blocks: 1
Av.  Block  Size: 1645056
Tree      Height: 1
, 0.7505630 secs] [Times: user=15.17 sys=0.00, real=0.75 secs] 
Heap after GC invocations=5 (full 1):
 par new generation   total 4404032K, used 489280K [0x000000047ae00000, 0x00000005a58a0000, 0x00000005a58a0000)
  eden space 3914752K,   0% used [0x000000047ae00000, 0x000000047ae00000, 0x0000000569d00000)
  from space 489280K, 100% used [0x0000000587ad0000, 0x00000005a58a0000, 0x00000005a58a0000)
  to   space 489280K,   0% used [0x0000000569d00000, 0x0000000569d00000, 0x0000000587ad0000)
 concurrent mark-sweep generation total 9786752K, used 1291534K [0x00000005a58a0000, 0x00000007fae00000, 0x00000007fae00000)
 concurrent-mark-sweep perm gen total 34100K, used 20920K [0x00000007fae00000, 0x00000007fcf4d000, 0x0000000800000000)
}
2015-01-09T23:57:13.422+0000: 36.664: Total time for which application threads were stopped: 0.7513670 seconds
2015-01-09T23:57:13.667+0000: 36.909: Total time for which application threads were stopped: 0.0015250 seconds
{Heap before GC invocations=5 (full 1):
 par new generation   total 4404032K, used 4404032K [0x000000047ae00000, 0x00000005a58a0000, 0x00000005a58a0000)
  eden space 3914752K, 100% used [0x000000047ae00000, 0x0000000569d00000, 0x0000000569d00000)
  from space 489280K, 100% used [0x0000000587ad0000, 0x00000005a58a0000, 0x00000005a58a0000)
  to   space 489280K,   0% used [0x0000000569d00000, 0x0000000569d00000, 0x0000000587ad0000)
 concurrent mark-sweep generation total 9786752K, used 1291534K [0x00000005a58a0000, 0x00000007fae00000, 0x00000007fae00000)
 concurrent-mark-sweep perm gen total 34100K, used 20933K [0x00000007fae00000, 0x00000007fcf4d000, 0x0000000800000000)
2015-01-09T23:57:16.341+0000: 39.583: [GCBefore GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1086999941
Max   Chunk Size: 1086999941
Number of Blocks: 1
Av.  Block  Size: 1086999941
Tree      Height: 1
Before GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1645056
Max   Chunk Size: 1645056
Number of Blocks: 1
Av.  Block  Size: 1645056
Tree      Height: 1
2015-01-09T23:57:16.341+0000: 39.583: [ParNew
Desired survivor size 250511360 bytes, new threshold 10 (max 10)
- age   1:  132443984 bytes,  132443984 total
: 4404032K->422270K(4404032K), 0.2780820 secs] 5695566K->2186197K(14190784K)After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1025829756
Max   Chunk Size: 1025829756
Number of Blocks: 1
Av.  Block  Size: 1025829756
Tree      Height: 1
After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 1645056
Max   Chunk Size: 1645056
Number of Blocks: 1
Av.  Block  Size: 1645056
Tree      Height: 1
, 0.2787060 secs] [Times: user=4.36 sys=0.05, real=0.28 secs] 
Heap after GC invocations=6 (full 1):
 par new generation   total 4404032K, used 422270K [0x000000047ae00000, 0x00000005a58a0000, 0x00000005a58a0000)
  eden space 3914752K,   0% used [0x000000047ae00000, 0x000000047ae00000, 0x0000000569d00000)
  from space 489280K,  86% used [0x0000000569d00000, 0x000000058395f8f0, 0x0000000587ad0000)
  to   space 489280K,   0% used [0x0000000587ad0000, 0x0000000587ad0000, 0x00000005a58a0000)
 concurrent mark-sweep generation total 9786752K, used 1763927K [0x00000005a58a0000, 0x00000007fae00000, 0x00000007fae00000)
 concurrent-mark-sweep perm gen total 34100K, used 20933K [0x00000007fae00000, 0x00000007fcf4d000, 0x0000000800000000)
}

[chewiebug]

I have pushed a fix to the repository and built the latest SNAPSHOT release. Does it work now?

[krishna81m]

Checking.
On Jan 16, 2015 2:36 PM, "chewiebug" notifications@github.com wrote:

I have pushed a fix to the repository and built the latest SNAPSHOT
release. Does it work now?

—
Reply to this email directly or view it on GitHub
#127 (comment).

[krishna81m]

Awesome works now and able to see them, wonder if there is a way to get event details when I click a data point or "at least the exact time when the event happened on top" instead of hours elapsed so I can back track the spikes in my logs.

[krishna81m]

Also awesome would be to adjust the time scale as few outliers (> few seconds) can completely mess up the plot.

[krishna81m]

Our GC configuration is pretty simple and uses fixed values instead of variable ranges, not sure when variable ranges to let JVM decide the sizes would make more sense? Anyways, in our write/read intensive cassandra with some caching, we noticed our (all the way below) 14 GB heap, new ratio=2, tenuringThreshold=10 and survivor ratio=8 or about 250 MB is working fine because most read data generated garbage remains in survivor stays for a long time to reach 250 MB at >80% of the time, but is this a good idea to keep such read related data and cache in survivor spaces as very little amount 40 MB alone is filled up in survivor space? In this case there is no point in increasing survivor space as we don’t fill up but what about increasing tenured ratio to > 15, is it ok to live with 20-40ms par new GCs every half a min or reduce this size and tenuring ratio as most of the time only about 1-10 MB is surviving and flushed to old gen.
Desired survivor size 250511360 bytes, new threshold 10 (max 10)
– age 1: 21011760 bytes, 21011760 total
– age 2: 4261448 bytes, 25273208 total
– age 3: 2583752 bytes, 27856960 total
– age 4: 1939944 bytes, 29796904 total
– age 5: 1933296 bytes, 31730200 total
– age 6: 1876272 bytes, 33606472 total
– age 7: 1900928 bytes, 35507400 total
– age 8: 1756536 bytes, 37263936 total
– age 9: 2162784 bytes, 39426720 total
– age 10: 1401480 bytes, 40828200 total

-XX:+UseThreadPriorities
-XX:ThreadPriorityPolicy=42
-Xms14G -Xmx14G
-XX:+HeapDumpOnOutOfMemoryError
-XX:NewRatio=2 -XX:MaxTenuringThreshold=10 -XX:+DisableExplicitGC -Xss250k
-XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+CMSParallelRemarkEnabled
-XX:SurvivorRatio=8 -XX:CMSInitiatingOccupancyFraction=75 -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseTLAB -XX:+UseCondCardMark -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -XX:+PrintTenuringDistribution -XX:+PrintGCApplicationStoppedTime -XX:+PrintPromotionFailure -XX:PrintFLSStatistics=1

[krishna81m]

Wanted to use GCViewer to understand this one outlier, however, I still don't understand why the GC times are more than 4 seconds here although two CMS seem to happen and complete without any problem and the heap really did not hit the full limit?

[chewiebug]

Thanks - I am happy to know, there are poeple out there, who have a
benefit in using GCViewer!

There is already a feature request for showing exact details, when
hovering on a point (#114) and another requesting adjustment of the time
scale (#5 - partial log file analysis). They still wait for some
implementer do work on it.

Concerning your tuning question: I'd need to have the part of your log,
which contains that outlier to maybe get an idea, why it is there (you
could send it to gcviewer-info@googlegroups.com - please compress, there
is a size limit).

Do you happen to know hotspot-gc-use@openjdk.java.net? That's the
mailing list to go to with your tuning question. There are quite a few
gc tuning experts around.

Best regards,
Jörg

[krishna81m]

Just sent, thanks.

[chewiebug]

I close this issue, since the GCViewer related part is fixed.