$ guides / logstash / logstash-grok-catastrophic-backtracking ▌

Operations Guides

Logstash grok slow: catastrophic backtracking and per-event duration spikes

A Logstash pipeline that ran fine for months suddenly pegs CPU. Workers saturate, the persistent queue grows, and event throughput collapses. The input rate is unchanged, the output destination is healthy, and there are no error storms in the logs. The only visible anomaly is that one grok filter’s per-event processing duration has exploded.

This is the signature of catastrophic regex backtracking, also known as ReDoS. A single malformed or near-miss log line hits a pattern with nested unbounded quantifiers or overlapping alternation, and the Oniguruma regex engine that grok uses takes exponential time to determine that the match fails. One bad event can occupy a pipeline worker thread for seconds or longer.

The trigger is data, not load. The same event volume that ran fine yesterday is now pathological because a new log shape arrived from the source. The default timeout_millis is 30000 (30 seconds), so a single pathological event can hold a worker for half a minute before timing out.

What this means

Catastrophic backtracking occurs when a regex engine must try an exponential number of paths before concluding that no match exists. Constructs that create this ambiguity include nested quantifiers such as (.*)*, overlapping alternation such as (a|a)*, and unanchored greedy patterns where the engine attempts substring matches at every position in the input. When the input nearly matches but fails near the end, the engine backtracks through every combination.

Grok runs these patterns on the Oniguruma regex engine inside JRuby. A non-matching pattern can take significantly longer than a matching one because the engine exhausts every possible backtrack path before giving up. CPU is high because worker threads burn cycles inside regex evaluation, not because of GC pauses or output blocking.

flowchart TD
    A[New or malformed log arrives] --> B[Grok attempts match]
    B --> C{Nested quantifiers or
unanchored greedy data?}
    C -->|Yes| D[Exponential backtracking]
    C -->|No| E[Fast match or fail]
    D --> F[Worker CPU pegs]
    F --> G[Per-event duration spikes]
    G --> H[Queue grows, backpressure]
    H --> I[Throughput drops]

Common causes

Cause	What it looks like	First thing to check
Unanchored pattern	CPU pegs when new log format arrives; slow failure on non-matching lines	Whether pattern starts with `^` and ends with `$`
GREEDYDATA mid-pattern	Processing time proportional to message length; large messages trigger timeouts	Whether `%{GREEDYDATA}` appears before the end of the match
Nested or overlapping quantifiers	Exponential blowup on near-miss inputs; `_groktimeout` tags appear	Pattern for `(.)`, `(.+)+`, or overlapping alternation
New source log format	Spike coincides with upstream deployment or format change	grok `failures` counter and recent source-side changes
Default timeout too generous	Single event stalls a worker thread for up to 30 seconds	Whether `timeout_millis` is set below the 30s default

Quick checks

All read-only and safe to run during an active incident.

# Per-filter processing time: look for a grok filter with disproportionate ms/event
curl -sS http://127.0.0.1:9600/_node/stats/pipelines?pretty | python3 -c "
import sys,json
filters = json.load(sys.stdin)['pipelines']['main']['plugins']['filters']
for f in filters:
    name = f.get('name','?')
    fid = f.get('id','?')
    dur = f['events'].get('duration_in_millis',0)
    evts = f['events'].get('out',0)
    avg = (dur/evts) if evts > 0 else 0
    print(f'{name} ({fid}): {dur}ms total, {evts} events, {avg:.3f} ms/event')
"

# Hot threads: look for org.jruby.RubyRegexp at the top of CPU usage
curl -sS 'http://127.0.0.1:9600/_node/hot_threads?threads=10'

# Worker utilization (Logstash 8.x flow metrics)
curl -sS http://127.0.0.1:9600/_node/stats/pipelines?pretty | python3 -c "
import sys,json
flow = json.load(sys.stdin)['pipelines']['main'].get('flow', {})
print(f\"Worker utilization: {flow.get('worker_utilization', 'N/A')}\")
"

# Process CPU percent
curl -sS http://127.0.0.1:9600/_node/stats/process?pretty | grep '"percent"'

# Queue depth: growing queue confirms workers cannot keep up
curl -sS http://127.0.0.1:9600/_node/stats/pipelines?pretty | python3 -c "
import sys,json
q = json.load(sys.stdin)['pipelines']['main'].get('queue',{})
print(f\"Queue type: {q.get('type','?')}, events: {q.get('events_count',0)}\")
print(f\"Size: {q.get('queue_size_in_bytes',0)} / {q.get('max_queue_size_in_bytes','N/A')} bytes\")
"

# Grok failures counter: sudden increase indicates format change at source
curl -sS http://127.0.0.1:9600/_node/stats/pipelines?pretty | python3 -c "
import sys,json
filters = json.load(sys.stdin)['pipelines']['main']['plugins']['filters']
for f in filters:
    if f.get('name') == 'grok':
        e = f.get('events',{})
        print(f\"grok ({f.get('id','?')}): failures={e.get('failures',0)}, in={e.get('in',0)}\")
"

# Timeout evidence in the log
grep -i 'groktimeout\|Timeout executing grok' /var/log/logstash/logstash-plain.log | tail -n 50

How to diagnose it

Confirm the bottleneck is in filters, not outputs. Check that output plugin duration is stable and there are no output errors or retries. If output duration is also high, the problem is downstream. High CPU with no output errors points to a CPU-bound filter; low CPU with output errors points to downstream backpressure.
Identify which filter dominates. Pull per-plugin stats and look for a grok filter whose per-event duration (computed from duration_in_millis divided by event count) or share of total duration_in_millis is disproportionate. A single grok filter consuming more than 80% of total pipeline processing time is the telltale.
Confirm regex is the CPU consumer. Capture two or three hot threads snapshots a few seconds apart. If org.jruby.RubyRegexp or grok-related frames consistently top the CPU list, regex evaluation is the bottleneck. A single snapshot can be noisy; repeated samples separate steady bottlenecks from transient work.
Check whether the spike correlates with a data change. Look at the grok failures counter. A sudden increase suggests a source format change that is triggering either parse failures (fast fail) or near-miss inputs that hit the backtracking path (slow fail). Cross-reference with recent deployments or known source-side changes.
Reproduce the problematic input. If you can identify the event shape causing the stall, extract a sample and test the pattern in isolation. A grok pattern that takes milliseconds on normal input but seconds or longer on the sample confirms catastrophic backtracking.
Check for timeout evidence. Search the log for _groktimeout tags or “Timeout executing grok” messages. These indicate events are hitting the timeout_millis limit.

Metrics and signals to monitor

Signal	Why it matters	Warning sign
Per-filter `duration_in_millis` per event	Directly measures per-event cost of each filter (computed from API fields); Logstash 8.6.0 and later exposes this natively as per-filter `flow.worker_millis_per_event`	One grok filter’s value spikes above baseline without event-complexity change
Per-filter `duration_in_millis` share	Shows which filter dominates pipeline time	Single filter consuming more than 80% of total processing time
`flow.worker_utilization`	Indicates worker saturation (Logstash 8.x)	Sustained above 90% with growing queue
`process.cpu.percent`	Confirms CPU-bound processing	High CPU with no output errors or downstream issues
Hot threads (`/_node/hot_threads`)	Shows what threads are actually doing	`org.jruby.RubyRegexp` frames dominating CPU time
Queue `events_count`	Confirms workers cannot drain fast enough	Monotonic growth over minutes
Grok `failures` counter	Indicates format drift at source	Sudden rate increase correlating with duration spike

Fixes

Anchor your patterns

The single most impactful fix is adding ^ and $ anchors to grok patterns. Without anchors, the regex engine attempts to match at every position in the input string. On a non-matching line, this means the engine runs the full pattern, including any backtracking paths, starting at every character position. Anchoring eliminates this substring search entirely.

# Before: engine tries match at every position, backtracking at each
match => { "message" => "%{GREEDYDATA:timestamp} %{LOGLEVEL:level} %{GREEDYDATA:msg}" }

# After: engine attempts match exactly once
match => { "message" => "^%{GREEDYDATA:timestamp} %{LOGLEVEL:level} %{GREEDYDATA:msg}$" }

Anchoring lets the engine reject a non-matching line in one pass rather than trying every substring position.

Replace mid-pattern GREEDYDATA with bounded alternatives

%{GREEDYDATA} compiles to .*, a greedy quantifier that matches as much as possible before backtracking. When GREEDYDATA appears in the middle of a pattern, the engine must backtrack through the entire remaining string to satisfy subsequent pattern elements. For large messages, this is expensive.

Replace mid-pattern GREEDYDATA with more specific alternatives:

%{DATA} (lazy .*?) when you need minimal matching
Character classes for known delimiters: [^\]]+ for bracketed content, [^,]+ for comma-separated values
Named patterns for known field formats

# Before: GREEDYDATA in the middle forces backtracking
match => { "message" => "\[%{GREEDYDATA:ts}\] %{LOGLEVEL:level} %{GREEDYDATA:msg}" }

# After: bounded alternatives prevent runaway backtracking
match => { "message" => "\[%{DATA:ts}\] %{LOGLEVEL:level} %{GREEDYDATA:msg}" }

Keeping GREEDYDATA at the end of the pattern is generally safe because there is nothing after it to backtrack into.

Use dissect for fixed-format logs

When the log format is positional and consistent, the dissect filter is faster than grok and avoids regex entirely. Dissect splits on literal delimiters rather than evaluating regex patterns, making it immune to backtracking. Use grok for formats that require actual regex matching (variable whitespace, optional fields, alternative formats) and dissect for straightforward delimited formats.

Set timeout_millis on the grok filter

The grok filter supports timeout_millis to cap how long a single pattern evaluation can run. The default is 30000 (30 seconds). For most production pipelines, this is too generous: a single bad event can stall a worker for half a minute before timing out.

grok {
  id => "parse_app_logs"
  match => { "message" => "^%{TIMESTAMP_ISO8601:ts} %{LOGLEVEL:level} %{GREEDYDATA:msg}$" }
  timeout_millis => 500
  tag_on_timeout => ["_groktimeout"]
}

Consider lowering timeout_millis to 500-1000ms. When a timeout fires, the event is tagged (default tag _groktimeout) and processing continues. This prevents one pathological event from monopolizing a worker.

Tradeoff: timeout handling overhead. In grok filter v4.1.0 and later, the timeout mechanism uses JRuby’s Timeout.timeout, which introduces per-event overhead, especially with multiple fallback patterns. This mechanism is still the current implementation in the grok filter source, so the tradeoff stands and there is no newer design that removes it. If you observe throughput degradation after enabling timeouts and your patterns are well-anchored and bounded, setting timeout_millis => 0 disables timeout handling entirely and removes this overhead, at the cost of losing protection against runaway patterns.

Tradeoff: timeout precision. The actual timeout is approximate. The grok filter source states this directly: “Actual timeout is approximate based on a 250ms quantization.”

Use timeout_scope event for lower overhead

timeout_scope is a real grok filter option with values pattern (the default) and event. It controls whether the timeout applies per-pattern (pattern, the default) or per-event (event). With multiple fallback patterns in a single grok block, per-pattern timeout means each pattern gets its own timeout window, multiplying the worst case. Setting timeout_scope => "event" applies a single timeout across all patterns for that event, reducing total overhead.

grok {
  match => { "message" => ["^pattern_one...", "^pattern_two...", "^pattern_three..."] }
  timeout_millis => 500
  timeout_scope => "event"
}

Note: timeout_scope was added in grok filter v4.2.0, which ships with Logstash 7.6.0 and later. If the option is not recognized, your plugin version is too old and you need to update.

Test patterns against worst-case input

Before deploying a new or modified grok pattern, test it against adversarial inputs. Craft near-miss lines that almost match but fail near the end of the pattern, as well as large messages (100KB+) that stress greedy quantifiers. If a test input takes more than a few hundred milliseconds, the pattern is vulnerable to backtracking.

Prevention

Always assign id to grok filters. Without an explicit id, Logstash auto-generates opaque identifiers, making it impossible to map per-plugin stats back to the correct configuration block.
Anchor every pattern. Make ^ and $ a review requirement for all grok patterns before deployment.
Audit GREEDYDATA placement. Flag any %{GREEDYDATA} that is not at the end of a pattern. Replace with bounded alternatives during review.
Set a conservative timeout_millis. 500ms is a reasonable default for most log parsing. This bounds the worst case per event.
Monitor per-filter processing duration per event. A sudden increase, without a corresponding change in event complexity, is the earliest indicator that a pattern is hitting a pathological input.
Track the grok failures counter. A spike indicates source format drift, which often precedes a backtracking incident as near-miss inputs become more common.
Use tiered matching. Order patterns from most specific to least specific. With break_on_match enabled (the default), the first matching pattern wins and subsequent patterns are not evaluated, reducing total regex work.

How Netdata helps

Per-second metric resolution reveals per-event duration spikes that would be invisible at 10-second or 60-second polling intervals. A single backtracking event may cause a sub-second CPU spike that longer intervals average away.
Correlating CPU utilization, worker utilization, queue depth, and pipeline event rates in one view lets you confirm that the bottleneck is in the filter stage rather than downstream, narrowing the investigation immediately.
Anomaly detection on pipeline processing duration surfaces slow drift in filter cost before it becomes a queue-growth incident, which is especially valuable when backtracking only triggers on rare event shapes.
Baseline-relative alerting distinguishes a genuine per-event cost increase from normal workload variation, avoiding false positives from legitimate traffic bursts. Pair Netdata’s per-second CPU and pipeline metrics with the manual _node/hot_threads check to confirm regex backtracking as the root cause.