Skip to content

Commit 327a64e

Browse files
chewiebugchewiebug
committed
#198 update parsing of Shenandoah algorithm (jdk8u232, jdk11.0.4)
1 parent 5c88ab5 commit 327a64e

17 files changed

+717
-19873
lines changed

‎src/main/java/com/tagtraum/perf/gcviewer/imp/AbstractDataReaderSun.java‎

Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -414,6 +414,7 @@ else if (datestamp != null && pos.getFirstDateStamp() != null) {
414414
* @param trimLine if <code>true</code> then trim <code>line</code>
415415
* @return <code>true</code>, if <code>line</code> starts with one of the strings in
416416
* <code>lineStartStrings</code>
417+
* @see #contains(String, List, boolean)
417418
*/
418419
protected boolean startsWith(String line, List<String> lineStartStrings, boolean trimLine) {
419420
String lineToTest = trimLine ? line.trim() : line;
@@ -426,6 +427,24 @@ protected boolean startsWith(String line, List<String> lineStartStrings, boolean
426427
return false;
427428
}
428429

430+
/**
431+
* Tests if <code>line</code> starts with one of the strings in <code>lineStartStrings</code>.
432+
* If <code>trimLine</code> is <code>true</code>, then <code>line</code> is trimmed first.
433+
*
434+
* @param line line to be checked against
435+
* @param lineContainsStrings list of strings to check
436+
* @param trimLine if <code>true</code> then trim <code>line</code>
437+
* @return <code>true</code>, if <code>line</code> contains one of the strings in
438+
* <code>lineContainsStrings</code>
439+
* @see #startsWith(String, List, boolean)
440+
*/
441+
protected boolean contains(String line, List<String> lineContainsStrings, boolean trimLine) {
442+
String lineToTest = trimLine ? line.trim() : line;
443+
return lineContainsStrings.stream()
444+
.filter(entry -> lineToTest.contains(entry))
445+
.count() > 0;
446+
}
447+
429448
/**
430449
* Parses a datestamp in <code>line</code> at <code>pos</code>.
431450
*

‎src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderSun1_6_0.java‎

Lines changed: 78 additions & 49 deletions
Original file line numberDiff line numberDiff line change
@@ -75,51 +75,85 @@ public class DataReaderSun1_6_0 extends AbstractDataReaderSun {
7575
private static final String TIMES = " [Times";
7676
private static final String ADAPTIVE_PATTERN = "AdaptiveSize";
7777

78-
private static final List<String> EXCLUDE_STRINGS = new LinkedList<String>();
78+
/** lines to be excluded, if they start with a string of this list */
79+
private static final List<String> EXCLUDE_STRINGS_LINE_START = new LinkedList<String>();
80+
/** lines to be excluded, if they contain a string of this list */
81+
private static final List<String> EXCLUDE_STRINGS_LINE_CONTAIN = new LinkedList<String>();
7982

8083
static {
81-
EXCLUDE_STRINGS.add(UNLOADING_CLASS);
82-
EXCLUDE_STRINGS.add(APPLICATION_TIME); // -XX:+PrintGCApplicationConcurrentTime
84+
EXCLUDE_STRINGS_LINE_START.add(UNLOADING_CLASS);
85+
EXCLUDE_STRINGS_LINE_START.add(APPLICATION_TIME); // -XX:+PrintGCApplicationConcurrentTime
8386
//EXCLUDE_STRINGS.add(Type.APPLICATION_STOPPED_TIME.getName()); // -XX:+PrintGCApplicationStoppedTime
84-
EXCLUDE_STRINGS.add("Desired survivor"); // -XX:+PrintTenuringDistribution
85-
EXCLUDE_STRINGS.add("- age"); // -XX:+PrintTenuringDistribution
86-
EXCLUDE_STRINGS.add(TIMES);
87-
EXCLUDE_STRINGS.add("Finished"); // -XX:PrintCmsStatistics=2
88-
EXCLUDE_STRINGS.add(" (cardTable: "); // -XX:PrintCmsStatistics=2
89-
EXCLUDE_STRINGS.add("GC locker: Trying a full collection because scavenge failed");
90-
EXCLUDE_STRINGS.add("CMSCollector"); // -XX:+PrintCMSInitiationStatistics
91-
EXCLUDE_STRINGS.add("time_until_cms_gen_full"); // -XX:+PrintCMSInitiationStatistics
92-
EXCLUDE_STRINGS.add("free"); // -XX:+PrintCMSInitiationStatistics
93-
EXCLUDE_STRINGS.add("contiguous_available"); // -XX:+PrintCMSInitiationStatistics
94-
EXCLUDE_STRINGS.add("promotion_rate"); // -XX:+PrintCMSInitiationStatistics
95-
EXCLUDE_STRINGS.add("cms_allocation_rate"); // -XX:+PrintCMSInitiationStatistics
96-
EXCLUDE_STRINGS.add("occupancy"); // -XX:+PrintCMSInitiationStatistics
97-
EXCLUDE_STRINGS.add("initiating"); // -XX:+PrintCMSInitiationStatistics
98-
EXCLUDE_STRINGS.add("Statistics"); // -XX:+PrintFLSStatistics=1
99-
EXCLUDE_STRINGS.add("----------------"); // -XX:+PrintFLSStatistics=1
100-
EXCLUDE_STRINGS.add("Total Free Space:"); // -XX:+PrintFLSStatistics=1
101-
EXCLUDE_STRINGS.add("Max Chunk Size:"); // -XX:+PrintFLSStatistics=1
102-
EXCLUDE_STRINGS.add("Number of Blocks:"); // -XX:+PrintFLSStatistics=1
103-
EXCLUDE_STRINGS.add("Av. Block Size:"); // -XX:+PrintFLSStatistics=1
104-
EXCLUDE_STRINGS.add("Tree Height:"); // -XX:+PrintFLSStatistics=1
105-
EXCLUDE_STRINGS.add(BEFORE_GC); // -XX:+PrintFLSStatistics=1
106-
EXCLUDE_STRINGS.add(AFTER_GC); // -XX:+PrintFLSStatistics=1
107-
EXCLUDE_STRINGS.add(CMS_LARGE_BLOCK); // -XX:+PrintFLSStatistics=1
108-
EXCLUDE_STRINGS.add(" free"); // -XX:+PrintFLSStatistics=2
109-
EXCLUDE_STRINGS.add(SIZE); // -XX:+PrintFLSStatistics=2
110-
EXCLUDE_STRINGS.add("demand"); // -XX:+PrintFLSStatistics=2
111-
EXCLUDE_STRINGS.add(ADAPTIVE_PATTERN); // -XX:+PrintAdaptiveSizePolicy
112-
EXCLUDE_STRINGS.add("PS" + ADAPTIVE_PATTERN); // -XX:PrintAdaptiveSizePolicy
113-
EXCLUDE_STRINGS.add(" avg_survived_padded_avg"); // -XX:PrintAdaptiveSizePolicy
114-
EXCLUDE_STRINGS.add("/proc/meminfo"); // apple vms seem to print this out in the beginning of the logs
115-
EXCLUDE_STRINGS.add("Uncommitted"); // -XX:+UseShenandoahGC
116-
EXCLUDE_STRINGS.add("Cancelling concurrent GC"); // -XX:+UseShenandoahGC
117-
EXCLUDE_STRINGS.add("Capacity"); // -XX:+UseShenandoahGC -XX:+PrintGCDetails
118-
EXCLUDE_STRINGS.add("Periodic GC triggered"); // -XX:+UseShenandoahGC -XX:+PrintGCDetails
119-
EXCLUDE_STRINGS.add("Immediate Garbage"); // -XX:+UseShenandoahGC -XX:+PrintGCDetails
120-
EXCLUDE_STRINGS.add("Garbage to be collected"); // -XX:+UseShenandoahGC -XX:+PrintGCDetails
121-
EXCLUDE_STRINGS.add("Live"); // -XX:+UseShenandoahGC -XX:+PrintGCDetails
122-
EXCLUDE_STRINGS.add("Concurrent marking triggered"); // -XX:+UseShenandoahGC -XX:+PrintGCDetails
87+
EXCLUDE_STRINGS_LINE_START.add("Desired survivor"); // -XX:+PrintTenuringDistribution
88+
EXCLUDE_STRINGS_LINE_START.add("- age"); // -XX:+PrintTenuringDistribution
89+
EXCLUDE_STRINGS_LINE_START.add(TIMES);
90+
EXCLUDE_STRINGS_LINE_START.add("Finished"); // -XX:PrintCmsStatistics=2
91+
EXCLUDE_STRINGS_LINE_START.add(" (cardTable: "); // -XX:PrintCmsStatistics=2
92+
EXCLUDE_STRINGS_LINE_START.add("GC locker: Trying a full collection because scavenge failed");
93+
EXCLUDE_STRINGS_LINE_START.add("CMSCollector"); // -XX:+PrintCMSInitiationStatistics
94+
EXCLUDE_STRINGS_LINE_START.add("time_until_cms_gen_full"); // -XX:+PrintCMSInitiationStatistics
95+
EXCLUDE_STRINGS_LINE_START.add("free"); // -XX:+PrintCMSInitiationStatistics
96+
EXCLUDE_STRINGS_LINE_START.add("contiguous_available"); // -XX:+PrintCMSInitiationStatistics
97+
EXCLUDE_STRINGS_LINE_START.add("promotion_rate"); // -XX:+PrintCMSInitiationStatistics
98+
EXCLUDE_STRINGS_LINE_START.add("cms_allocation_rate"); // -XX:+PrintCMSInitiationStatistics
99+
EXCLUDE_STRINGS_LINE_START.add("occupancy"); // -XX:+PrintCMSInitiationStatistics
100+
EXCLUDE_STRINGS_LINE_START.add("initiating"); // -XX:+PrintCMSInitiationStatistics
101+
EXCLUDE_STRINGS_LINE_START.add("Statistics"); // -XX:+PrintFLSStatistics=1
102+
EXCLUDE_STRINGS_LINE_START.add("----------------"); // -XX:+PrintFLSStatistics=1
103+
EXCLUDE_STRINGS_LINE_START.add("Total Free Space:"); // -XX:+PrintFLSStatistics=1
104+
EXCLUDE_STRINGS_LINE_START.add("Max Chunk Size:"); // -XX:+PrintFLSStatistics=1
105+
EXCLUDE_STRINGS_LINE_START.add("Number of Blocks:"); // -XX:+PrintFLSStatistics=1
106+
EXCLUDE_STRINGS_LINE_START.add("Av. Block Size:"); // -XX:+PrintFLSStatistics=1
107+
EXCLUDE_STRINGS_LINE_START.add("Tree Height:"); // -XX:+PrintFLSStatistics=1
108+
EXCLUDE_STRINGS_LINE_START.add(BEFORE_GC); // -XX:+PrintFLSStatistics=1
109+
EXCLUDE_STRINGS_LINE_START.add(AFTER_GC); // -XX:+PrintFLSStatistics=1
110+
EXCLUDE_STRINGS_LINE_START.add(CMS_LARGE_BLOCK); // -XX:+PrintFLSStatistics=1
111+
EXCLUDE_STRINGS_LINE_START.add(" free"); // -XX:+PrintFLSStatistics=2
112+
EXCLUDE_STRINGS_LINE_START.add(SIZE); // -XX:+PrintFLSStatistics=2
113+
EXCLUDE_STRINGS_LINE_START.add("demand"); // -XX:+PrintFLSStatistics=2
114+
EXCLUDE_STRINGS_LINE_START.add(ADAPTIVE_PATTERN); // -XX:+PrintAdaptiveSizePolicy
115+
EXCLUDE_STRINGS_LINE_START.add("PS" + ADAPTIVE_PATTERN); // -XX:PrintAdaptiveSizePolicy
116+
EXCLUDE_STRINGS_LINE_START.add(" avg_survived_padded_avg"); // -XX:PrintAdaptiveSizePolicy
117+
EXCLUDE_STRINGS_LINE_START.add("/proc/meminfo"); // apple vms seem to print this out in the beginning of the logs
118+
EXCLUDE_STRINGS_LINE_START.add("Uncommitted"); // -XX:+UseShenandoahGC
119+
EXCLUDE_STRINGS_LINE_START.add("Cancelling concurrent GC"); // -XX:+UseShenandoahGC
120+
EXCLUDE_STRINGS_LINE_START.add("Capacity"); // -XX:+UseShenandoahGC -XX:+PrintGCDetails
121+
EXCLUDE_STRINGS_LINE_START.add("Periodic GC triggered"); // -XX:+UseShenandoahGC -XX:+PrintGCDetails
122+
EXCLUDE_STRINGS_LINE_START.add("Immediate Garbage"); // -XX:+UseShenandoahGC -XX:+PrintGCDetails
123+
EXCLUDE_STRINGS_LINE_START.add("Garbage to be collected"); // -XX:+UseShenandoahGC -XX:+PrintGCDetails
124+
EXCLUDE_STRINGS_LINE_START.add("Live"); // -XX:+UseShenandoahGC -XX:+PrintGCDetails
125+
EXCLUDE_STRINGS_LINE_START.add("Concurrent marking triggered"); // -XX:+UseShenandoahGC -XX:+PrintGCDetails
126+
EXCLUDE_STRINGS_LINE_START.add("Adjusting free threshold"); // -XX:+UseShenandoahGC
127+
EXCLUDE_STRINGS_LINE_START.add("Predicted cset threshold"); // -XX:+UseShenandoahGC
128+
EXCLUDE_STRINGS_LINE_START.add("Trigger"); // -XX:+UseShenandoahGC
129+
EXCLUDE_STRINGS_LINE_START.add("Free"); // -XX:+UseShenandoahGC
130+
EXCLUDE_STRINGS_LINE_START.add("Evacuation Reserve"); // -XX:+UseShenandoahGC
131+
EXCLUDE_STRINGS_LINE_START.add("Pacer for "); // -XX:+UseShenandoahGC
132+
EXCLUDE_STRINGS_LINE_START.add(" Using"); // -XX:+UseShenandoahGC
133+
EXCLUDE_STRINGS_LINE_START.add(" Pacer for "); // -XX:+UseShenandoahGC
134+
EXCLUDE_STRINGS_LINE_START.add(" Adaptive CSet Selection"); // -XX:+UseShenandoahGC
135+
EXCLUDE_STRINGS_LINE_START.add(" Collectable Garbage"); // -XX:+UseShenandoahGC
136+
EXCLUDE_STRINGS_LINE_START.add(" Immediate Garbage"); // -XX:+UseShenandoahGC
137+
138+
EXCLUDE_STRINGS_LINE_CONTAIN.add(LOGFILE_ROLLING_BEGIN);
139+
EXCLUDE_STRINGS_LINE_CONTAIN.add(LOGFILE_ROLLING_END);
140+
// when it occurs including timestamp (since about jdk1.7.0_50) it should still be ignored
141+
EXCLUDE_STRINGS_LINE_CONTAIN.add(APPLICATION_TIME); // -XX:+PrintGCApplicationConcurrentTime
142+
EXCLUDE_STRINGS_LINE_CONTAIN.add(", start"); // -XX:+UseShenandoahGC
143+
144+
LOG_INFORMATION_STRINGS.add("Region"); // -XX:+UseShenandoahGC
145+
LOG_INFORMATION_STRINGS.add("Humongous threshold"); // -XX:+UseShenandoahGC
146+
LOG_INFORMATION_STRINGS.add("Number of regions"); // -XX:+UseShenandoahGC
147+
LOG_INFORMATION_STRINGS.add("Shenandoah heuristics"); // -XX:+UseShenandoahGC
148+
LOG_INFORMATION_STRINGS.add("Parallel GC threads");// -XX:+UseShenandoahGC
149+
LOG_INFORMATION_STRINGS.add("Concurrent GC threads"); // -XX:+UseShenandoahGC
150+
LOG_INFORMATION_STRINGS.add("Parallel reference processing"); // -XX:+UseShenandoahGC
151+
LOG_INFORMATION_STRINGS.add("Humongous object threshold"); // -XX:+UseShenandoahGC
152+
LOG_INFORMATION_STRINGS.add("Max TLAB size"); // -XX:+UseShenandoahGC
153+
LOG_INFORMATION_STRINGS.add("GC threads"); // -XX:+UseShenandoahGC
154+
LOG_INFORMATION_STRINGS.add("Reference processing"); // -XX:+UseShenandoahGC
155+
LOG_INFORMATION_STRINGS.add("Heuristics ergonomically sets"); // -XX:+UseShenandoahGC
156+
LOG_INFORMATION_STRINGS.add("Initialize Shenandoah heap"); // -XX:+UseShenandoahGC
123157
}
124158

125159
private static final String EVENT_YG_OCCUPANCY = "YG occupancy";
@@ -258,21 +292,16 @@ public GCModel read() throws IOException {
258292
try {
259293
printTenuringDistributionOn = false;
260294
// filter out lines that don't need to be parsed
261-
if (startsWith(line, EXCLUDE_STRINGS, false)) {
295+
if (startsWith(line, EXCLUDE_STRINGS_LINE_START, false)) {
262296
continue;
263297
}
264-
else if (line.indexOf(APPLICATION_TIME) > 0) {
265-
// -XX:+PrintGCApplicationConcurrentTime
266-
// when it occurs including timestamp (since about jdk1.7.0_50) it should still be ignored
298+
else if (contains(line, EXCLUDE_STRINGS_LINE_CONTAIN, false)) {
267299
continue;
268300
}
269301
else if (startsWith(line, LOG_INFORMATION_STRINGS, false)) {
270302
getLogger().info(line);
271303
continue;
272304
}
273-
else if (line.indexOf(LOGFILE_ROLLING_BEGIN) > 0 || line.indexOf(LOGFILE_ROLLING_END) > 0) {
274-
continue;
275-
}
276305

277306
if (line.contains(SHENANDOAH_DETAILS_FINAL_MARK)) {
278307
beginningOfLine.addFirst(line.substring(0, line.indexOf(SHENANDOAH_DETAILS_FINAL_MARK_SPLIT_START)));

‎src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderUnifiedJvmLogging.java‎

Lines changed: 17 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -59,7 +59,7 @@ public class DataReaderUnifiedJvmLogging extends AbstractDataReader {
5959
// Regex: ^(?:\[(?<time>[0-9-T:.+]*)])?(?:\[(?<uptime>[^s]*)s])?\[(?<level>[^]]+)]\[(?:(?<tags>[^] ]+)[ ]*)][ ]GC\((?<gcnumber>[0-9]+)\)[ ](?<type>([-.a-zA-Z ()]+|[a-zA-Z1 ()]+))(?:(?:[ ](?<tail>[0-9]{1}.*))|$)
6060
// note for the <type> part: easiest would have been to use [^0-9]+, but the G1 events don't fit there, because of the number in their name
6161
private static final Pattern PATTERN_DECORATORS = Pattern.compile(
62-
"^(?:\\[(?<time>[0-9-T:.+]*)])?(?:\\[(?<uptime>[^ms]*)(?<uptimeunit>m?s)])?\\[(?<level>[^]]+)]\\[(?:(?<tags>[^] ]+)[ ]*)][ ]GC\\((?<gcnumber>[0-9]+)\\)[ ](?<type>(?:Phase [0-9]{1}: [a-zA-Z ]+)|[-.a-zA-Z: ()]+|[a-zA-Z1 ()]+)(?:(?:[ ](?<tail>[0-9]{1}.*))|$)"
62+
"^(?:\\[(?<time>[0-9-T:.+]*)])?(?:\\[(?<uptime>[^ms]*)(?<uptimeunit>m?s)])?\\[(?<level>[^]]+)]\\[(?:(?<tags>[^] ]+)[ ]*)][ ](GC\\((?<gcnumber>[0-9]+)\\)[ ])?(?<type>(?:Phase [0-9]{1}: [a-zA-Z ]+)|[-.a-zA-Z: ()]+|[a-zA-Z1 ()]+)(?:(?:[ ](?<tail>[0-9]{1}.*))|$)"
6363
);
6464
private static final String GROUP_DECORATORS_TIME = "time";
6565
private static final String GROUP_DECORATORS_UPTIME = "uptime";
@@ -161,9 +161,20 @@ public class DataReaderUnifiedJvmLogging extends AbstractDataReader {
161161
/** list of strings, that must be part of the gc log line to be considered for parsing */
162162
private static final List<String> INCLUDE_STRINGS = Arrays.asList("[gc ", "[gc]", "[" + TAG_GC_START, "[" + TAG_GC_HEAP, "[" + TAG_GC_METASPACE, "[" + TAG_GC_PHASES);
163163
/** list of strings, that target gc log lines, that - although part of INCLUDE_STRINGS - are not considered a gc event */
164-
private static final List<String> EXCLUDE_STRINGS = Arrays.asList("Cancelling concurrent GC", "[debug", "[trace", "gc,heap,coops", "gc,heap,exit", "[gc,phases,start");
164+
private static final List<String> EXCLUDE_STRINGS = Arrays.asList("Cancelling concurrent GC",
165+
"[debug",
166+
"[trace",
167+
"gc,heap,coops",
168+
"gc,heap,exit",
169+
"[gc,phases,start",
170+
"Trigger: ",
171+
"Failed to allocate",
172+
"Cancelling GC");
165173
/** list of strings, that are gc log lines, but not a gc event -&gt; should be logged only */
166-
private static final List<String> LOG_ONLY_STRINGS = Arrays.asList("Using", "Heap region size");
174+
private static final List<String> LOG_ONLY_STRINGS = Arrays.asList("Using",
175+
"Heap region size",
176+
"Consider",
177+
"Heuristics ergonomically sets");
167178

168179
protected DataReaderUnifiedJvmLogging(GCResource gcResource, InputStream in) throws UnsupportedEncodingException {
169180
super(gcResource, in);
@@ -450,7 +461,9 @@ private AbstractGCEvent<?> createGcEventWithStandardDecorators(Matcher decorator
450461

451462
AbstractGCEvent<?> event = type.getConcurrency().equals(Concurrency.CONCURRENT) ? new ConcurrentGCEvent() : new GCEventUJL();
452463
event.setExtendedType(type);
453-
event.setNumber(Integer.parseInt(decoratorsMatcher.group(GROUP_DECORATORS_GC_NUMBER)));
464+
if (decoratorsMatcher.group(GROUP_DECORATORS_GC_NUMBER) != null) {
465+
event.setNumber(Integer.parseInt(decoratorsMatcher.group(GROUP_DECORATORS_GC_NUMBER)));
466+
}
454467
setDateStampIfPresent(event, decoratorsMatcher.group(GROUP_DECORATORS_TIME));
455468
setTimeStampIfPresent(event, decoratorsMatcher.group(GROUP_DECORATORS_UPTIME), decoratorsMatcher.group(GROUP_DECORATORS_UPTIME_UNIT));
456469
return event;

0 commit comments

Comments
 (0)