Skip to content

Parser: avoid allocating a fresh Matcher per rule per line in the hot parse path #566

Description

@brunoborges

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

  1. 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.
  2. 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).
  3. 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.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions