[BUG] runtime error in (*routeRegexp).Match

[streamer45]

Is there an existing issue for this?

• [X] I have searched the existing issues

Current Behavior

Code panics

Expected Behavior

Not to panic but return an error

Steps To Reproduce

It's a sporadic issue we spotted through automation (Sentry) so hard to tell how it could be reproduced but somehow the regexp pointer is nil when the code attempts to match.

Anything else?

Stacktrace

runtime.errorString: runtime error: invalid memory address or nil pointer dereference
  File "regexp/exec.go", line 527, in (*Regexp).doExecute
  File "regexp/exec.go", line 514, in (*Regexp).doMatch
  File "regexp/regexp.go", line 533, in (*Regexp).MatchString
  File "github.com/gorilla/[email protected]/regexp.go", line 193, in (*routeRegexp).Match
  File "github.com/gorilla/[email protected]/route.go", line 50, in (*Route).Match
  File "github.com/gorilla/[email protected]/mux.go", line 138, in (*Router).Match
  File "github.com/gorilla/[email protected]/route.go", line 50, in (*Route).Match
  File "github.com/gorilla/[email protected]/mux.go", line 138, in (*Router).Match
  File "github.com/gorilla/[email protected]/route.go", line 50, in (*Route).Match
  File "github.com/gorilla/[email protected]/mux.go", line 138, in (*Router).Match
  File "github.com/gorilla/[email protected]/mux.go", line 196, in (*Router).ServeHTTP
  File "net/http/server.go", line 2109, in HandlerFunc.ServeHTTP
  File "net/http/server.go", line 2947, in serverHandler.ServeHTTP
  File "net/http/server.go", line 1991, in (*conn).serve

[arcward]

The test below- while it doesn't yet replicate this- when it's run with -race, gives a similar stack trace from the race detector (the lines are off by a couple presumably due to version differences), and seems similar to #742:

func TestConcurrentRouteMatchingAndModification(t *testing.T) {
	r := NewRouter()

	var wg sync.WaitGroup
	concurrency := 1000
	panicChan := make(chan interface{}, concurrency)

	for i := 0; i < concurrency; i++ {
		wg.Add(1)
		go func(i int) {

			defer func() {
				if re := recover(); re != nil {
					panicChan <- re
				}
			}()

			defer wg.Done()

			if i%2 == 0 {
				r.HandleFunc(
					fmt.Sprintf("/test/%d/{id:[0-9]+}", i),
					func(w http.ResponseWriter, r *http.Request) {
						defer func() {
							if perr := recover(); perr != nil {
								t.Fatalf("%v", perr)
							}
						}()
						// t.Logf("request: %s", r.RequestURI)
					},
				)
			} else {
				req := httptest.NewRequest(
					"GET",
					fmt.Sprintf("/test/%d/123", i-1),
					nil,
				)
				w := httptest.NewRecorder()
				r.ServeHTTP(w, req)
			}
		}(i)
	}

	wg.Wait()
	close(panicChan)

	for p := range panicChan {
		t.Errorf("Panic occurred: %v", p)
	}
}

Data races:

Read at 0x00c00023a550 by goroutine 9:
  github.com/gorilla/mux.(*routeRegexp).Match()
      /home/arcward/dev/mux/regexp.go:190 +0x54
  github.com/gorilla/mux.(*Route).Match()
      /home/arcward/dev/mux/route.go:56 +0x144
  github.com/gorilla/mux.(*Router).Match()
      /home/arcward/dev/mux/mux.go:154 +0xbe
  github.com/gorilla/mux.(*Router).ServeHTTP()
      /home/arcward/dev/mux/mux.go:204 +0x1d2
  github.com/gorilla/mux.TestConcurrentRouteMatchingAndModification.func1()
      /home/arcward/dev/mux/route_test.go:328 +0x416
  github.com/gorilla/mux.TestConcurrentRouteMatchingAndModification.gowrap1()
      /home/arcward/dev/mux/route_test.go:330 +0x41

Previous write at 0x00c00023a550 by goroutine 10:
  github.com/gorilla/mux.newRouteRegexp()
      /home/arcward/dev/mux/regexp.go:157 +0xd3e
  github.com/gorilla/mux.(*Route).addRegexpMatcher()
      /home/arcward/dev/mux/route.go:259 +0x26f
  github.com/gorilla/mux.(*Route).Path()
      /home/arcward/dev/mux/route.go:427 +0x392
  github.com/gorilla/mux.(*Router).HandleFunc()
      /home/arcward/dev/mux/mux.go:345 +0x460
  github.com/gorilla/mux.TestConcurrentRouteMatchingAndModification.func1()
      /home/arcward/dev/mux/route_test.go:309 +0x248
  github.com/gorilla/mux.TestConcurrentRouteMatchingAndModification.gowrap1()
      /home/arcward/dev/mux/route_test.go:330 +0x41

==================
WARNING: DATA RACE
Read at 0x00c00023e270 by goroutine 9:
  regexp.(*Regexp).doExecute()
      /home/arcward/sdk/go1.22.5/src/regexp/exec.go:527 +0xfd
  regexp.(*Regexp).doMatch()
      /home/arcward/sdk/go1.22.5/src/regexp/exec.go:514 +0x344
  regexp.(*Regexp).MatchString()
      /home/arcward/sdk/go1.22.5/src/regexp/regexp.go:531 +0x315
  github.com/gorilla/mux.(*routeRegexp).Match()
      /home/arcward/dev/mux/regexp.go:208 +0x2bb
  github.com/gorilla/mux.(*Route).Match()
      /home/arcward/dev/mux/route.go:56 +0x144
  github.com/gorilla/mux.(*Router).Match()
      /home/arcward/dev/mux/mux.go:154 +0xbe
  github.com/gorilla/mux.(*Router).ServeHTTP()
      /home/arcward/dev/mux/mux.go:204 +0x1d2
  github.com/gorilla/mux.TestConcurrentRouteMatchingAndModification.func1()
      /home/arcward/dev/mux/route_test.go:328 +0x416
  github.com/gorilla/mux.TestConcurrentRouteMatchingAndModification.gowrap1()
      /home/arcward/dev/mux/route_test.go:330 +0x41

Previous write at 0x00c00023e270 by goroutine 10:
  regexp.compile()
      /home/arcward/sdk/go1.22.5/src/regexp/regexp.go:188 +0x2ad
  regexp.Compile()
      /home/arcward/sdk/go1.22.5/src/regexp/regexp.go:135 +0x3a
  github.com/gorilla/mux.newRouteRegexp()
      /home/arcward/dev/mux/regexp.go:132 +0xbad
  github.com/gorilla/mux.(*Route).addRegexpMatcher()
      /home/arcward/dev/mux/route.go:259 +0x26f
  github.com/gorilla/mux.(*Route).Path()
      /home/arcward/dev/mux/route.go:427 +0x392
  github.com/gorilla/mux.(*Router).HandleFunc()
      /home/arcward/dev/mux/mux.go:345 +0x460
  github.com/gorilla/mux.TestConcurrentRouteMatchingAndModification.func1()
      /home/arcward/dev/mux/route_test.go:309 +0x248
  github.com/gorilla/mux.TestConcurrentRouteMatchingAndModification.gowrap1()
      /home/arcward/dev/mux/route_test.go:330 +0x41

I was able to eliminate the races by adding mutexes to:

• Router.HandleFunc() (Lock)
• Router.Path() (RLock)
• Route.Match() (RLock)
• Route.Handler() (Lock)
• Route.Path() (Lock - modifies regex matchers)

The race at least seems to be from functions being able to concurrently read/copy/modify routeConf.matchers, and I'd be curious if eliminating the race would resolve the issue here... but like I said, I have to poke around a bit more to try to fully replicate it to induce a panic (there's stuff happening when adding a new path that I'm not totally familiar with at the moment)

[ghost]

@arcward The mux does not support modifying routes concurrently with serving requests. Applications should assume this restriction following Go conventions (concurrency is not supported unless explicitly stated). Perhaps the documentation should be updated to explicitly state the restriction.

@streamer45 Does your application modify the routes concurrently with serving requests? Try running the application with the Data Race Detector to see if the detector reports any problems.

[streamer45]

@hulkingshtick Our full test suite runs in -race mode and has not reported problems, but of course coverage is far from 100%, so there's a chance there could be races. We'll keep monitoring.

[ghost]

The panic indicates that the field routeRegexp.regexp == nil.

I cannot find a code path that will set the field to nil, even in the presence of a data race. I am leaving this comment in case it helps another investigator.

[jaitaiwan]

Very interesting thanks for sharing. If I am able to get around to this I’ll test it out

[arcward]

@hulkingshtick Entendu, and for normal usage, absolutely. After the nil I saw 'sentry' and 'automation' and suspected it may be something that (maybe only) happens in test cases. I honed in on copyRouteConf for the test which seems to line up, though it's difficult to reproduce (data races tend to make for unpredictable outcomes)