Summary
Profiling the parser shows that per-line regex matching is the single largest source of allocation and CPU in the library. GenerationalHeapParser.process(String) evaluates every rule against every line, and each evaluation allocates a brand-new Matcher (and its internal int[] group/local arrays) via Pattern.matcher(line).
Evidence (JFR settings=profile, ~28s run)
Workload: sample Main parsing a 195 MB JDK8 ParallelGC rolling log (gclogs/rolling/jdk8/aagl_prd/gc.log), -Xmx1500m, G1, Java 25 (GraalVM 25.0.3). 4015 execution samples, ~19,985 MB sampled allocations.
Allocation pressure (share of ~19,985 MB):
| Rank |
Type / Site |
Share |
≈ MB |
| 1 |
int[] (Matcher groups/locals arrays) |
23.0% |
~4,589 |
| 2 |
java.util.regex.Matcher |
10.2% |
~2,036 |
| — |
alloc site Pattern.matcher(CharSequence) |
17.6% |
— |
Hot methods (CPU) — top 8 are all regex, ≈76% of 4015 samples:
Pattern$Branch.match 17.8%, Pattern$BmpCharProperty.match 16.7%, Pattern$GroupHead.match 12.5%, Pattern$Curly.match 11.6%, Pattern$BmpCharPropertyGreedy.match 11.5%, plus Start/Slice/GroupTail.
Root cause
parser/src/main/java/com/microsoft/gctoolkit/parser/GCParseRule.java
public GCLogTrace parse(String trace) {
Matcher matcher = pattern.matcher(trace); // new Matcher + int[] arrays every call
if (matcher.find()) { return new GCLogTrace(matcher); }
return null;
}
GenerationalHeapParser.process(String) (line ~303) runs this across the whole rule set for every line:
parseRules.keys().stream()
.map(rule -> new AbstractMap.SimpleEntry<>(rule, rule.parse(line))) // matcher per rule per line
.filter(tuple -> tuple.getValue() != null)
.findFirst();
For a multi-million-line log tried against dozens of rules, that is tens of millions of throwaway Matcher/int[] allocations. ignoreFrequentButUnwantedEntries also runs several parse() calls per line before the main loop.
Suggested fixes
- Cheap prefilter before regex. Add a fast
String.startsWith/indexOf/length guard (or a first-token switch) per rule so the full regex is only attempted on plausible candidates.
- Reuse
Matcher instances via matcher.reset(line) instead of pattern.matcher(line) (parsing per channel is single-threaded — note the existing synchronized/"matcher corruption" TODO in GCParseRule).
- Order/short-circuit rules by hit frequency so common lines match early.
Expected impact
Targets the ~33% of allocations (int[] + Matcher) and ~76% of CPU attributed to regex. GC itself is already healthy (98.76% throughput), so this is a CPU/allocation-throughput improvement, not a pause fix.
Summary
Profiling the parser shows that per-line regex matching is the single largest source of allocation and CPU in the library.
GenerationalHeapParser.process(String)evaluates every rule against every line, and each evaluation allocates a brand-newMatcher(and its internalint[]group/local arrays) viaPattern.matcher(line).Evidence (JFR
settings=profile, ~28s run)Workload: sample
Mainparsing a 195 MB JDK8 ParallelGC rolling log (gclogs/rolling/jdk8/aagl_prd/gc.log),-Xmx1500m, G1, Java 25 (GraalVM 25.0.3). 4015 execution samples, ~19,985 MB sampled allocations.Allocation pressure (share of ~19,985 MB):
int[](Matchergroups/localsarrays)java.util.regex.MatcherPattern.matcher(CharSequence)Hot methods (CPU) — top 8 are all regex, ≈76% of 4015 samples:
Pattern$Branch.match17.8%,Pattern$BmpCharProperty.match16.7%,Pattern$GroupHead.match12.5%,Pattern$Curly.match11.6%,Pattern$BmpCharPropertyGreedy.match11.5%, plusStart/Slice/GroupTail.Root cause
parser/src/main/java/com/microsoft/gctoolkit/parser/GCParseRule.javaGenerationalHeapParser.process(String)(line ~303) runs this across the whole rule set for every line:For a multi-million-line log tried against dozens of rules, that is tens of millions of throwaway
Matcher/int[]allocations.ignoreFrequentButUnwantedEntriesalso runs severalparse()calls per line before the main loop.Suggested fixes
String.startsWith/indexOf/length guard (or a first-token switch) per rule so the full regex is only attempted on plausible candidates.Matcherinstances viamatcher.reset(line)instead ofpattern.matcher(line)(parsing per channel is single-threaded — note the existingsynchronized/"matcher corruption" TODO inGCParseRule).Expected impact
Targets the ~33% of allocations (
int[]+Matcher) and ~76% of CPU attributed to regex. GC itself is already healthy (98.76% throughput), so this is a CPU/allocation-throughput improvement, not a pause fix.