diff --git a/parser/src/main/java/com/microsoft/gctoolkit/parser/jvm/Decorators.java b/parser/src/main/java/com/microsoft/gctoolkit/parser/jvm/Decorators.java index 955db7d3..11659c39 100644 --- a/parser/src/main/java/com/microsoft/gctoolkit/parser/jvm/Decorators.java +++ b/parser/src/main/java/com/microsoft/gctoolkit/parser/jvm/Decorators.java @@ -64,9 +64,20 @@ public class Decorators { private static final long TWENTY_YEARS_IN_MILLIS = 731L * 24L * 60L * 60L * 1000L; private static final long TWENTY_YEARS_IN_NANO = 731L * 24L * 60L * 60L * 1000L; + private static final int DATE_STAMP_GROUP = 0; + private static final int UPTIME_GROUP = 1; + private static final int TIME_MILLIS_OR_MAYBE_UPTIME_MILLIS_GROUP = 2; + private static final int UPTIME_MILLIS_GROUP = 3; + private static final int TIME_NANOS_OR_MAYBE_UPTIME_NANOS_GROUP = 4; + private static final int UPTIME_NANOS_GROUP = 5; + private static final int PID_GROUP = 6; + private static final int TID_GROUP = 7; + private static final int LOG_LEVEL_GROUP = 8; + private static final int TAGS_GROUP = 9; + int numberOfDecorators; - private Matcher decoratorMatcher = null; + private String[] decoratorGroups; private String tags; public Decorators(String line) { @@ -74,25 +85,23 @@ public Decorators(String line) { } private void extractValues(String line) { - if (!line.startsWith("[")) return; - decoratorMatcher = UnifiedLoggingTokens.DECORATORS.matcher(line); + Matcher decoratorMatcher = UnifiedLoggingTokens.DECORATORS.matcher(line); if (!decoratorMatcher.find()) { return; } - for ( int i = 1; i <= decoratorMatcher.groupCount(); i++) { - if ( decoratorMatcher.group(i) != null) + // Retrieving a group from a matcher calls substring each time + // Store all the groups in an array ahead of time to avoid paying this cost unnecessarily + decoratorGroups = new String[decoratorMatcher.groupCount()]; + for (int i = 1; i <= decoratorMatcher.groupCount(); i++) { + String group = decoratorMatcher.group(i); + decoratorGroups[i-1] = group; + if (group != null) numberOfDecorators++; } - - Matcher tagMatcher = UnifiedLoggingTokens.TAGS.matcher(line); - if (tagMatcher.find()) { - numberOfDecorators++; - tags = String.join(",", Arrays.asList(tagMatcher.group(1).trim().split(","))); - } } // For some reason, ISO_DATE_TIME doesn't like that time-zone is -0100. It wants -01:00. @@ -100,10 +109,11 @@ private void extractValues(String line) { public ZonedDateTime getDateStamp() { try { - String value = decoratorMatcher.group(1); + String value = decoratorGroups[DATE_STAMP_GROUP]; if (value != null) { TemporalAccessor temporalAccessor = formatter.parse(value.substring(1, value.length()-1)); - return ZonedDateTime.from(temporalAccessor); } + return ZonedDateTime.from(temporalAccessor); + } } catch (NullPointerException npe) { LOGGER.log(Level.SEVERE, npe.getMessage(), npe); } @@ -111,7 +121,7 @@ public ZonedDateTime getDateStamp() { } public double getUpTime() { - String value = decoratorMatcher.group(2); + String value = decoratorGroups[UPTIME_GROUP]; if (value != null) { value = value.replace(",", "."); return Double.parseDouble(unboxValue(value, 1)); @@ -121,10 +131,10 @@ public double getUpTime() { private long extractClock(int groupIndex, long threshold) { long clockReading = -1L; - String stringValue = decoratorMatcher.group(groupIndex); + String stringValue = decoratorGroups[groupIndex]; if (stringValue != null) { clockReading = Long.parseLong(unboxValue(stringValue, 2)); - if (decoratorMatcher.group(groupIndex + 1) == null) + if (decoratorGroups[groupIndex + 1] == null) if (clockReading < threshold) clockReading = -1L; } @@ -132,13 +142,13 @@ private long extractClock(int groupIndex, long threshold) { } public long getTimeMillis() { - return extractClock(3, TWENTY_YEARS_IN_MILLIS); + return extractClock(TIME_MILLIS_OR_MAYBE_UPTIME_MILLIS_GROUP, TWENTY_YEARS_IN_MILLIS); } public long getUptimeMillis() { - String value = decoratorMatcher.group(4); + String value = decoratorGroups[UPTIME_MILLIS_GROUP]; if (value == null) { - value = decoratorMatcher.group(3); + value = decoratorGroups[TIME_MILLIS_OR_MAYBE_UPTIME_MILLIS_GROUP]; } if (value != null) { long longValue = Long.parseLong(unboxValue(value, 2)); @@ -149,13 +159,13 @@ public long getUptimeMillis() { } public long getTimeNano() { - return extractClock(5, TWENTY_YEARS_IN_NANO); + return extractClock(TIME_NANOS_OR_MAYBE_UPTIME_NANOS_GROUP, TWENTY_YEARS_IN_NANO); } public long getUptimeNano() { - String value = decoratorMatcher.group(6); + String value = decoratorGroups[UPTIME_NANOS_GROUP]; if (value == null) { - value = decoratorMatcher.group(5); + value = decoratorGroups[TIME_NANOS_OR_MAYBE_UPTIME_NANOS_GROUP]; } if (value != null) { long longValue = Long.parseLong(unboxValue(value, 2)); @@ -166,7 +176,7 @@ public long getUptimeNano() { } public int getPid() { - String value = decoratorMatcher.group(7); + String value = decoratorGroups[PID_GROUP]; if (value != null) { return Integer.parseInt(unboxValue(value)); } @@ -174,7 +184,7 @@ public int getPid() { } public int getTid() { - String value = decoratorMatcher.group(8); + String value = decoratorGroups[TID_GROUP]; if (value != null) { return Integer.parseInt(unboxValue(value)); } @@ -182,7 +192,7 @@ public int getTid() { } public Optional getLogLevel() { - String level = decoratorMatcher.group(9); + String level = decoratorGroups[LOG_LEVEL_GROUP]; if (level != null) try { return Optional.of(UnifiedLoggingLevel.valueOf(unboxValue(level))); @@ -211,10 +221,15 @@ private String unboxValue(String boxedValue) { } public boolean tagsContain(String tagList) { - return tags.contains(tagList); + return getTags().contains(tagList); } public String getTags() { + if (tags == null && decoratorGroups[TAGS_GROUP] != null) { + tags = String.join(",", Arrays.asList( + unboxValue(decoratorGroups[TAGS_GROUP]).trim().split(",") + )); + } return tags; } } \ No newline at end of file diff --git a/parser/src/main/java/com/microsoft/gctoolkit/parser/unified/UnifiedLoggingTokens.java b/parser/src/main/java/com/microsoft/gctoolkit/parser/unified/UnifiedLoggingTokens.java index 59b008fd..e6bb694c 100644 --- a/parser/src/main/java/com/microsoft/gctoolkit/parser/unified/UnifiedLoggingTokens.java +++ b/parser/src/main/java/com/microsoft/gctoolkit/parser/unified/UnifiedLoggingTokens.java @@ -32,10 +32,9 @@ public interface UnifiedLoggingTokens extends GenericTokens { String TIME_NANOS = "\\[\\d+ns\\]"; String PID_TID = "\\[\\d+\\]"; String UNIFIED_LOG_LEVEL_BLOCK = "\\[(?:error|warning|info|debug|trace|develop) *\\]"; - Pattern DECORATORS = Pattern.compile("(" + DATE_STAMP + ")?(" + UPTIME + ")?(" + TIME_MILLIS + ")?(" + TIME_MILLIS + ")?(" + TIME_NANOS + ")?(" + TIME_NANOS + ")?(" + PID_TID + ")?(" + PID_TID + ")?(" + UNIFIED_LOG_LEVEL_BLOCK + ")?"); - //Using zero-width negative lookbehind to miss capturing records formatted like [0x1f03]. - //[0.081s][trace][safepoint] Thread: 0x00007fd0d2006800 [0x1f03] State: _at_safepoint _has_called_back 0 _at_poll_safepoint 0 - Pattern TAGS = Pattern.compile(".*(?<=^|\\])\\[([a-z0-9,. ]+)\\]"); + // We combine TAGS with the DECORATORS for performance reasons. + String TAGS = "\\[[a-z0-9,. ]+\\]"; + Pattern DECORATORS = Pattern.compile("^(" + DATE_STAMP + ")?(" + UPTIME + ")?(" + TIME_MILLIS + ")?(" + TIME_MILLIS + ")?(" + TIME_NANOS + ")?(" + TIME_NANOS + ")?(" + PID_TID + ")?(" + PID_TID + ")?(" + UNIFIED_LOG_LEVEL_BLOCK + ")?(" + TAGS + ")?"); String UNIFIED_META_RECORD = "Metaspace: " + BEFORE_AFTER_CONFIGURED; String WORKER_SUMMARY_REAL = "Min:\\s+" + TIME + ", Avg:\\s+" + TIME + ", Max:\\s+" + TIME + ", Diff:\\s+" + TIME + ", Sum:\\s+" + TIME + ", Workers:\\s+" + COUNTER;