Skip to content

Commit

Permalink
Speed up matches in the presence of timeouts.
Browse files Browse the repository at this point in the history
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).
  • Loading branch information
ghemawat authored and dlclark committed Jan 13, 2023
1 parent 3511044 commit af93f4c
Show file tree
Hide file tree
Showing 7 changed files with 273 additions and 38 deletions.
38 changes: 38 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -92,6 +92,44 @@ if isMatch, _ := re.MatchString(`Something to match`); isMatch {

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?).

## Catastrophic Backtracking and Timeouts

`regexp2` supports features that can lead to catastrophic backtracking.
`Regexp.MatchTimeout` can be set to to limit the impact of such behavior; the
match will fail with an error after approximately MatchTimeout. No timeout
checks are done by default.

Timeout checking is not free. The current timeout checking implementation starts
a background worker that updates a clock value approximately once every 100
milliseconds. The matching code compares this value against the precomputed
deadline for the match. The performance impact is as follows.

1. A match with a timeout runs almost as fast as a match without a timeout.
2. If any live matches have a timeout, there will be a background CPU load
(`~0.15%` currently on a modern machine). This load will remain constant
regardless of the number of matches done including matches done in parallel.
3. If no live matches are using a timeout, the background load will remain
until the longest deadline (match timeout + the time when the match started)
is reached. E.g., if you set a timeout of one minute the load will persist
for approximately a minute even if the match finishes quickly.

Some alternative implementations were considered and ruled out.

1. **time.Now()** - This was the initial timeout implementation. It called `time.Now()`
and compared the result to the deadline approximately once every 1000 matching steps.
Adding a timeout to a simple match increased the cost from ~45ns to ~3000ns).
2. **time.AfterFunc** - This approach entails using `time.AfterFunc` to set an `expired`
atomic boolean value. However it increases the cost of handling a simple match
with a timeout from ~45ns to ~360ns and was therefore ruled out.
3. **counter** - In this approach an atomic variable tracks the number of live matches
with timeouts. The background clock stops when the counter hits zero. The benefit
of this approach is that the background load will stop more quickly (after the
last match has finished as opposed to waiting until the deadline for the last
match). However this approach requires more atomic variable updates and has poorer
performance when multiple matches are executed concurrently. (The cost of a
single match jumps from ~45ns to ~65ns, and the cost of running matches on
all 12 available CPUs jumps from ~400ns to ~730ns).

## ECMAScript compatibility mode
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.

Expand Down
104 changes: 104 additions & 0 deletions fastclock.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,104 @@
package regexp2

import (
"sync"
"sync/atomic"
"time"
)

// fasttime holds a time value (ticks since clock initialization)
type fasttime int64

// fastclock provides a fast clock implementation.
//
// A background goroutine periodically stores the current time
// into an atomic variable.
//
// A deadline can be quickly checked for expiration by comparing
// its value to the clock stored in the atomic variable.
//
// The goroutine automatically stops once clockEnd is reached.
// (clockEnd covers the largest deadline seen so far + some
// extra time). This ensures that if regexp2 with timeouts
// stops being used we will stop background work.
type fastclock struct {
// current and clockEnd can be read via atomic loads.
// Reads and writes of other fields require mu to be held.
mu sync.Mutex

start time.Time // Time corresponding to fasttime(0)
current atomicTime // Current time (approximate)
clockEnd atomicTime // When clock updater is supposed to stop (>= any existing deadline)
running bool // Is a clock updater running?
}

var fast fastclock

// reached returns true if current time is at or past t.
func (t fasttime) reached() bool {
return fast.current.read() >= t
}

// makeDeadline returns a time that is approximately time.Now().Add(d)
func makeDeadline(d time.Duration) fasttime {
// Increase the deadline since the clock we are reading may be
// just about to tick forwards.
end := fast.current.read() + durationToTicks(d+clockPeriod)

// Start or extend clock if necessary.
if end > fast.clockEnd.read() {
extendClock(end)
}
return end
}

// extendClock ensures that clock is live and will run until at least end.
func extendClock(end fasttime) {
fast.mu.Lock()
defer fast.mu.Unlock()

if fast.start.IsZero() {
fast.start = time.Now()
}

// Extend the running time to cover end as well as a bit of slop.
if shutdown := end + durationToTicks(time.Second); shutdown > fast.clockEnd.read() {
fast.clockEnd.write(shutdown)
}

// Start clock if necessary
if !fast.running {
fast.running = true
go runClock()
}
}

func durationToTicks(d time.Duration) fasttime {
// Downscale nanoseconds to approximately a millisecond so that we can avoid
// overflow even if the caller passes in math.MaxInt64.
return fasttime(d) >> 20
}

// clockPeriod is the approximate interval between updates of approximateClock.
const clockPeriod = 100 * time.Millisecond

func runClock() {
fast.mu.Lock()
defer fast.mu.Unlock()

for fast.current.read() <= fast.clockEnd.read() {
// Unlock while sleeping.
fast.mu.Unlock()
time.Sleep(clockPeriod)
fast.mu.Lock()

newTime := durationToTicks(time.Since(fast.start))
fast.current.write(newTime)
}
fast.running = false
}

type atomicTime struct{ v int64 } // Should change to atomic.Int64 when we can use go 1.19

func (t *atomicTime) read() fasttime { return fasttime(atomic.LoadInt64(&t.v)) }
func (t *atomicTime) write(v fasttime) { atomic.StoreInt64(&t.v, int64(v)) }
34 changes: 34 additions & 0 deletions fastclock_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,34 @@
package regexp2

import (
"fmt"
"testing"
"time"
)

func TestDeadline(t *testing.T) {
for _, delay := range []time.Duration{
clockPeriod / 10,
clockPeriod,
clockPeriod * 5,
clockPeriod * 10,
} {
delay := delay // Make copy for parallel sub-test.
t.Run(fmt.Sprint(delay), func(t *testing.T) {
t.Parallel()
start := time.Now()
d := makeDeadline(delay)
if d.reached() {
t.Fatalf("deadline (%v) unexpectedly expired immediately", delay)
}
time.Sleep(delay / 2)
if d.reached() {
t.Fatalf("deadline (%v) expired too soon (after %v)", delay, time.Since(start))
}
time.Sleep(delay/2 + 2*clockPeriod) // Give clock time to tick
if !d.reached() {
t.Fatalf("deadline (%v) did not expire within %v", delay, time.Since(start))
}
})
}
}
6 changes: 5 additions & 1 deletion regexp.go
Original file line number Diff line number Diff line change
Expand Up @@ -24,7 +24,11 @@ var DefaultMatchTimeout = time.Duration(math.MaxInt64)
// Regexp is the representation of a compiled regular expression.
// A Regexp is safe for concurrent use by multiple goroutines.
type Regexp struct {
//timeout when trying to find matches
// A match will time out if it takes (approximately) more than
// MatchTimeout. This is a safety check in case the match
// encounters catastrophic backtracking. The default value
// (DefaultMatchTimeout) causes all time out checking to be
// suppressed.
MatchTimeout time.Duration

// read-only after Compile
Expand Down
50 changes: 50 additions & 0 deletions regexp_performance_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@ package regexp2
import (
"strings"
"testing"
"time"
)

func BenchmarkLiteral(b *testing.B) {
Expand Down Expand Up @@ -58,13 +59,15 @@ func BenchmarkMatchClass_InRange(b *testing.B) {

/*
func BenchmarkReplaceAll(b *testing.B) {
x := "abcdefghijklmnopqrstuvwxyz"
b.StopTimer()
re := MustCompile("[cjrw]", 0)
b.StartTimer()
for i := 0; i < b.N; i++ {
re.ReplaceAllString(x, "")
}
}
*/
func BenchmarkAnchoredLiteralShortNonMatch(b *testing.B) {
Expand Down Expand Up @@ -305,3 +308,50 @@ func BenchmarkLeading(b *testing.B) {
}
}
}

func BenchmarkShortSearch(b *testing.B) {
type benchmark struct {
name string
parallel bool // Run in parallel?
timeout time.Duration
increase time.Duration // timeout increase per match
}
for _, mode := range []benchmark{
{"serial-no-timeout", false, DefaultMatchTimeout, 0},
{"serial-fixed-timeout", false, time.Second, 0},
{"serial-increasing-timeout", false, time.Second, time.Second},
{"parallel-no-timeout", true, DefaultMatchTimeout, 0},
{"parallel-fixed-timeout", true, time.Second, 0},
{"parallel-increasing-timeout", true, time.Second, time.Second},
} {
b.Run(mode.name, func(b *testing.B) {
t := makeText(100)
b.SetBytes(int64(len(t)))
matchOnce := func(r *Regexp) {
if m, err := r.MatchRunes(t); m {
b.Fatal("match!")
} else if err != nil {
b.Fatalf("Err %v", err)
}
}

if !mode.parallel {
r := MustCompile(easy0, 0)
r.MatchTimeout = mode.timeout
for i := 0; i < b.N; i++ {
matchOnce(r)
r.MatchTimeout += mode.increase
}
} else {
b.RunParallel(func(pb *testing.PB) {
r := MustCompile(easy0, 0)
r.MatchTimeout = mode.timeout
for pb.Next() {
matchOnce(r)
r.MatchTimeout += mode.increase
}
})
}
})
}
}
44 changes: 37 additions & 7 deletions regexp_test.go
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
package regexp2

import (
"fmt"
"reflect"
"strings"
"testing"
Expand All @@ -11,14 +12,43 @@ import (

func TestBacktrack_CatastrophicTimeout(t *testing.T) {
r, err := Compile("(.+)*\\?", 0)
r.MatchTimeout = time.Millisecond * 1
t.Logf("code dump: %v", r.code.Dump())
m, err := r.FindStringMatch("Do you think you found the problem string!")
if err == nil {
t.Errorf("expected timeout err")
if err != nil {
t.Fatal(err)
}
if m != nil {
t.Errorf("Expected no match")
t.Logf("code dump: %v", r.code.Dump())
const subject = "Do you think you found the problem string!"

const earlyAllowance = 10 * time.Millisecond
const lateAllowance = clockPeriod + 500*time.Millisecond // Large allowance in case machine is slow

for _, timeout := range []time.Duration{
-1 * time.Millisecond,
0 * time.Millisecond,
1 * time.Millisecond,
10 * time.Millisecond,
100 * time.Millisecond,
500 * time.Millisecond,
1000 * time.Millisecond,
} {
t.Run(fmt.Sprint(timeout), func(t *testing.T) {
r.MatchTimeout = timeout
start := time.Now()
m, err := r.FindStringMatch(subject)
elapsed := time.Since(start)
if err == nil {
t.Errorf("expected timeout err")
}
if m != nil {
t.Errorf("Expected no match")
}
t.Logf("timeed out after %v", elapsed)
if elapsed < timeout-earlyAllowance {
t.Errorf("Match timed out too quickly (%v instead of expected %v)", elapsed, timeout-earlyAllowance)
}
if elapsed > timeout+lateAllowance {
t.Errorf("Match timed out too late (%v instead of expected %v)", elapsed, timeout+lateAllowance)
}
})
}
}

Expand Down
35 changes: 5 additions & 30 deletions runner.go
Original file line number Diff line number Diff line change
Expand Up @@ -58,10 +58,9 @@ type runner struct {

runmatch *Match // result object

ignoreTimeout bool
timeout time.Duration // timeout in milliseconds (needed for actual)
timeoutChecksToSkip int
timeoutAt time.Time
ignoreTimeout bool
timeout time.Duration // timeout in milliseconds (needed for actual)
deadline fasttime

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

// this seems like a comment to justify randomly picking 1000 :-P
// We have determined this value in a series of experiments where x86 retail
// builds (ono-lab-optimized) were run on different pattern/input pairs. Larger values
// of TimeoutCheckFrequency did not tend to increase performance; smaller values
// of TimeoutCheckFrequency tended to slow down the execution.
const timeoutCheckFrequency int = 1000

func (r *runner) startTimeoutWatch() {
if r.ignoreTimeout {
return
}

r.timeoutChecksToSkip = timeoutCheckFrequency
r.timeoutAt = time.Now().Add(r.timeout)
r.deadline = makeDeadline(r.timeout)
}

func (r *runner) checkTimeout() error {
if r.ignoreTimeout {
return nil
}
r.timeoutChecksToSkip--
if r.timeoutChecksToSkip != 0 {
return nil
}

r.timeoutChecksToSkip = timeoutCheckFrequency
return r.doCheckTimeout()
}

func (r *runner) doCheckTimeout() error {
current := time.Now()

if current.Before(r.timeoutAt) {
if r.ignoreTimeout || !r.deadline.reached() {
return nil
}

Expand Down

0 comments on commit af93f4c

Please sign in to comment.