Skip to content

Commit af93f4c

Browse files
ghemawatdlclark
authored andcommitted
Speed up matches in the presence of timeouts.
Currently regexp2 can be quite slow when a MatchTimeout is supplied (a micro-benchmark shows 3000ns compared to 45ns when no timeout is supplied). This slowdown is caused by repeated timeout checks which call time.Now(). The new approach introduces a fast but approximate clock that is just an atomic variable updated by a goroutine once very 100ms. The new timeout check just compares this variable to the precomputed deadline. Removed "timeout check skip" mechanism since a timeout check is now very cheap. Added a simple micro-benchmark that compares the speed of searching 100 byte text with and without a timeout. Performance impact: 1. A micro-benchmark that looks for an "easy" regexp in a 100 byte string goes from ~3000ns to ~45ns. 2. Chroma (syntax highlighter) speeds up from ~500ms to ~50ms on a 24KB source file. 3. A background CPU load of ~0.15% is present until the end of of all match deadlines (even for matches that have finished).
1 parent 3511044 commit af93f4c

7 files changed

+273
-38
lines changed

README.md

Lines changed: 38 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -92,6 +92,44 @@ if isMatch, _ := re.MatchString(`Something to match`); isMatch {
9292

9393
This feature is a work in progress and I'm open to ideas for more things to put here (maybe more relaxed character escaping rules?).
9494

95+
## Catastrophic Backtracking and Timeouts
96+
97+
`regexp2` supports features that can lead to catastrophic backtracking.
98+
`Regexp.MatchTimeout` can be set to to limit the impact of such behavior; the
99+
match will fail with an error after approximately MatchTimeout. No timeout
100+
checks are done by default.
101+
102+
Timeout checking is not free. The current timeout checking implementation starts
103+
a background worker that updates a clock value approximately once every 100
104+
milliseconds. The matching code compares this value against the precomputed
105+
deadline for the match. The performance impact is as follows.
106+
107+
1. A match with a timeout runs almost as fast as a match without a timeout.
108+
2. If any live matches have a timeout, there will be a background CPU load
109+
(`~0.15%` currently on a modern machine). This load will remain constant
110+
regardless of the number of matches done including matches done in parallel.
111+
3. If no live matches are using a timeout, the background load will remain
112+
until the longest deadline (match timeout + the time when the match started)
113+
is reached. E.g., if you set a timeout of one minute the load will persist
114+
for approximately a minute even if the match finishes quickly.
115+
116+
Some alternative implementations were considered and ruled out.
117+
118+
1. **time.Now()** - This was the initial timeout implementation. It called `time.Now()`
119+
and compared the result to the deadline approximately once every 1000 matching steps.
120+
Adding a timeout to a simple match increased the cost from ~45ns to ~3000ns).
121+
2. **time.AfterFunc** - This approach entails using `time.AfterFunc` to set an `expired`
122+
atomic boolean value. However it increases the cost of handling a simple match
123+
with a timeout from ~45ns to ~360ns and was therefore ruled out.
124+
3. **counter** - In this approach an atomic variable tracks the number of live matches
125+
with timeouts. The background clock stops when the counter hits zero. The benefit
126+
of this approach is that the background load will stop more quickly (after the
127+
last match has finished as opposed to waiting until the deadline for the last
128+
match). However this approach requires more atomic variable updates and has poorer
129+
performance when multiple matches are executed concurrently. (The cost of a
130+
single match jumps from ~45ns to ~65ns, and the cost of running matches on
131+
all 12 available CPUs jumps from ~400ns to ~730ns).
132+
95133
## ECMAScript compatibility mode
96134
In this mode the engine provides compatibility with the [regex engine](https://tc39.es/ecma262/multipage/text-processing.html#sec-regexp-regular-expression-objects) described in the ECMAScript specification.
97135

fastclock.go

Lines changed: 104 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,104 @@
1+
package regexp2
2+
3+
import (
4+
"sync"
5+
"sync/atomic"
6+
"time"
7+
)
8+
9+
// fasttime holds a time value (ticks since clock initialization)
10+
type fasttime int64
11+
12+
// fastclock provides a fast clock implementation.
13+
//
14+
// A background goroutine periodically stores the current time
15+
// into an atomic variable.
16+
//
17+
// A deadline can be quickly checked for expiration by comparing
18+
// its value to the clock stored in the atomic variable.
19+
//
20+
// The goroutine automatically stops once clockEnd is reached.
21+
// (clockEnd covers the largest deadline seen so far + some
22+
// extra time). This ensures that if regexp2 with timeouts
23+
// stops being used we will stop background work.
24+
type fastclock struct {
25+
// current and clockEnd can be read via atomic loads.
26+
// Reads and writes of other fields require mu to be held.
27+
mu sync.Mutex
28+
29+
start time.Time // Time corresponding to fasttime(0)
30+
current atomicTime // Current time (approximate)
31+
clockEnd atomicTime // When clock updater is supposed to stop (>= any existing deadline)
32+
running bool // Is a clock updater running?
33+
}
34+
35+
var fast fastclock
36+
37+
// reached returns true if current time is at or past t.
38+
func (t fasttime) reached() bool {
39+
return fast.current.read() >= t
40+
}
41+
42+
// makeDeadline returns a time that is approximately time.Now().Add(d)
43+
func makeDeadline(d time.Duration) fasttime {
44+
// Increase the deadline since the clock we are reading may be
45+
// just about to tick forwards.
46+
end := fast.current.read() + durationToTicks(d+clockPeriod)
47+
48+
// Start or extend clock if necessary.
49+
if end > fast.clockEnd.read() {
50+
extendClock(end)
51+
}
52+
return end
53+
}
54+
55+
// extendClock ensures that clock is live and will run until at least end.
56+
func extendClock(end fasttime) {
57+
fast.mu.Lock()
58+
defer fast.mu.Unlock()
59+
60+
if fast.start.IsZero() {
61+
fast.start = time.Now()
62+
}
63+
64+
// Extend the running time to cover end as well as a bit of slop.
65+
if shutdown := end + durationToTicks(time.Second); shutdown > fast.clockEnd.read() {
66+
fast.clockEnd.write(shutdown)
67+
}
68+
69+
// Start clock if necessary
70+
if !fast.running {
71+
fast.running = true
72+
go runClock()
73+
}
74+
}
75+
76+
func durationToTicks(d time.Duration) fasttime {
77+
// Downscale nanoseconds to approximately a millisecond so that we can avoid
78+
// overflow even if the caller passes in math.MaxInt64.
79+
return fasttime(d) >> 20
80+
}
81+
82+
// clockPeriod is the approximate interval between updates of approximateClock.
83+
const clockPeriod = 100 * time.Millisecond
84+
85+
func runClock() {
86+
fast.mu.Lock()
87+
defer fast.mu.Unlock()
88+
89+
for fast.current.read() <= fast.clockEnd.read() {
90+
// Unlock while sleeping.
91+
fast.mu.Unlock()
92+
time.Sleep(clockPeriod)
93+
fast.mu.Lock()
94+
95+
newTime := durationToTicks(time.Since(fast.start))
96+
fast.current.write(newTime)
97+
}
98+
fast.running = false
99+
}
100+
101+
type atomicTime struct{ v int64 } // Should change to atomic.Int64 when we can use go 1.19
102+
103+
func (t *atomicTime) read() fasttime { return fasttime(atomic.LoadInt64(&t.v)) }
104+
func (t *atomicTime) write(v fasttime) { atomic.StoreInt64(&t.v, int64(v)) }

fastclock_test.go

Lines changed: 34 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,34 @@
1+
package regexp2
2+
3+
import (
4+
"fmt"
5+
"testing"
6+
"time"
7+
)
8+
9+
func TestDeadline(t *testing.T) {
10+
for _, delay := range []time.Duration{
11+
clockPeriod / 10,
12+
clockPeriod,
13+
clockPeriod * 5,
14+
clockPeriod * 10,
15+
} {
16+
delay := delay // Make copy for parallel sub-test.
17+
t.Run(fmt.Sprint(delay), func(t *testing.T) {
18+
t.Parallel()
19+
start := time.Now()
20+
d := makeDeadline(delay)
21+
if d.reached() {
22+
t.Fatalf("deadline (%v) unexpectedly expired immediately", delay)
23+
}
24+
time.Sleep(delay / 2)
25+
if d.reached() {
26+
t.Fatalf("deadline (%v) expired too soon (after %v)", delay, time.Since(start))
27+
}
28+
time.Sleep(delay/2 + 2*clockPeriod) // Give clock time to tick
29+
if !d.reached() {
30+
t.Fatalf("deadline (%v) did not expire within %v", delay, time.Since(start))
31+
}
32+
})
33+
}
34+
}

regexp.go

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -24,7 +24,11 @@ var DefaultMatchTimeout = time.Duration(math.MaxInt64)
2424
// Regexp is the representation of a compiled regular expression.
2525
// A Regexp is safe for concurrent use by multiple goroutines.
2626
type Regexp struct {
27-
//timeout when trying to find matches
27+
// A match will time out if it takes (approximately) more than
28+
// MatchTimeout. This is a safety check in case the match
29+
// encounters catastrophic backtracking. The default value
30+
// (DefaultMatchTimeout) causes all time out checking to be
31+
// suppressed.
2832
MatchTimeout time.Duration
2933

3034
// read-only after Compile

regexp_performance_test.go

Lines changed: 50 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@ package regexp2
33
import (
44
"strings"
55
"testing"
6+
"time"
67
)
78

89
func BenchmarkLiteral(b *testing.B) {
@@ -58,13 +59,15 @@ func BenchmarkMatchClass_InRange(b *testing.B) {
5859

5960
/*
6061
func BenchmarkReplaceAll(b *testing.B) {
62+
6163
x := "abcdefghijklmnopqrstuvwxyz"
6264
b.StopTimer()
6365
re := MustCompile("[cjrw]", 0)
6466
b.StartTimer()
6567
for i := 0; i < b.N; i++ {
6668
re.ReplaceAllString(x, "")
6769
}
70+
6871
}
6972
*/
7073
func BenchmarkAnchoredLiteralShortNonMatch(b *testing.B) {
@@ -305,3 +308,50 @@ func BenchmarkLeading(b *testing.B) {
305308
}
306309
}
307310
}
311+
312+
func BenchmarkShortSearch(b *testing.B) {
313+
type benchmark struct {
314+
name string
315+
parallel bool // Run in parallel?
316+
timeout time.Duration
317+
increase time.Duration // timeout increase per match
318+
}
319+
for _, mode := range []benchmark{
320+
{"serial-no-timeout", false, DefaultMatchTimeout, 0},
321+
{"serial-fixed-timeout", false, time.Second, 0},
322+
{"serial-increasing-timeout", false, time.Second, time.Second},
323+
{"parallel-no-timeout", true, DefaultMatchTimeout, 0},
324+
{"parallel-fixed-timeout", true, time.Second, 0},
325+
{"parallel-increasing-timeout", true, time.Second, time.Second},
326+
} {
327+
b.Run(mode.name, func(b *testing.B) {
328+
t := makeText(100)
329+
b.SetBytes(int64(len(t)))
330+
matchOnce := func(r *Regexp) {
331+
if m, err := r.MatchRunes(t); m {
332+
b.Fatal("match!")
333+
} else if err != nil {
334+
b.Fatalf("Err %v", err)
335+
}
336+
}
337+
338+
if !mode.parallel {
339+
r := MustCompile(easy0, 0)
340+
r.MatchTimeout = mode.timeout
341+
for i := 0; i < b.N; i++ {
342+
matchOnce(r)
343+
r.MatchTimeout += mode.increase
344+
}
345+
} else {
346+
b.RunParallel(func(pb *testing.PB) {
347+
r := MustCompile(easy0, 0)
348+
r.MatchTimeout = mode.timeout
349+
for pb.Next() {
350+
matchOnce(r)
351+
r.MatchTimeout += mode.increase
352+
}
353+
})
354+
}
355+
})
356+
}
357+
}

regexp_test.go

Lines changed: 37 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
package regexp2
22

33
import (
4+
"fmt"
45
"reflect"
56
"strings"
67
"testing"
@@ -11,14 +12,43 @@ import (
1112

1213
func TestBacktrack_CatastrophicTimeout(t *testing.T) {
1314
r, err := Compile("(.+)*\\?", 0)
14-
r.MatchTimeout = time.Millisecond * 1
15-
t.Logf("code dump: %v", r.code.Dump())
16-
m, err := r.FindStringMatch("Do you think you found the problem string!")
17-
if err == nil {
18-
t.Errorf("expected timeout err")
15+
if err != nil {
16+
t.Fatal(err)
1917
}
20-
if m != nil {
21-
t.Errorf("Expected no match")
18+
t.Logf("code dump: %v", r.code.Dump())
19+
const subject = "Do you think you found the problem string!"
20+
21+
const earlyAllowance = 10 * time.Millisecond
22+
const lateAllowance = clockPeriod + 500*time.Millisecond // Large allowance in case machine is slow
23+
24+
for _, timeout := range []time.Duration{
25+
-1 * time.Millisecond,
26+
0 * time.Millisecond,
27+
1 * time.Millisecond,
28+
10 * time.Millisecond,
29+
100 * time.Millisecond,
30+
500 * time.Millisecond,
31+
1000 * time.Millisecond,
32+
} {
33+
t.Run(fmt.Sprint(timeout), func(t *testing.T) {
34+
r.MatchTimeout = timeout
35+
start := time.Now()
36+
m, err := r.FindStringMatch(subject)
37+
elapsed := time.Since(start)
38+
if err == nil {
39+
t.Errorf("expected timeout err")
40+
}
41+
if m != nil {
42+
t.Errorf("Expected no match")
43+
}
44+
t.Logf("timeed out after %v", elapsed)
45+
if elapsed < timeout-earlyAllowance {
46+
t.Errorf("Match timed out too quickly (%v instead of expected %v)", elapsed, timeout-earlyAllowance)
47+
}
48+
if elapsed > timeout+lateAllowance {
49+
t.Errorf("Match timed out too late (%v instead of expected %v)", elapsed, timeout+lateAllowance)
50+
}
51+
})
2252
}
2353
}
2454

runner.go

Lines changed: 5 additions & 30 deletions
Original file line numberDiff line numberDiff line change
@@ -58,10 +58,9 @@ type runner struct {
5858

5959
runmatch *Match // result object
6060

61-
ignoreTimeout bool
62-
timeout time.Duration // timeout in milliseconds (needed for actual)
63-
timeoutChecksToSkip int
64-
timeoutAt time.Time
61+
ignoreTimeout bool
62+
timeout time.Duration // timeout in milliseconds (needed for actual)
63+
deadline fasttime
6564

6665
operator syntax.InstOp
6766
codepos int
@@ -1551,39 +1550,15 @@ func (r *runner) isECMABoundary(index, startpos, endpos int) bool {
15511550
(index < endpos && syntax.IsECMAWordChar(r.runtext[index]))
15521551
}
15531552

1554-
// this seems like a comment to justify randomly picking 1000 :-P
1555-
// We have determined this value in a series of experiments where x86 retail
1556-
// builds (ono-lab-optimized) were run on different pattern/input pairs. Larger values
1557-
// of TimeoutCheckFrequency did not tend to increase performance; smaller values
1558-
// of TimeoutCheckFrequency tended to slow down the execution.
1559-
const timeoutCheckFrequency int = 1000
1560-
15611553
func (r *runner) startTimeoutWatch() {
15621554
if r.ignoreTimeout {
15631555
return
15641556
}
1565-
1566-
r.timeoutChecksToSkip = timeoutCheckFrequency
1567-
r.timeoutAt = time.Now().Add(r.timeout)
1557+
r.deadline = makeDeadline(r.timeout)
15681558
}
15691559

15701560
func (r *runner) checkTimeout() error {
1571-
if r.ignoreTimeout {
1572-
return nil
1573-
}
1574-
r.timeoutChecksToSkip--
1575-
if r.timeoutChecksToSkip != 0 {
1576-
return nil
1577-
}
1578-
1579-
r.timeoutChecksToSkip = timeoutCheckFrequency
1580-
return r.doCheckTimeout()
1581-
}
1582-
1583-
func (r *runner) doCheckTimeout() error {
1584-
current := time.Now()
1585-
1586-
if current.Before(r.timeoutAt) {
1561+
if r.ignoreTimeout || !r.deadline.reached() {
15871562
return nil
15881563
}
15891564

0 commit comments

Comments
 (0)