Description
Hi,
First of all, it would be great if gcviewer could ignore the "G1Ergonomics" messages from the -XX:+PrintAdaptiveSizePolicy setting.
Second, I do have a strange bug while parsing gc log files.
This one works fine :
2015-02-13T17:12:01.182+0100: 195,970: Total time for which application threads were stopped: 0,0001000 seconds
2015-02-13T17:12:01.265+0100: 196,053: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 20447232 bytes, new threshold 15 (max 15)
- age 1: 503304 bytes, 503304 total
- age 2: 43928 bytes, 547232 total
, 0,0331820 secs]
[Parallel Time: 22,5 ms, GC Workers: 4]
[GC Worker Start (ms): Min: 196053,3, Avg: 196053,3, Max: 196053,4, Diff: 0,1]
[Ext Root Scanning (ms): Min: 11,0, Avg: 11,5, Max: 12,1, Diff: 1,1, Sum: 46,1]
[Update RS (ms): Min: 0,6, Avg: 1,1, Max: 1,5, Diff: 0,9, Sum: 4,3]
[Processed Buffers: Min: 12, Avg: 19,0, Max: 30, Diff: 18, Sum: 76]
[Scan RS (ms): Min: 0,9, Avg: 1,0, Max: 1,0, Diff: 0,1, Sum: 3,8]
[Code Root Scanning (ms): Min: 0,0, Avg: 0,0, Max: 0,1, Diff: 0,0, Sum: 0,1]
[Object Copy (ms): Min: 8,4, Avg: 8,7, Max: 8,9, Diff: 0,5, Sum: 34,9]
[Termination (ms): Min: 0,0, Avg: 0,0, Max: 0,0, Diff: 0,0, Sum: 0,0]
[GC Worker Other (ms): Min: 0,0, Avg: 0,0, Max: 0,0, Diff: 0,0, Sum: 0,1]
[GC Worker Total (ms): Min: 22,3, Avg: 22,4, Max: 22,4, Diff: 0,1, Sum: 89,4]
[GC Worker End (ms): Min: 196075,7, Avg: 196075,7, Max: 196075,7, Diff: 0,0]
[Code Root Fixup: 0,0 ms]
[Code Root Migration: 0,1 ms]
[Clear CT: 0,5 ms]
[Other: 10,1 ms]
[Choose CSet: 0,0 ms]
[Ref Proc: 8,6 ms]
[Ref Enq: 0,2 ms]
[Free CSet: 1,0 ms]
[Eden: 304,0M(304,0M)->0,0B(279,0M) Survivors: 3072,0K->28,0M Heap: 418,0M(512,0M)->139,3M(512,0M)]
[Times: user=0,09 sys=0,00, real=0,03 secs]
2015-02-13T17:12:01.299+0100: 196,087: Total time for which application threads were stopped: 0,0338710 seconds
But, this one doesn't work :
2015-02-13T17:12:01.196+0100: 195,854: Total time for which application threads were stopped: 0,0000890 seconds
2015-02-13T17:12:01.729+0100: 196,388: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 20447232 bytes, new threshold 15 (max 15)
- age 1: 6700576 bytes, 6700576 total
- age 2: 10504568 bytes, 17205144 total
- age 3: 320040 bytes, 17525184 total
- age 4: 92336 bytes, 17617520 total
, 0,0608680 secs]
[Parallel Time: 48,4 ms, GC Workers: 4]
[GC Worker Start (ms): Min: 196388,7, Avg: 196390,4, Max: 196394,8, Diff: 6,1]
[Ext Root Scanning (ms): Min: 14,1, Avg: 16,5, Max: 20,1, Diff: 6,0, Sum: 66,0]
[Update RS (ms): Min: 0,0, Avg: 0,6, Max: 2,2, Diff: 2,2, Sum: 2,2]
[Processed Buffers: Min: 0, Avg: 20,8, Max: 83, Diff: 83, Sum: 83]
[Scan RS (ms): Min: 0,3, Avg: 1,4, Max: 2,5, Diff: 2,2, Sum: 5,7]
[Code Root Scanning (ms): Min: 0,0, Avg: 0,1, Max: 0,1, Diff: 0,1, Sum: 0,2]
[Object Copy (ms): Min: 26,6, Avg: 27,4, Max: 28,5, Diff: 1,9, Sum: 109,6]
[Termination (ms): Min: 0,0, Avg: 0,0, Max: 0,0, Diff: 0,0, Sum: 0,1]
[GC Worker Other (ms): Min: 0,0, Avg: 0,0, Max: 0,1, Diff: 0,0, Sum: 0,2]
[GC Worker Total (ms): Min: 41,6, Avg: 46,0, Max: 47,8, Diff: 6,2, Sum: 183,9]
[GC Worker End (ms): Min: 196436,4, Avg: 196436,4, Max: 196436,4, Diff: 0,0]
[Code Root Fixup: 0,1 ms]
[Code Root Migration: 0,2 ms]
[Clear CT: 0,3 ms]
[Other: 11,8 ms]
[Choose CSet: 0,0 ms]
[Ref Proc: 10,5 ms]
[Ref Enq: 0,3 ms]
[Free CSet: 0,7 ms]
[Eden: 281,0M(281,0M)->0,0B(180,0M) Survivors: 26,0M->39,0M Heap: 398,8M(512,0M)->138,5M(512,0M)]
[Times: user=0,20 sys=0,00, real=0,06 secs]
2015-02-13T17:12:01.791+0100: 196,450: Total time for which application threads were stopped: 0,0624330 seconds
I couldn't see any structural difference between these two samples.
Here are the error messages:
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.ArrayIndexOutOfBoundsException) Line 245: 2015-02-13T17:12:01.729+0100: 196,388: [GC pause (G1 Evacuation Pause) (young)
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: '' Line 251: , 0,0608680 secs]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Parallel Time' Line 252: [Parallel Time: 48,4 ms, GC Workers: 4]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'GC Worker Start (ms)' Line 253: [GC Worker Start (ms): Min: 196388,7, Avg: 196390,4, Max: 196394,8, Diff: 6,1]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Ext Root Scanning (ms)' Line 254: [Ext Root Scanning (ms): Min: 14,1, Avg: 16,5, Max: 20,1, Diff: 6,0, Sum: 66,0]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Update RS (ms)' Line 255: [Update RS (ms): Min: 0,0, Avg: 0,6, Max: 2,2, Diff: 2,2, Sum: 2,2]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Processed Buffers' Line 256: [Processed Buffers: Min: 0, Avg: 20,8, Max: 83, Diff: 83, Sum: 83]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Scan RS (ms)' Line 257: [Scan RS (ms): Min: 0,3, Avg: 1,4, Max: 2,5, Diff: 2,2, Sum: 5,7]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Code Root Scanning (ms)' Line 258: [Code Root Scanning (ms): Min: 0,0, Avg: 0,1, Max: 0,1, Diff: 0,1, Sum: 0,2]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Object Copy (ms)' Line 259: [Object Copy (ms): Min: 26,6, Avg: 27,4, Max: 28,5, Diff: 1,9, Sum: 109,6]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Termination (ms)' Line 260: [Termination (ms): Min: 0,0, Avg: 0,0, Max: 0,0, Diff: 0,0, Sum: 0,1]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'GC Worker Other (ms)' Line 261: [GC Worker Other (ms): Min: 0,0, Avg: 0,0, Max: 0,1, Diff: 0,0, Sum: 0,2]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'GC Worker Total (ms)' Line 262: [GC Worker Total (ms): Min: 41,6, Avg: 46,0, Max: 47,8, Diff: 6,2, Sum: 183,9]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'GC Worker End (ms)' Line 263: [GC Worker End (ms): Min: 196436,4, Avg: 196436,4, Max: 196436,4, Diff: 0,0]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Code Root Fixup' Line 264: [Code Root Fixup: 0,1 ms]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Code Root Migration' Line 265: [Code Root Migration: 0,2 ms]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Clear CT' Line 266: [Clear CT: 0,3 ms]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Other' Line 267: [Other: 11,8 ms]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Choose CSet' Line 268: [Choose CSet: 0,0 ms]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Ref Proc' Line 269: [Ref Proc: 10,5 ms]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Ref Enq' Line 270: [Ref Enq: 0,3 ms]
AVERTISSEMENT [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.UnknownGcTypeException: Unknown gc type: 'Free CSet' Line 271: [Free CSet: 0,7 ms]
Any clue ?