search

gin-contrib / timeout

Timeout middleware for Gin
MIT License
177 stars 37 forks source link

Data race on c.Next() and c.Abort() #45

Open AbdouB opened 1 year ago

AbdouB commented 1 year ago

Running go test with -race flag fails with detecting a race. The go routine for the handler calling Next() is accessing the same variable as the call to Abort() after a timeout.

Will be happy to open a PR if I get sometime to address this.

How to reproduce

Run go test -race ./... on the root level of the project

Expected

Tests to pass, and safe concurrent access to variables

Result


[GIN-debug] [WARNING] Running in "debug" mode. Switch to "release" mode in production.
 - using env:   export GIN_MODE=release
 - using code:  gin.SetMode(gin.ReleaseMode)

[GIN-debug] GET    /                         --> github.com/gin-contrib/timeout.New.func1 (1 handlers)
==================
WARNING: DATA RACE
Read at 0x00c000422128 by goroutine 8:
  github.com/gin-gonic/gin.(*Context).Status()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:839 +0x4e
  github.com/gin-gonic/gin.(*Context).Render()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:902 +0x3d
  github.com/gin-gonic/gin.(*Context).String()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:991 +0x6b
  github.com/gin-contrib/timeout.emptySuccessResponse()
     [...]/timeout/timeout_test.go:16 +0x2f
  github.com/gin-contrib/timeout.New.func1.1()
     [...]/timeout/timeout.go:55 +0xb7

Previous write at 0x00c000422128 by goroutine 7:
  github.com/gin-contrib/timeout.New.func1()
     [...]/timeout/timeout.go:88 +0x7c6
  github.com/gin-gonic/gin.(*Context).Next()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:173 +0xba3
  github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/gin.go:616 +0x785
  github.com/gin-gonic/gin.(*Engine).ServeHTTP()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/gin.go:572 +0x44b
  github.com/gin-contrib/timeout.TestTimeout()
     [...]/timeout/timeout_test.go:25 +0x2d4
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1576 +0x216
  testing.(*T).Run.func1()
      /usr/local/go/src/testing/testing.go:1629 +0x47

Goroutine 8 (running) created at:
  github.com/gin-contrib/timeout.New.func1()
     [...]/timeout/timeout.go:49 +0x4d5
  github.com/gin-gonic/gin.(*Context).Next()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:173 +0xba3
  github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/gin.go:616 +0x785
  github.com/gin-gonic/gin.(*Engine).ServeHTTP()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/gin.go:572 +0x44b
  github.com/gin-contrib/timeout.TestTimeout()
     [...]/timeout/timeout_test.go:25 +0x2d4
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1576 +0x216
  testing.(*T).Run.func1()
      /usr/local/go/src/testing/testing.go:1629 +0x47

Goroutine 7 (running) created at:
  testing.(*T).Run()
      /usr/local/go/src/testing/testing.go:1629 +0x805
  testing.runTests.func1()
      /usr/local/go/src/testing/testing.go:2036 +0x8d
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1576 +0x216
  testing.runTests()
      /usr/local/go/src/testing/testing.go:2034 +0x87c
  testing.(*M).Run()
      /usr/local/go/src/testing/testing.go:1906 +0xb44
  main.main()
      _testmain.go:59 +0x2e9
==================
==================
WARNING: DATA RACE
Read at 0x00c00041e068 by goroutine 8:
  github.com/gin-contrib/timeout.(*Writer).WriteHeader()
     [...]/timeout/writer.go:43 +0x74
  github.com/gin-gonic/gin.(*Context).Status()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:839 +0x66
  github.com/gin-gonic/gin.(*Context).Render()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:902 +0x3d
  github.com/gin-gonic/gin.(*Context).String()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:991 +0x6b
  github.com/gin-contrib/timeout.emptySuccessResponse()
     [...]/timeout/timeout_test.go:16 +0x2f
  github.com/gin-contrib/timeout.New.func1.1()
     [...]/timeout/timeout.go:55 +0xb7

Previous write at 0x00c00041e068 by goroutine 7:
  github.com/gin-contrib/timeout.New.func1()
     [...]/timeout/timeout.go:84 +0x6cd
  github.com/gin-gonic/gin.(*Context).Next()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:173 +0xba3
  github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/gin.go:616 +0x785
  github.com/gin-gonic/gin.(*Engine).ServeHTTP()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/gin.go:572 +0x44b
  github.com/gin-contrib/timeout.TestTimeout()
     [...]/timeout/timeout_test.go:25 +0x2d4
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1576 +0x216
  testing.(*T).Run.func1()
      /usr/local/go/src/testing/testing.go:1629 +0x47

Goroutine 8 (running) created at:
  github.com/gin-contrib/timeout.New.func1()
     [...]/timeout/timeout.go:49 +0x4d5
  github.com/gin-gonic/gin.(*Context).Next()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:173 +0xba3
  github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/gin.go:616 +0x785
  github.com/gin-gonic/gin.(*Engine).ServeHTTP()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/gin.go:572 +0x44b
  github.com/gin-contrib/timeout.TestTimeout()
     [...]/timeout/timeout_test.go:25 +0x2d4
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1576 +0x216
  testing.(*T).Run.func1()
      /usr/local/go/src/testing/testing.go:1629 +0x47

Goroutine 7 (running) created at:
  testing.(*T).Run()
      /usr/local/go/src/testing/testing.go:1629 +0x805
  testing.runTests.func1()
      /usr/local/go/src/testing/testing.go:2036 +0x8d
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1576 +0x216
  testing.runTests()
      /usr/local/go/src/testing/testing.go:2034 +0x87c
  testing.(*M).Run()
      /usr/local/go/src/testing/testing.go:1906 +0xb44
  main.main()
      _testmain.go:59 +0x2e9
==================
--- FAIL: TestTimeout (0.00s)
    testing.go:1446: race detected during execution of test
[GIN-debug] [WARNING] Running in "debug" mode. Switch to "release" mode in production.
 - using env:   export GIN_MODE=release
 - using code:  gin.SetMode(gin.ReleaseMode)

[GIN-debug] GET    /                         --> github.com/gin-contrib/timeout.emptySuccessResponse (1 handlers)
[GIN-debug] [WARNING] Running in "debug" mode. Switch to "release" mode in production.
 - using env:   export GIN_MODE=release
 - using code:  gin.SetMode(gin.ReleaseMode)

[GIN-debug] GET    /                         --> github.com/gin-contrib/timeout.New.func1 (1 handlers)
[GIN-debug] [WARNING] Running in "debug" mode. Switch to "release" mode in production.
 - using env:   export GIN_MODE=release
 - using code:  gin.SetMode(gin.ReleaseMode)

[GIN-debug] GET    /                         --> github.com/gin-contrib/timeout.New.func1 (1 handlers)
==================
WARNING: DATA RACE
Read at 0x00c000175328 by goroutine 13:
  github.com/gin-gonic/gin.(*Context).Status()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:839 +0x4e
  github.com/gin-gonic/gin.(*Context).Render()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:902 +0x3d
  github.com/gin-gonic/gin.(*Context).String()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:991 +0x6b
  github.com/gin-contrib/timeout.emptySuccessResponse()
     [...]/timeout/timeout_test.go:16 +0x2f
  github.com/gin-contrib/timeout.New.func1.1()
     [...]/timeout/timeout.go:55 +0xb7

Previous write at 0x00c000175328 by goroutine 12:
  github.com/gin-contrib/timeout.New.func1()
     [...]/timeout/timeout.go:88 +0x7c6
  github.com/gin-gonic/gin.(*Context).Next()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:173 +0xba3
  github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/gin.go:616 +0x785
  github.com/gin-gonic/gin.(*Engine).ServeHTTP()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/gin.go:572 +0x44b
  github.com/gin-contrib/timeout.TestCustomResponse()
     [...]/timeout/timeout_test.go:57 +0x304
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1576 +0x216
  testing.(*T).Run.func1()
      /usr/local/go/src/testing/testing.go:1629 +0x47

Goroutine 13 (running) created at:
  github.com/gin-contrib/timeout.New.func1()
     [...]/timeout/timeout.go:49 +0x4d5
  github.com/gin-gonic/gin.(*Context).Next()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:173 +0xba3
  github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/gin.go:616 +0x785
  github.com/gin-gonic/gin.(*Engine).ServeHTTP()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/gin.go:572 +0x44b
  github.com/gin-contrib/timeout.TestCustomResponse()
     [...]/timeout/timeout_test.go:57 +0x304
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1576 +0x216
  testing.(*T).Run.func1()
      /usr/local/go/src/testing/testing.go:1629 +0x47

Goroutine 12 (finished) created at:
  testing.(*T).Run()
      /usr/local/go/src/testing/testing.go:1629 +0x805
  testing.runTests.func1()
      /usr/local/go/src/testing/testing.go:2036 +0x8d
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1576 +0x216
  testing.runTests()
      /usr/local/go/src/testing/testing.go:2034 +0x87c
  testing.(*M).Run()
      /usr/local/go/src/testing/testing.go:1906 +0xb44
  main.main()
      _testmain.go:59 +0x2e9
==================
==================
WARNING: DATA RACE
Read at 0x00c0003c2a28 by goroutine 13:
  github.com/gin-contrib/timeout.(*Writer).WriteHeader()
     [...]/timeout/writer.go:43 +0x74
  github.com/gin-gonic/gin.(*Context).Status()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:839 +0x66
  github.com/gin-gonic/gin.(*Context).Render()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:902 +0x3d
  github.com/gin-gonic/gin.(*Context).String()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:991 +0x6b
  github.com/gin-contrib/timeout.emptySuccessResponse()
     [...]/timeout/timeout_test.go:16 +0x2f
  github.com/gin-contrib/timeout.New.func1.1()
     [...]/timeout/timeout.go:55 +0xb7

Previous write at 0x00c0003c2a28 by goroutine 12:
  github.com/gin-contrib/timeout.New.func1()
     [...]/timeout/timeout.go:84 +0x6cd
  github.com/gin-gonic/gin.(*Context).Next()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:173 +0xba3
  github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/gin.go:616 +0x785
  github.com/gin-gonic/gin.(*Engine).ServeHTTP()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/gin.go:572 +0x44b
  github.com/gin-contrib/timeout.TestCustomResponse()
     [...]/timeout/timeout_test.go:57 +0x304
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1576 +0x216
  testing.(*T).Run.func1()
      /usr/local/go/src/testing/testing.go:1629 +0x47

Goroutine 13 (running) created at:
  github.com/gin-contrib/timeout.New.func1()
     [...]/timeout/timeout.go:49 +0x4d5
  github.com/gin-gonic/gin.(*Context).Next()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/context.go:173 +0xba3
  github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/gin.go:616 +0x785
  github.com/gin-gonic/gin.(*Engine).ServeHTTP()
     [...]/go/pkg/mod/github.com/gin-gonic/gin@v1.8.1/gin.go:572 +0x44b
  github.com/gin-contrib/timeout.TestCustomResponse()
     [...]/timeout/timeout_test.go:57 +0x304
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1576 +0x216
  testing.(*T).Run.func1()
      /usr/local/go/src/testing/testing.go:1629 +0x47

Goroutine 12 (finished) created at:
  testing.(*T).Run()
      /usr/local/go/src/testing/testing.go:1629 +0x805
  testing.runTests.func1()
      /usr/local/go/src/testing/testing.go:2036 +0x8d
  testing.tRunner()
      /usr/local/go/src/testing/testing.go:1576 +0x216
  testing.runTests()
      /usr/local/go/src/testing/testing.go:2034 +0x87c
  testing.(*M).Run()
      /usr/local/go/src/testing/testing.go:1906 +0xb44
  main.main()
      _testmain.go:59 +0x2e9
==================
--- FAIL: TestSuccess (0.00s)
    testing.go:1446: race detected during execution of test
appleboy commented 7 months ago

I will take a look.