Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

JDK1.6 parser cannot skip CMSStatistics=2 lines #33

Closed
ecki opened this issue Aug 25, 2012 · 4 comments
Closed

JDK1.6 parser cannot skip CMSStatistics=2 lines #33

ecki opened this issue Aug 25, 2012 · 4 comments
Assignees
Milestone

Comments

@ecki
Copy link
Contributor

ecki commented Aug 25, 2012

The following import warnings appear when reading a JDK1.6 or JDK1.7 file with -XX:CMSStatistics=2:

Information [DataReaderFactory]: File format: Sun 1.6.x
Information [DataReaderSun1_6_0]: Reading Sun / Oracle 1.4.x / 1.5.x / 1.6.x / 1.7.x format...
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 3: Finished cms space scanning in 0th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 4: Finished cms space scanning in 1th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 5: Finished perm space scanning in 1th thread: 0.042 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 6: Finished perm space scanning in 0th thread: 0.047 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 7: Finished work stealing in 0th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 8: Finished work stealing in 1th thread: 0.005 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 11:  (cardTable: 1054 cards, re-scanned 1054 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 14:  (cardTable: 922 cards, re-scanned 922 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 15:  (cardTable: 667 cards, re-scanned 667 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 16:  (cardTable: 127 cards, re-scanned 127 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 17:  (cardTable: 186 cards, re-scanned 186 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 18:  (cardTable: 44 cards, re-scanned 44 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 19:  (cardTable: 1767 cards, re-scanned 1767 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 20:  (cardTable: 670 cards, re-scanned 670 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 21:  (cardTable: 341 cards, re-scanned 341 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 22:  (cardTable: 709 cards, re-scanned 709 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 23:  (cardTable: 879 cards, re-scanned 879 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 24:  (cardTable: 340 cards, re-scanned 340 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 25:  (cardTable: 1047 cards, re-scanned 1047 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 26:  (cardTable: 1649 cards, re-scanned 1649 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 27:  (cardTable: 1949 cards, re-scanned 1949 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 28:  (cardTable: 1497 cards, re-scanned 1497 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 29:  (cardTable: 913 cards, re-scanned 913 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 30:  (cardTable: 907 cards, re-scanned 907 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 31:  (cardTable: 1688 cards, re-scanned 1688 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 32:  (cardTable: 1075 cards, re-scanned 1075 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 33:  (cardTable: 316 cards, re-scanned 316 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 34:  (cardTable: 391 cards, re-scanned 391 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 35:  (cardTable: 1514 cards, re-scanned 1514 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 36:  (cardTable: 820 cards, re-scanned 820 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 37:  (cardTable: 566 cards, re-scanned 566 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 38:  (cardTable: 23 cards, re-scanned 23 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 39:  (cardTable: 362 cards, re-scanned 362 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 40:  (cardTable: 397 cards, re-scanned 397 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 41:  (cardTable: 1053 cards, re-scanned 1053 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 42:  (cardTable: 1887 cards, re-scanned 1887 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 43:  (cardTable: 1682 cards, re-scanned 1682 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 44:  (cardTable: 2194 cards, re-scanned 2194 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 45:  (cardTable: 1437 cards, re-scanned 1437 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 46:  (cardTable: 946 cards, re-scanned 946 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 47:  (cardTable: 830 cards, re-scanned 830 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 48:  (cardTable: 677 cards, re-scanned 677 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 49:  (cardTable: 266 cards, re-scanned 266 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 50:  (cardTable: 1940 cards, re-scanned 1940 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 51:  [37 iterations, 2 waits, 34678 cards)] 2012-08-23T17:42:23.373-0800: [CMS-concurrent-abortable-preclean: 4.350/5.107 secs] (CMS-concurrent-abortable-preclean yielded 426685 times)
Warnung [AbstractDataReaderSun]: unknown memoryunit 't' in line 2012-08-23T17:42:23.373-0800: [GC[YG occupancy: 341381 K (3774912 K)][Rescan (parallel)  (Survivor:571chunks) Finished young gen rescan work in 2th thread: 0.001 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NumberFormatException: 2012-08-23T17:42:23.373-0800: [GC[YG occupancy: 341381 K (3774912 K)][Rescan (parallel)  (Survivor:571chunks) Finished young gen rescan work in 2th thread: 0.001 sec) Line 53: 2012-08-23T17:42:23.373-0800: [GC[YG occupancy: 341381 K (3774912 K)][Rescan (parallel)  (Survivor:571chunks) Finished young gen rescan work in 2th thread: 0.001 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 54: Finished young gen rescan work in 0th thread: 0.002 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 55: Finished young gen rescan work in 3th thread: 0.001 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 56: Finished young gen rescan work in 4th thread: 0.001 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 57: Finished remaining root rescan work in 2th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 58: Finished dirty card rescan work in 2th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 59: Finished remaining root rescan work in 3th thread: 0.001 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 60: Finished dirty card rescan work in 3th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 61: Finished remaining root rescan work in 0th thread: 0.001 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 62: Finished dirty card rescan work in 0th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 63: Finished remaining root rescan work in 4th thread: 0.002 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 64: Finished dirty card rescan work in 4th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 65: Finished young gen rescan work in 1th thread: 0.011 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 66: Finished remaining root rescan work in 1th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 67: Finished dirty card rescan work in 1th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 68: Finished young gen rescan work in 7th thread: 0.027 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 69: Finished remaining root rescan work in 7th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 70: Finished dirty card rescan work in 7th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 71: Finished young gen rescan work in 6th thread: 0.065 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 72: Finished remaining root rescan work in 6th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 73: Finished dirty card rescan work in 6th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 74: Finished young gen rescan work in 5th thread: 0.068 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 75: Finished remaining root rescan work in 5th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 76: Finished dirty card rescan work in 5th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 77: Finished work stealing in 5th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 78: Finished work stealing in 6th thread: 0.003 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 79: Finished work stealing in 3th thread: 0.066 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 80: Finished work stealing in 0th thread: 0.066 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 81: Finished work stealing in 4th thread: 0.065 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 82: Finished work stealing in 7th thread: 0.041 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 83: Finished work stealing in 1th thread: 0.058 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 84: Finished work stealing in 2th thread: 0.066 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 85: , 0.0692650 secs][weak refs processing, 0.0000150 secs][class unloading, 0.0066440 secs][scrub symbol & string tables, 0.0049270 secs] [1 CMS-remark: 0K(4194304K)] 341381K(7969216K), 0.0816280 secs] [Times: user=0.52 sys=0.00, real=0.09 secs] 
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 93: Finished cms space scanning in 0th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 94: Finished cms space scanning in 1th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 95: Finished perm space scanning in 0th thread: 0.236 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 96: Finished perm space scanning in 1th thread: 0.240 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 97: Finished work stealing in 1th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 98: Finished work stealing in 0th thread: 0.003 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 101:  (cardTable: 38176 cards, re-scanned 38176 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 104:  (cardTable: 14401 cards, re-scanned 14401 cards, 1 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 106:  (cardTable: 777 cards, re-scanned 70061 cards, 2 iterations)
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 107:  [2 iterations, 0 waits, 84462 cards)] 2012-08-23T17:43:13.231-0800: [CMS-concurrent-abortable-preclean: 4.885/5.810 secs] (CMS-concurrent-abortable-preclean yielded 226971 times)
Warnung [AbstractDataReaderSun]: unknown memoryunit 't' in line 2012-08-23T17:43:13.233-0800: [GC[YG occupancy: 402755 K (3774912 K)][Rescan (parallel)  (Survivor:21chunks) Finished young gen rescan work in 3th thread: 0.048 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NumberFormatException: 2012-08-23T17:43:13.233-0800: [GC[YG occupancy: 402755 K (3774912 K)][Rescan (parallel)  (Survivor:21chunks) Finished young gen rescan work in 3th thread: 0.048 sec) Line 109: 2012-08-23T17:43:13.233-0800: [GC[YG occupancy: 402755 K (3774912 K)][Rescan (parallel)  (Survivor:21chunks) Finished young gen rescan work in 3th thread: 0.048 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 110: Finished young gen rescan work in 2th thread: 0.049 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 111: Finished young gen rescan work in 6th thread: 0.049 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 112: Finished young gen rescan work in 4th thread: 0.049 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 113: Finished young gen rescan work in 0th thread: 0.049 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 114: Finished young gen rescan work in 7th thread: 0.048 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 115: Finished remaining root rescan work in 4th thread: 0.001 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 116: Finished remaining root rescan work in 3th thread: 0.001 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 117: Finished remaining root rescan work in 2th thread: 0.001 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 118: Finished remaining root rescan work in 7th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 119: Finished dirty card rescan work in 2th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 120: Finished dirty card rescan work in 4th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 121: Finished dirty card rescan work in 7th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 122: Finished dirty card rescan work in 3th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 123: Finished remaining root rescan work in 0th thread: 0.001 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 124: Finished dirty card rescan work in 0th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 125: Finished young gen rescan work in 1th thread: 0.050 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 126: Finished remaining root rescan work in 1th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 127: Finished dirty card rescan work in 1th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 128: Finished remaining root rescan work in 6th thread: 0.003 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 129: Finished dirty card rescan work in 6th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 130: Finished young gen rescan work in 5th thread: 0.058 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 131: Finished remaining root rescan work in 5th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 132: Finished dirty card rescan work in 5th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 133: Finished work stealing in 5th thread: 0.000 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 134: Finished work stealing in 3th thread: 0.009 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 135: Finished work stealing in 7th thread: 0.009 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 136: Finished work stealing in 6th thread: 0.007 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 137: Finished work stealing in 4th thread: 0.009 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 138: Finished work stealing in 0th thread: 0.009 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 139: Finished work stealing in 2th thread: 0.009 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 140: Finished work stealing in 1th thread: 0.009 sec
Warnung [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NullPointerException) Line 141: , 0.0594580 secs][weak refs processing, 0.0000180 secs][class unloading, 0.0141700 secs][scrub symbol & string tables, 0.0189250 secs] [1 CMS-remark: 0K(4194304K)] 402755K(7969216K), 0.0957690 secs] [Times: user=0.50 sys=0.00, real=0.09 secs] 
Information [DataReaderSun1_6_0]: Done reading.
@chewiebug
Copy link
Owner

Hi Bernd,

Could you please test my fix with one of your log files?

Regards, Jörg

@chewiebug
Copy link
Owner

bernds comment to the above commit

Hmm, it improved things and I have some of the log files which are not parsed with no errors, and I also see both CMS STW Events with the same count.

However I have one file which produces some warnings, here are the warnings produced:

WARNING [AbstractDataReaderSun]: unknown memoryunit '-' in line 2012-09-27T10:35:13.591-0800: [GC[YG occupancy: 10342869 K (15099520 K)]2012-09-27T10:35:13.644-0800: [CMS-concurrent-sweep: 0.013/0.029 secs] (CMS-concurrent-sweep yielded 6551 times)
WARNING [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NumberFormatException: 2012-09-27T10:35:13.591-0800: [GC[YG occupancy: 10342869 K (15099520 K)]2012-09-27T10:35:13.644-0800: [CMS-concurrent-sweep: 0.013/0.029 secs] (CMS-concurrent-sweep yielded 6551 times)) Line 7: 2012-09-27T10:35:13.591-0800: [GC[YG occupancy: 10342869 K (15099520 K)]2012-09-27T10:35:13.644-0800: [CMS-concurrent-sweep: 0.013/0.029 secs] (CMS-concurrent-sweep yielded 6551 times)
WARNING [AbstractDataReaderSun]: unknown memoryunit '-' in line 2012-09-27T10:36:08.081-0800: [GC[YG occupancy: 3366851 K (15099520 K)]2012-09-27T10:36:08.360-0800: [CMS-concurrent-sweep: 0.075/0.077 secs] (CMS-concurrent-sweep yielded 29 times)
WARNING [DataReaderSun1_6_0]: com.tagtraum.perf.gcviewer.imp.ParseException: Error parsing entry (java.lang.NumberFormatException: 2012-09-27T10:36:08.081-0800: [GC[YG occupancy: 3366851 K (15099520 K)]2012-09-27T10:36:08.360-0800: [CMS-concurrent-sweep: 0.075/0.077 secs] (CMS-concurrent-sweep yielded 29 times)) Line 19: 2012-09-27T10:36:08.081-0800: [GC[YG occupancy: 3366851 K (15099520 K)]2012-09-27T10:36:08.360-0800: [CMS-concurrent-sweep: 0.075/0.077 secs] (CMS-concurrent-sweep yielded 29 times)
INFO [DataReaderSun1_6_0]: Done reading.

and here are parsed gc log lines:

2012-09-27T10:35:13.250-0800: [GC [ParNew: 1073746K->8056K(15099520K), 0.0198690 secs] 1073746K->8056K(48653952K), 0.0200020 secs] [Times: user=0.13 sys=0.01, real=0.02 secs] 
2012-09-27T10:35:13.271-0800: [GC [1 CMS-initial-mark: 0K(33554432K)] 8056K(48653952K), 0.0093810 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 
2012-09-27T10:35:13.333-0800: [CMS-concurrent-mark: 0.025/0.053 secs] (CMS-concurrent-mark yielded 24 times)
2012-09-27T10:35:13.448-0800: [CMS-concurrent-preclean: 0.114/0.115 secs] (CMS-concurrent-preclean yielded 85 times)
 [1 iterations, 1 waits, 19 cards)] 2012-09-27T10:35:13.589-0800: [CMS-concurrent-abortable-preclean: 0.124/0.141 secs] (CMS-concurrent-abortable-preclean yielded 4273 times)
2012-09-27T10:35:13.591-0800: [GC[YG occupancy: 10342869 K (15099520 K)]2012-09-27T10:35:13.591-0800: [GC [ParNew: 10342869K->14005K(15099520K), 0.0122450 secs] 10342869K->14005K(48653952K), 0.0124520 secs] [Times: user=0.27 sys=0.01, real=0.01 secs] 
2012-09-27T10:35:13.644-0800: [CMS-concurrent-sweep: 0.013/0.029 secs] (CMS-concurrent-sweep yielded 6551 times)
2012-09-27T10:35:14.032-0800: [CMS-concurrent-reset: 0.386/0.388 secs] (CMS-concurrent-reset yielded 5 times)
2012-09-27T10:35:25.958-0800: [GC [ParNew: 13435829K->84502K(15099520K), 0.0303790 secs] 13435829K->84502K(48653952K), 0.0307270 secs] [Times: user=0.66 sys=0.18, real=0.03 secs] 
2012-09-27T10:35:32.961-0800: [GC [ParNew: 13505917K->170281K(15099520K), 0.0469210 secs] 13505917K->170281K(48653952K), 0.0473510 secs] [Times: user=1.50 sys=0.43, real=0.05 secs] 
2012-09-27T10:35:41.126-0800: [GC [ParNew: 13592105K->255293K(15099520K), 0.1072250 secs] 13592105K->263521K(48653952K), 0.1077610 secs] [Times: user=1.32 sys=0.16, real=0.10 secs] 
2012-09-27T10:35:51.151-0800: [GC [ParNew: 13677117K->331384K(15099520K), 0.0487500 secs] 13685345K->340716K(48653952K), 0.0492990 secs] [Times: user=1.38 sys=0.24, real=0.04 secs] 
2012-09-27T10:35:58.106-0800: [GC [1 CMS-initial-mark: 9331K(33554432K)] 8166192K(48653952K), 1.7910680 secs] [Times: user=1.77 sys=0.00, real=1.79 secs] 
2012-09-27T10:35:59.961-0800: [CMS-concurrent-mark: 0.036/0.059 secs] (CMS-concurrent-mark yielded 18 times)
2012-09-27T10:36:00.103-0800: [CMS-concurrent-preclean: 0.139/0.142 secs] (CMS-concurrent-preclean yielded 0 times)
2012-09-27T10:36:04.037-0800: [GC [ParNew: 13753208K->385654K(15099520K), 0.3407720 secs] 13762540K->466944K(48653952K), 0.3416910 secs] [Times: user=2.26 sys=0.33, real=0.34 secs] 
 CMS: abort preclean due to time  [3 iterations, 0 waits, 181035 cards)] 2012-09-27T10:36:08.080-0800: [CMS-concurrent-abortable-preclean: 7.404/7.977 secs] (CMS-concurrent-abortable-preclean yielded 232855 times)
2012-09-27T10:36:08.081-0800: [GC[YG occupancy: 3366851 K (15099520 K)]2012-09-27T10:36:08.081-0800: [GC [ParNew: 3366851K->369888K(15099520K), 0.1387480 secs] 3448141K->511931K(48653952K), 0.1395510 secs] [Times: user=1.66 sys=0.18, real=0.14 secs] 
2012-09-27T10:36:08.360-0800: [CMS-concurrent-sweep: 0.075/0.077 secs] (CMS-concurrent-sweep yielded 29 times)
2012-09-27T10:36:08.517-0800: [CMS-concurrent-reset: 0.149/0.157 secs] (CMS-concurrent-reset yielded 6 times)
2012-09-27T10:37:25.246-0800: [GC [ParNew: 13791744K->1500886K(15099520K), 15.1588390 secs] 13933770K->1694355K(48653952K), 15.1622180 secs] [Times: user=8.56 sys=789.17, real=15.17 secs]

chewiebug added a commit that referenced this issue Oct 26, 2012
@chewiebug
Copy link
Owner

Hi Bernd

Good Test, thank you! It looks like you combined -XX:PrintCMSStatistics=2 with -XX:CMSScavengeBeforeRemark. I have pushed a commit that is able to parse this combination.

The sample lines you posted could still not be parsed, however. I miss most of the remark event in it. I'd expect at least one more line after a line containing YG occupancy containing the rest of the information about the remark event. Could it be that you dropped a few lines of the original log when posting your finding?

Regards, Jörg

@ghost ghost assigned chewiebug Nov 10, 2012
@chewiebug
Copy link
Owner

Hi Bernd,

I close this issue having pushed a fix to github. If you still find warnings parsing logs with -XX:PrintCMSStatistics=2 please reopen the issue.

Regards, Jörg

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants