Deque<String> beginningOfLine = new LinkedList<String>();
int lineNumber = 0;
boolean lastLineWasScavengeBeforeRemark = false;
boolean lineSkippedForScavengeBeforeRemark = false;
boolean printTenuringDistributionOn = false;
ParseInformation parsePosition = new ParseInformation(0);
while ((line = in.readLine()) != null) {
++lineNumber;
parsePosition.setLineNumber(lineNumber);
if ("".equals(line)) {
continue;
}
try {
printTenuringDistributionOn = false;
// filter out lines that don't need to be parsed
if (startsWith(line, EXCLUDE_STRINGS, false)) {
continue;
}
else if (line.indexOf(APPLICATION_TIME) > 0) {
// -XX:+PrintGCApplicationConcurrentTime
// when it occurs including timestamp (since about jdk1.7.0_50) it should still be ignored
continue;
}
else if (startsWith(line, LOG_INFORMATION_STRINGS, false)) {
LOG.info(line);
continue;
}
if (line.indexOf(CMS_ABORT_PRECLEAN) >= 0) {
// line contains like " CMS: abort preclean due to time "
// -> remove the text
int indexOfStart = line.indexOf(CMS_ABORT_PRECLEAN);
StringBuilder sb = new StringBuilder(line);
sb.replace(indexOfStart, indexOfStart + CMS_ABORT_PRECLEAN.length(), "");
line = sb.toString();
}
if (line.indexOf(PRINT_CMS_STATISTICS_ITERATIONS) > 0) {
// -XX:PrintCmsStatistics -> filter text that the parser doesn't know
printCmsStatisticsIterationsMatcher.reset(line);
if (!printCmsStatisticsIterationsMatcher.matches()) {
LOG.severe("printCmsStatisticsIterationsMatcher did not match for line " + lineNumber + ": '" + line + "'");
continue;
}
line = printCmsStatisticsIterationsMatcher.group(PRINT_CMS_STATISTICS_ITERATIONS_GROUP_BEFORE)
+ printCmsStatisticsIterationsMatcher.group(PRINT_CMS_STATISTICS_ITERATIONS_GROUP_AFTER);
}
if (line.indexOf(PRINT_CMS_STATISTICS_SURVIVOR) > 0) {
String currentBeginning = "";
if (beginningOfLine.size() > 0) {
// if -XX:PrintCmsStatistics=2 is combined with -XX:+CMSScavengeBeforeRemark
// then a remark line is broken into three parts, which have to be glued together
currentBeginning = beginningOfLine.removeFirst();
}
beginningOfLine.addFirst(currentBeginning + line.substring(0, line.indexOf(PRINT_CMS_STATISTICS_SURVIVOR)));
continue;
}
if (line.indexOf(PRINT_TENURING_DISTRIBUTION) > 0) {
printTenuringDistributionMatcher.reset(line);
if (!printTenuringDistributionMatcher.matches()) {
LOG.severe("printDistributionMatcher did not match for line " + lineNumber + ": '" + line + "'");
continue;
}
line = printTenuringDistributionMatcher.group(PRINT_TENURING_DISTRIBUTION_PATTERN_GROUP_BEFORE)
+ printTenuringDistributionMatcher.group(PRINT_TENURING_DISTRIBUTION_PATTERN_GROUP_AFTER);
}
if (line.indexOf(PRINT_REFERENCE_GC_INDICATOR) > 0) {
line = filterAwayReferenceGc(line);
}
if (lineHasPrintFlsStatistics(line)) {
handlePrintFlsStatistics(line, beginningOfLine);
continue;
}
if (isCmsScavengeBeforeRemark(line)) {
// This is the case, when option -XX:+CMSScavengeBeforeRemark is used.
// we have two events in the first line -> split it
// if this option is combined with -XX:+PrintTenuringDistribution, the
// first event is also distributed over more than one line
int startOf2ndEvent = line.indexOf("]", line.indexOf(EVENT_YG_OCCUPANCY)) + 1;
beginningOfLine.addFirst(line.substring(0, startOf2ndEvent));
if (!isPrintTenuringDistribution(line)) {
if (line.indexOf(SCAVENGE_BEFORE_REMARK) >= 0) {
// jdk1.5 scavenge before remark: just after another separate event occurs
startOf2ndEvent = line.indexOf(SCAVENGE_BEFORE_REMARK) + SCAVENGE_BEFORE_REMARK.length();
}
model.add(parseLine(line.substring(startOf2ndEvent), parsePosition));
parsePosition.setIndex(0);
}
else {
beginningOfLine.addFirst(line.substring(startOf2ndEvent));
}
lastLineWasScavengeBeforeRemark = true;
continue;
}
int unloadingClassIndex = line.indexOf(UNLOADING_CLASS);
if (unloadingClassIndex > 0) {
beginningOfLine.addFirst(line.substring(0, unloadingClassIndex));
continue;
}
else if (isPrintTenuringDistribution(line)) {
// this is the case, when e.g. -XX:+PrintTenuringDistribution is used
// where we want to skip "Desired survivor..." and "- age..." lines
beginningOfLine.addFirst(line);
continue;
}
else if (line.indexOf(ADAPTIVE_PATTERN) >= 0) {
if (line.indexOf("Times") > 0) {
// -XX:+PrintAdaptiveSizePolicy -XX:-UseAdaptiveSizePolicy
printAdaptiveSizePolicyMatcher.reset(line);
if (!printAdaptiveSizePolicyMatcher.matches()) {
LOG.severe("printAdaptiveSizePolicyMatcher did not match for line " + lineNumber + ": '" + line + "'");
continue;
}
model.add(parseLine(
printAdaptiveSizePolicyMatcher.group(PRINT_ADAPTIVE_SIZE_GROUP_BEFORE)
+ printAdaptiveSizePolicyMatcher.group(PRINT_ADAPTIVE_SIZE_GROUP_AFTER),
parsePosition));
parsePosition.setIndex(0);
}
else {
// -XX:+PrintAdaptiveSizePolicy
adaptiveSizePolicyMatcher.reset(line);
if (!adaptiveSizePolicyMatcher.matches()) {
LOG.severe("adaptiveSizePolicyMatcher did not match for line " + lineNumber + ": '" + line + "'");
continue;
}
beginningOfLine.addFirst(adaptiveSizePolicyMatcher.group(1));
lineNumber = skipLines(in, parsePosition, lineNumber, ADAPTIVE_SIZE_POLICY_STRINGS);
}
continue;
}
else if (beginningOfLine.size() > 0) {
// -XX:+CMSScavengeBeforeRemark combined with -XX:+PrintTenuringDistribution
// is the only case where beginningOfLine.size() > 1
printTenuringDistributionOn = beginningOfLine.size() == 2;
if (gcLogType == GcLogType.SUN1_5
&& lastLineWasScavengeBeforeRemark
&& ! lineSkippedForScavengeBeforeRemark) {
// -XX:+CMSScavengeBeforeRemark inserts a pause on its own line between
// the first and the second part of the enclosing remark event. Probably
// that is the duration of the Scavenge-Before-Remark event; this information
// will be dropped to reduce complexity of the parser at the cost of
// some accuracy in that case.
lineSkippedForScavengeBeforeRemark = true;
continue;
}
else {
line = beginningOfLine.removeFirst() + line;
}
}
else if (line.indexOf(HEAP_SIZING_START) >= 0) {
// the next few lines will be the sizing of the heap
lineNumber = skipLines(in, parsePosition, lineNumber, HEAP_STRINGS);
continue;
}
if (isMixedLine(line, mixedLineMatcher)) {
// if PrintTenuringDistribution is used and a line is mixed,
// beginningOfLine may already contain a value, which must be preserved
String firstPartOfBeginningOfLine = beginningOfLine.pollFirst();
if (firstPartOfBeginningOfLine == null) {
firstPartOfBeginningOfLine = "";
}
beginningOfLine.addFirst(firstPartOfBeginningOfLine + mixedLineMatcher.group(LINES_MIXED_STARTOFLINE_GROUP));
model.add(parseLine(mixedLineMatcher.group(LINES_MIXED_ENDOFLINE_GROUP), parsePosition));
parsePosition.setIndex(0);
continue;
}
AbstractGCEvent<?> gcEvent = parseLine(line, parsePosition);
if (lastLineWasScavengeBeforeRemark && !printTenuringDistributionOn) {
// according to http://mail.openjdk.java.net/pipermail/hotspot-gc-use/2012-August/001297.html
// the pause time reported for cms-remark includes the scavenge-before-remark time
// so it has to be corrected to show only the time spent in remark event
lastLineWasScavengeBeforeRemark = false;
lineSkippedForScavengeBeforeRemark = false;
AbstractGCEvent<?> scavengeBeforeRemarkEvent = model.get(model.size() - 1);
AbstractGCEvent<?> remarkEvent = gcEvent;
remarkEvent.setPause(remarkEvent.getPause() - scavengeBeforeRemarkEvent.getPause());
}
model.add(gcEvent);
}
catch (Exception pe) {
if (LOG.isLoggable(Level.WARNING)) LOG.warning(pe.toString());
if (LOG.isLoggable(Level.FINE)) LOG.log(Level.FINE, pe.getMessage(), pe);
beginningOfLine.clear();
}
// reset ParsePosition
parsePosition.setIndex(0);
}
return model;
}
finally {
if (LOG.isLoggable(Level.INFO)) LOG.info("Done reading.");