gin-contrib / timeout Goto Github PK
View Code? Open in Web Editor NEWTimeout middleware for Gin
License: MIT License
timeout's People
Contributors
![dependabot[bot] avatar](https://avatars.githubusercontent.com/in/29110?v=4 "dependabot[bot]")
Stargazers
Watchers
Forkers
hantmac lroccoon s654632396 ainiaa slimdy daheige vadimski niuyueyang1996 fixbanking cheng10 xtony77 polymathwhiz wangrenyi himanshusharma-angel larsgroeber gaozhenyusky kz-takeda syuparn guancecloud casxt kuanyulai rfyiamcool jangocheng sasakiyori jeff-lyu etiennemarais demouth zhouruisong smiley-yoyo trunin youzhixiaomutou elvinchan james-storey yxd326 n10tytimeout's Issues
Headers get overwritten if using multiple custom middlewares
If you use multiple custom middlewares then the timeout middleware will overwrite previous status codes.
package main
import (
"log"
"net/http"
"time"
"github.com/gin-contrib/timeout"
"github.com/gin-gonic/gin"
)
func testResponse(c *gin.Context) {
c.String(http.StatusRequestTimeout, "timeout")
}
// custom middleware straight from example
func timeoutMiddleware() gin.HandlerFunc {
return timeout.New(
timeout.WithTimeout(500*time.Millisecond),
timeout.WithHandler(func(c *gin.Context) {
c.Next()
}),
timeout.WithResponse(testResponse),
)
}
// simple middleware to always throw a 401
func authMiddleware() gin.HandlerFunc {
return func(c *gin.Context) {
c.AbortWithStatus(401)
return
}
}
func main() {
r := gin.New()
// middleware
r.Use(gin.Logger())
r.Use(timeoutMiddleware()) // 1. timeout middleware
r.Use(authMiddleware()) // 2. auth middleware
r.Use(gin.Recovery()) // recommend to use this middleware to recover from any panics in the handlers.
r.GET("/", func(c *gin.Context) {
time.Sleep(1000 * time.Millisecond)
c.String(http.StatusOK, "Hello world!")
})
if err := r.Run(":8080"); err != nil {
log.Fatal(err)
}
}result:
HTTP/1.1 200 OK
gin logs:
[GIN-debug] [WARNING] Headers were already written. Wanted to override status code 200 with 401
[GIN] 2022/08/25 - 16:58:19 | 401 | 25.583µs | 127.0.0.1 | GET "/"
If you change the order of the middlewares then the timeout never applies correctly.
We swapped to https://github.com/vearne/gin-timeout and the issue doesn't occur there.
Combined http results
I have a very simple Gin server.
func Health(c *gin.Context) {
c.JSON(http.StatusOK, gin.H{
"status": "ok",
})
}
r := gin.Default()
r.GET("/", timeout.New(
timeout.WithTimeout(1000*time.Microsecond),
timeout.WithHandler(controllers.Health),
))
err := r.Run(":" + config.Port)However, if I click multiple times, sometimes I will get results like with previous call results and be combined together:
And sometimes not.
Any idea? Thanks
Middleware crashes when handler completed and timed out at the same time
When a handler passed to timeout.WithHandler completed and the middleware timed out at the same time, the context writes both response bodies or panics due to concurrent writes.
Reproduction
package main
import (
"log"
"net/http"
"time"
"github.com/gin-contrib/timeout"
"github.com/gin-gonic/gin"
)
func testResponse(c *gin.Context) {
c.String(http.StatusRequestTimeout, `{"error": "timeout error"}`)
}
func timeoutMiddleware() gin.HandlerFunc {
return timeout.New(
timeout.WithTimeout(1*time.Second),
timeout.WithHandler(func(c *gin.Context) {
c.Next()
}),
timeout.WithResponse(testResponse),
)
}
func main() {
r := gin.New()
r.Use(timeoutMiddleware())
r.GET("/slow", func(c *gin.Context) {
time.Sleep(999*time.Millisecond + 500*time.Microsecond) // wait almost same as timeout
c.String(http.StatusRequestTimeout, `{"error": "handler error"}`)
})
if err := r.Run(":8080"); err != nil {
log.Fatal(err)
}
}$ go run main.go Result
response bodies
Approximately 15% responses has duplicated response body.
# statistics of 100 responses of the server above
$ for i in {1..100}; do curl -s localhost:8080/slow --output - >> result.txt; echo >> result.txt; done
$ cat result.txt | sort | uniq -c
6 {"error": "handler error"}
8 {"error": "handler error"}{"error": "timeout error"}
80 {"error": "timeout error"}
6 {"error": "timeout error"}{"error": "handler error"}panic
Also, server sometimes crashes due to concurrent map writes.
Panic stacktraces (click to open)
fatal error: concurrent map writes
goroutine 9 [running]:
github.com/gin-gonic/gin/render.writeContentType({0x7f05a033b818?, 0xc000478100?}, {0xac9820, 0x1, 0x1})
/home/syuparn/go/pkg/mod/github.com/gin-gonic/[email protected]/render/render.go:39 +0x7f
github.com/gin-gonic/gin/render.WriteString({0x7f05a033b818?, 0xc000478100}, {0x7f4f0d, 0x1a}, {0x0, 0x0, 0x0})
/home/syuparn/go/pkg/mod/github.com/gin-gonic/[email protected]/render/text.go:34 +0x6f
github.com/gin-gonic/gin/render.String.Render(...)
/home/syuparn/go/pkg/mod/github.com/gin-gonic/[email protected]/render/text.go:24
github.com/gin-gonic/gin.(*Context).Render(0xc000478100, 0x198, {0x895858, 0xc0003ed950})
/home/syuparn/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:910 +0xf8
github.com/gin-gonic/gin.(*Context).String(...)
/home/syuparn/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:991
main.main.func1(0x0?)
/home/syuparn/middle/main.go:31 +0x77
github.com/gin-gonic/gin.(*Context).Next(...)
/home/syuparn/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:173
main.timeoutMiddleware.func1(0xc000478100)
/home/syuparn/middle/main.go:20 +0x2d
github.com/gin-contrib/timeout.New.func1.1()
/home/syuparn/go/pkg/mod/github.com/gin-contrib/[email protected]/timeout.go:55 +0x6d
created by github.com/gin-contrib/timeout.New.func1
/home/syuparn/go/pkg/mod/github.com/gin-contrib/[email protected]/timeout.go:49 +0x245
goroutine 1 [IO wait]:
internal/poll.runtime_pollWait(0x7f05a02f6f08, 0x72)
/usr/lib/go-1.19/src/runtime/netpoll.go:305 +0x89
internal/poll.(*pollDesc).wait(0xc000412180?, 0x6?, 0x0)
/usr/lib/go-1.19/src/internal/poll/fd_poll_runtime.go:84 +0x32
internal/poll.(*pollDesc).waitRead(...)
/usr/lib/go-1.19/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Accept(0xc000412180)
/usr/lib/go-1.19/src/internal/poll/fd_unix.go:614 +0x234
net.(*netFD).accept(0xc000412180)
/usr/lib/go-1.19/src/net/fd_unix.go:172 +0x35
net.(*TCPListener).accept(0xc000414150)
/usr/lib/go-1.19/src/net/tcpsock_posix.go:142 +0x28
net.(*TCPListener).Accept(0xc000414150)
/usr/lib/go-1.19/src/net/tcpsock.go:288 +0x3d
net/http.(*Server).Serve(0xc000470000, {0x895eb8, 0xc000414150})
/usr/lib/go-1.19/src/net/http/server.go:3070 +0x385
net/http.(*Server).ListenAndServe(0xc000470000)
/usr/lib/go-1.19/src/net/http/server.go:2999 +0x7d
net/http.ListenAndServe(...)
/usr/lib/go-1.19/src/net/http/server.go:3255
github.com/gin-gonic/gin.(*Engine).Run(0xc00044a680, {0xc00029ff50, 0x1, 0x1})
/home/syuparn/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:382 +0x20e
main.main()
/home/syuparn/middle/main.go:33 +0xc9
goroutine 7 [runnable]:
context.removeChild({0x896778?, 0xc0003d7e40?}, {0x8949f8, 0xc0003d7f00})
/usr/lib/go-1.19/src/context/context.go:321 +0x9f
context.(*cancelCtx).cancel(0xc0003d7f00, 0x1, {0x8937e0, 0xc000016250})
/usr/lib/go-1.19/src/context/context.go:421 +0x265
context.WithCancel.func1()
/usr/lib/go-1.19/src/context/context.go:238 +0x30
net/http.(*conn).serve(0xc0003eb860, {0x896820, 0xc000404de0})
/usr/lib/go-1.19/src/net/http/server.go:1993 +0x628
created by net/http.(*Server).Serve
/usr/lib/go-1.19/src/net/http/server.go:3102 +0x4db
goroutine 8 [IO wait]:
internal/poll.runtime_pollWait(0x7f05a02f6e18, 0x72)
/usr/lib/go-1.19/src/runtime/netpoll.go:305 +0x89
internal/poll.(*pollDesc).wait(0xc0003da380?, 0xc0003ed811?, 0x0)
/usr/lib/go-1.19/src/internal/poll/fd_poll_runtime.go:84 +0x32
internal/poll.(*pollDesc).waitRead(...)
/usr/lib/go-1.19/src/internal/poll/fd_poll_runtime.go:89
internal/poll.(*FD).Read(0xc0003da380, {0xc0003ed811, 0x1, 0x1})
/usr/lib/go-1.19/src/internal/poll/fd_unix.go:167 +0x25a
net.(*netFD).Read(0xc0003da380, {0xc0003ed811?, 0xc00040e2d8?, 0xc000066768?})
/usr/lib/go-1.19/src/net/fd_posix.go:55 +0x29
net.(*conn).Read(0xc000014b90, {0xc0003ed811?, 0xc0003ee3c0?, 0x0?})
/usr/lib/go-1.19/src/net/net.go:183 +0x45
net/http.(*connReader).backgroundRead(0xc0003ed800)
/usr/lib/go-1.19/src/net/http/server.go:678 +0x3f
created by net/http.(*connReader).startBackgroundRead
/usr/lib/go-1.19/src/net/http/server.go:674 +0xca
exit status 2
version
- github.com/gin-contrib/timeout v0.0.3
- github.com/gin-gonic/gin v1.8.1
- Go go1.19.1 linux/amd64
- running on WSL2/Windows11
HTTP Response Splitting vulnerability identified
Snyk has identified an issue with the github.com/gin-gonic/gin module, versions < 1.7.7
https://security.snyk.io/vuln/SNYK-GOLANG-GITHUBCOMGINGONICGIN-1041736
github.com/gin-contrib/[email protected] is depending on github.com/gin-gonic/[email protected] and is being flagged in my scans. Please update your dependency when you have time
Kind Regards,
Tom
Data race on c.Next() and c.Abort()
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/[email protected]/context.go:839 +0x4e
github.com/gin-gonic/gin.(*Context).Render()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:902 +0x3d
github.com/gin-gonic/gin.(*Context).String()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/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/[email protected]/context.go:173 +0xba3
github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:616 +0x785
github.com/gin-gonic/gin.(*Engine).ServeHTTP()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/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/[email protected]/context.go:173 +0xba3
github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:616 +0x785
github.com/gin-gonic/gin.(*Engine).ServeHTTP()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/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/[email protected]/context.go:839 +0x66
github.com/gin-gonic/gin.(*Context).Render()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:902 +0x3d
github.com/gin-gonic/gin.(*Context).String()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/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/[email protected]/context.go:173 +0xba3
github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:616 +0x785
github.com/gin-gonic/gin.(*Engine).ServeHTTP()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/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/[email protected]/context.go:173 +0xba3
github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:616 +0x785
github.com/gin-gonic/gin.(*Engine).ServeHTTP()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/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/[email protected]/context.go:839 +0x4e
github.com/gin-gonic/gin.(*Context).Render()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:902 +0x3d
github.com/gin-gonic/gin.(*Context).String()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/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/[email protected]/context.go:173 +0xba3
github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:616 +0x785
github.com/gin-gonic/gin.(*Engine).ServeHTTP()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/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/[email protected]/context.go:173 +0xba3
github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:616 +0x785
github.com/gin-gonic/gin.(*Engine).ServeHTTP()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/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/[email protected]/context.go:839 +0x66
github.com/gin-gonic/gin.(*Context).Render()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:902 +0x3d
github.com/gin-gonic/gin.(*Context).String()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/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/[email protected]/context.go:173 +0xba3
github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:616 +0x785
github.com/gin-gonic/gin.(*Engine).ServeHTTP()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/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/[email protected]/context.go:173 +0xba3
github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:616 +0x785
github.com/gin-gonic/gin.(*Engine).ServeHTTP()
[...]/go/pkg/mod/github.com/gin-gonic/[email protected]/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
when i download excel, timeout middleware lead to response to failed
- With issues:
- Use the search tool before opening a new issue.
- Please provide source code and commit sha if you found a bug.
- Review existing issues and provide feedback or react to them.
Description
I use gin and reverse_proxy to make a gateway, as well i use gin-contrib/timeout to Preventing Gateway timeouts.
but when i request to download .xls file, it show me the debug log: '[GIN-debug] [WARNING] Headers were already written. Wanted to override status code 404 with 200'
if i not use gin-contrib/timeout , it`s download excel ok
How to reproduce
I found this code tw.ResponseWriter.WriteHeader(tw.code) will debug log
package middleware
import (
"github.com/gin-gonic/gin"
)
select {
case p := <-panicChan:
tw.FreeBuffer()
c.Writer = w
panic(p)
case <-finish:
c.Next()
tw.mu.Lock()
defer tw.mu.Unlock()
dst := tw.ResponseWriter.Header()
for k, vv := range tw.Header() {
dst[k] = vv
}
tw.ResponseWriter.WriteHeader(tw.code)
if _, err := tw.ResponseWriter.Write(buffer.Bytes()); err != nil {
panic(err)
}
tw.FreeBuffer()
bufPool.Put(buffer)
case <-time.After(t.timeout):
c.Abort()
tw.mu.Lock()
defer tw.mu.Unlock()
tw.timeout = true
tw.FreeBuffer()
bufPool.Put(buffer)
c.Writer = w
t.response(c)
c.Writer = tw
}
And when i download excel file , it flushed, and use func WriteHeaderNow to make w.size = 0, it lead to my request failed with 404 statusCode
package gin
import (
"bufio"
"io"
"net"
"net/http"
)
const (
noWritten = -1
defaultStatus = http.StatusOK
)
func (w *responseWriter) WriteHeader(code int) {
if code > 0 && w.status != code {
if w.Written() {
debugPrint("[WARNING] Headers were already written. Wanted to override status code %d with %d", w.status, code)
}
w.status = code
}
}
func (w *responseWriter) Written() bool {
return w.size != noWritten
}
func (w *responseWriter) Flush() {
w.WriteHeaderNow()
w.ResponseWriter.(http.Flusher).Flush()
}
func (w *responseWriter) WriteHeaderNow() {
if !w.Written() {
w.size = 0
w.ResponseWriter.WriteHeader(w.status)
}
}
Expectations
i hope someone can teach me how to solve this problem, thx )
Environment
- go version: 1.19
- gin version (or commit ref): 1.8.1
- operating system: macOS 12.6 arm
The operation of "timeout" should be removed because it may lead to multiple handlers using the same gin.Context simultaneously, thus causing incorrect response results.
// New wraps a handler and aborts the process of the handler if the timeout is reached
func New(opts ...Option) gin.HandlerFunc {
t := &Timeout{
timeout: defaultTimeout,
handler: nil,
response: defaultResponse,
}
// Loop through each option
for _, opt := range opts {
if opt == nil {
panic("timeout Option not be nil")
}
// Call the option giving the instantiated
opt(t)
}
if t.timeout <= 0 {
return t.handler
}
bufPool = &BufferPool{}
return func(c *gin.Context) {
finish := make(chan struct{}, 1)
panicChan := make(chan interface{}, 1)
w := c.Writer
buffer := bufPool.Get()
tw := NewWriter(w, buffer)
c.Writer = tw
buffer.Reset()
go func() {
defer func() {
if p := recover(); p != nil {
panicChan <- p
}
}()
t.handler(c)
finish <- struct{}{}
}()
select {
case p := <-panicChan:
tw.FreeBuffer()
c.Writer = w
panic(p)
case <-finish:
c.Next()
tw.mu.Lock()
defer tw.mu.Unlock()
dst := tw.ResponseWriter.Header()
for k, vv := range tw.Header() {
dst[k] = vv
}
if _, err := tw.ResponseWriter.Write(buffer.Bytes()); err != nil {
panic(err)
}
tw.FreeBuffer()
bufPool.Put(buffer)
case <-time.After(t.timeout):
c.Abort()
tw.mu.Lock()
defer tw.mu.Unlock()
tw.timeout = true
tw.FreeBuffer()
bufPool.Put(buffer)
c.Writer = w
t.response(c)
c.Writer = tw
}
}
}case <-time.After(t.timeout): c.Abort()
If a timeout occurs and c.Abort() is called here, but the handler function has not completed execution (for example, waiting for database data to be read), it will still continue to execute. In such a case, when c.PureJSON() is called in the handler function, c may have already been used by subsequent requests.
so, i suggest remove timeout operation.
Doubts about lock/unlock operating range?
Line 98 in e89e167
Which block of logic is the lock/unlock operation here, is it the write to dst, or the entire block from 100 lines to 109 lines? For timeout.go#L114, which is the same for the lock and release locks here? If it is for data writing/reading, see if you use mu sync.Mutex here, can you use rw lock?
[Bug] panic: http: wrote more than the declared Content-Length
After timeout, the original goroutine still is running, and will cause panic finally.
The panic info is:
[GIN-debug] [WARNING] Headers were already written. Wanted to override status code 408 with 200
panic: http: wrote more than the declared Content-Length
Server core dump with `fatal error: concurrent map writes`
I test gin-timeout, and it's ok
https://github.com/vearne/gin-timeout/blob/master/timeout.go#L33
cp := *c //nolint: govet
c.Abort()
// sync.Pool
buffer := buffpool.GetBuff()
tw := &TimeoutWriter{body: buffer, ResponseWriter: cp.Writer, h: make(http.Header)}
tw.TimeoutOptions = defaultOptions
// ....
cp.Writer = tw
So, Is it caused by gin reusing the ctx object?
Incorrect timeout
The timeout time is 4S. After the first request timeout, the SQL does not finish executing. The timeout of the second request will be greater than 4S
panic occured while processing redirect request
redirect handler like that:
r.GET("/redirect", func(c *gin.Context) {
c.Redirect(302, "OK")
})panic when calling c.Render, because the call carries the parameter code=-1
// Redirect returns an HTTP redirect to the specific location.
func (c *Context) Redirect(code int, location string) {
c.Render(-1, render.Redirect{
Code: code,
Location: location,
Request: c.Request,
})
}Panic when calling WriteHeader because timeout middleware rewrites the writer
Line 41 in 7e229ec
Line 75 in 7e229ec
func checkWriteHeaderCode(code int) {
if code < 100 || code > 999 {
panic(fmt.Sprintf("invalid http status code: %d", code))
}
}insert stack info to error when recover from panic
timeout handler would better insert stack info to error when recover from panic.
HTTP Code 204 is not properly handled
Hello,
I reached to the point when I'm responding within the handler with the status code 204 (No content), but the timeout middleware changes the code to 200 (OK).
To reproduce, run the following test:
package middleware_test
import (
"log"
"net/http"
"net/http/httptest"
"net/http/httputil"
"testing"
"time"
"github.com/gin-contrib/timeout"
"github.com/gin-gonic/gin"
)
func Timeout(duration time.Duration) gin.HandlerFunc {
return timeout.New(
timeout.WithTimeout(duration),
timeout.WithHandler(func(c *gin.Context) { c.Next() }),
timeout.WithResponse(timeoutHandler()),
)
}
func timeoutHandler() gin.HandlerFunc {
gatewayTimeoutErr := struct {
Error string `json:"error"`
}{
Error: "Timed out.",
}
return func(c *gin.Context) {
log.Printf("request timed out: [method=%s,path=%s]",
c.Request.Method, c.Request.URL.Path)
c.JSON(http.StatusGatewayTimeout, gatewayTimeoutErr)
}
}
func Test2XXCode(t *testing.T) {
gin.SetMode(gin.ReleaseMode)
type testCase struct {
Name string
Method string
Path string
ExpStatusCode int
Handler gin.HandlerFunc
}
var (
testTimeOutDuration = 1 * time.Second
cases = []testCase{
{
Name: "Plain text (200)",
Method: http.MethodGet,
Path: "/me",
ExpStatusCode: http.StatusOK,
Handler: func(ctx *gin.Context) {
ctx.String(http.StatusOK, "I'm text!")
},
},
{
Name: "Plain text (201)",
Method: http.MethodGet,
Path: "/me",
ExpStatusCode: http.StatusCreated,
Handler: func(ctx *gin.Context) {
ctx.String(http.StatusCreated, "I'm created!")
},
},
{
Name: "Plain text (204)",
Method: http.MethodGet,
Path: "/me",
ExpStatusCode: http.StatusNoContent,
Handler: func(ctx *gin.Context) {
ctx.String(http.StatusNoContent, "")
},
},
{
Name: "JSON (200)",
Method: http.MethodGet,
Path: "/me",
ExpStatusCode: http.StatusOK,
Handler: func(ctx *gin.Context) {
ctx.JSON(http.StatusOK, gin.H{"field": "value"})
},
},
{
Name: "JSON (201)",
Method: http.MethodGet,
Path: "/me",
ExpStatusCode: http.StatusCreated,
Handler: func(ctx *gin.Context) {
ctx.JSON(http.StatusCreated, gin.H{"field": "value"})
},
},
{
Name: "JSON (204)",
Method: http.MethodGet,
Path: "/me",
ExpStatusCode: http.StatusNoContent,
Handler: func(ctx *gin.Context) {
ctx.JSON(http.StatusNoContent, nil)
},
},
{
Name: "No reply",
Method: http.MethodGet,
Path: "/me",
ExpStatusCode: http.StatusOK,
Handler: func(ctx *gin.Context) {},
},
}
initCase = func(c testCase) (*http.Request, *httptest.ResponseRecorder) {
return httptest.NewRequest(c.Method, c.Path, nil), httptest.NewRecorder()
}
)
for i := range cases {
t.Run(cases[i].Name, func(tt *testing.T) {
tt.Logf("Test case [%s]", cases[i].Name)
router := gin.Default()
router.Use(Timeout(testTimeOutDuration))
router.GET("/*root", cases[i].Handler)
req, resp := initCase(cases[i])
router.ServeHTTP(resp, req)
rawResponse, _ := httputil.DumpResponse(resp.Result(), true)
log.Printf("===============================================\n%s\n"+
"===============================================", string(rawResponse))
if resp.Code != cases[i].ExpStatusCode {
tt.Errorf("response is different from expected:\nexp: >>>%d<<<\ngot: >>>%d<<<",
cases[i].ExpStatusCode, resp.Code)
}
})
}
}Results I retrieved:
===============================================
--- FAIL: Test2XXCode (0.00s)
--- PASS: Test2XXCode/Plain_text_(200) (0.00s)
--- PASS: Test2XXCode/Plain_text_(201) (0.00s)
--- FAIL: Test2XXCode/Plain_text_(204) (0.00s)
--- PASS: Test2XXCode/JSON_(200) (0.00s)
--- PASS: Test2XXCode/JSON_(201) (0.00s)
--- FAIL: Test2XXCode/JSON_(204) (0.00s)
--- PASS: Test2XXCode/No_reply (0.00s)
FAIL
To confirm the issue, exclude the line router.Use(Timeout(testTimeOutDuration)) from the test and run it again, it would pass then.
Edit:
github.com/gin-contrib/timeout is the latest, from the master branch (commit: 53932ea)
data race
go test ./... -race
[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.emptySuccessResponse (1 handlers)
WARNING: DATA RACE
Read at 0x00c0001bd028 by goroutine 10:
github.com/gin-gonic/gin.(*Context).Status()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:839 +0x44
github.com/gin-gonic/gin.(*Context).Render()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:902 +0x38
github.com/gin-gonic/gin.(*Context).String()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:991 +0x64
github.com/gin-contrib/timeout.emptySuccessResponse()
/Users/jon/githubs/timeout/timeout_test.go:16 +0x30
github.com/gin-contrib/timeout.New.func1.1()
/Users/jon/githubs/timeout/timeout.go:55 +0x94
Previous write at 0x00c0001bd028 by goroutine 9:
github.com/gin-contrib/timeout.New.func1()
/Users/jon/githubs/timeout/timeout.go:88 +0x5fc
github.com/gin-gonic/gin.(*Context).Next()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:173 +0x864
github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:616 +0x570
github.com/gin-gonic/gin.(*Engine).ServeHTTP()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:572 +0x384
github.com/gin-contrib/timeout.TestTimeout()
/Users/jon/githubs/timeout/timeout_test.go:25 +0x254
testing.tRunner()
/usr/local/go/src/testing/testing.go:1446 +0x188
testing.(*T).Run.func1()
/usr/local/go/src/testing/testing.go:1493 +0x40
Goroutine 10 (running) created at:
github.com/gin-contrib/timeout.New.func1()
/Users/jon/githubs/timeout/timeout.go:49 +0x3e4
github.com/gin-gonic/gin.(*Context).Next()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:173 +0x864
github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:616 +0x570
github.com/gin-gonic/gin.(*Engine).ServeHTTP()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:572 +0x384
github.com/gin-contrib/timeout.TestTimeout()
/Users/jon/githubs/timeout/timeout_test.go:25 +0x254
testing.tRunner()
/usr/local/go/src/testing/testing.go:1446 +0x188
testing.(*T).Run.func1()
/usr/local/go/src/testing/testing.go:1493 +0x40
Goroutine 9 (finished) created at:
testing.(*T).Run()
/usr/local/go/src/testing/testing.go:1493 +0x55c
testing.runTests.func1()
/usr/local/go/src/testing/testing.go:1846 +0x90
testing.tRunner()
/usr/local/go/src/testing/testing.go:1446 +0x188
testing.runTests()
/usr/local/go/src/testing/testing.go:1844 +0x6c0
testing.(*M).Run()
/usr/local/go/src/testing/testing.go:1726 +0x870
main.main()
_testmain.go:59 +0x2fc
==================
WARNING: DATA RACE
Read at 0x00c0003e2028 by goroutine 10:
github.com/gin-contrib/timeout.(*Writer).WriteHeader()
/Users/jon/githubs/timeout/writer.go:43 +0x4c
github.com/gin-gonic/gin.(*Context).Status()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:839 +0x5c
github.com/gin-gonic/gin.(*Context).Render()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:902 +0x38
github.com/gin-gonic/gin.(*Context).String()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:991 +0x64
github.com/gin-contrib/timeout.emptySuccessResponse()
/Users/jon/githubs/timeout/timeout_test.go:16 +0x30
github.com/gin-contrib/timeout.New.func1.1()
/Users/jon/githubs/timeout/timeout.go:55 +0x94
Previous write at 0x00c0003e2028 by goroutine 9:
github.com/gin-contrib/timeout.New.func1()
/Users/jon/githubs/timeout/timeout.go:84 +0x53c
github.com/gin-gonic/gin.(*Context).Next()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:173 +0x864
github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:616 +0x570
github.com/gin-gonic/gin.(*Engine).ServeHTTP()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:572 +0x384
github.com/gin-contrib/timeout.TestTimeout()
/Users/jon/githubs/timeout/timeout_test.go:25 +0x254
testing.tRunner()
/usr/local/go/src/testing/testing.go:1446 +0x188
testing.(*T).Run.func1()
/usr/local/go/src/testing/testing.go:1493 +0x40
Goroutine 10 (running) created at:
github.com/gin-contrib/timeout.New.func1()
/Users/jon/githubs/timeout/timeout.go:49 +0x3e4
github.com/gin-gonic/gin.(*Context).Next()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/context.go:173 +0x864
github.com/gin-gonic/gin.(*Engine).handleHTTPRequest()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:616 +0x570
github.com/gin-gonic/gin.(*Engine).ServeHTTP()
/Users/jon/go/pkg/mod/github.com/gin-gonic/[email protected]/gin.go:572 +0x384
github.com/gin-contrib/timeout.TestTimeout()
/Users/jon/githubs/timeout/timeout_test.go:25 +0x254
testing.tRunner()
/usr/local/go/src/testing/testing.go:1446 +0x188
testing.(*T).Run.func1()
/usr/local/go/src/testing/testing.go:1493 +0x40
Goroutine 9 (finished) created at:
testing.(*T).Run()
/usr/local/go/src/testing/testing.go:1493 +0x55c
testing.runTests.func1()
/usr/local/go/src/testing/testing.go:1846 +0x90
testing.tRunner()
/usr/local/go/src/testing/testing.go:1446 +0x188
testing.runTests()
/usr/local/go/src/testing/testing.go:1844 +0x6c0
testing.(*M).Run()
/usr/local/go/src/testing/testing.go:1726 +0x870
main.main()
_testmain.go:59 +0x2fc
--- FAIL: TestWithoutTimeout (0.00s)
testing.go:1319: race detected during execution of test
fatal error: concurrent map writes
If set the handler time.Sleep same as the timeout, there is a chance to reproduce this error!
api.GET("/test", timeout.New(
timeout.WithTimeout(200*time.Microsecond),
timeout.WithHandler(func(c *gin.Context) {
time.Sleep(200*time.Microsecond)
c.JSON(http.StatusOK, gin.H{
"code": 200,
"data": "",
})
}),
timeout.WithResponse(func(c *gin.Context) {
c.JSON(http.StatusRequestTimeout, gin.H{
"code": "408",
"message": "test",
})
}),
))Here is gin panic code line:
https://github.com/gin-gonic/gin/blob/580e7da6eed01e2926de1240ec31f6473cd1a2af/render/render.go#L38
There is also a chance of combined http results:
{
"code": 200,
"data": ""
}{
"code": "408",
"message": "test"
}
I can't think of a solution at the moment, does anyone have any good ideas?
Question: How can i use this middleware to all handler?
I want use this middleware in global, such as:
eng := gin.Default()
eng.Use(
timeout.New(
// ... some options
)
)Then, i found the timeout.WithHandler must be given here. But this is a global middleware, there is no handler at all.
Please give me any suggestion, thank you very much.
使用后导致runtime.Caller或runtime.Callers获取不到panic的具体文件、行号等
不使用时能正常获取到panic的具体文件行号，使用了后，不管怎么调整runtime.Caller的skip参数都无法获取到了，runtime.Callers也获取不行，使用了后不管是哪个文件panic获取的runtime信息都会指示为timeout中间件panic了
README.md - Add WithResponse option wrong example
There is an issue on describing how to use "Add WithResponse option." in README.md file
r.GET("/", timeout.New( WithTimeout(100*time.Microsecond), WithHandler(emptySuccessResponse), WithResponse(testResponse), ))
should be:
r.GET("/", timeout.New( timeout.WithTimeout(100*time.Microsecond), timeout.WithHandler(emptySuccessResponse), timeout.WithResponse(testResponse), ))
Bug: the result will be incorrect when call gin.Context.Writer.Status() in our custom gin middleware used after this(#46)
consider this case:
func Timeout() gin.HandlerFunc {
return timeout.New(timeout.WithTimeout(time.Second*1),
timeout.WithHandler(func(ctx *gin.Context) {
ctx.Next()
}),
timeout.WithResponse(func(ctx *gin.Context) {
ctx.String(http.StatusRequestTimeout, "timeout")
}),
)
}
func Logger() gin.HandlerFunc {
return func(c *gin.Context) {
c.Next()
// access the status we are sending
status := c.Writer.Status() // Bug: in any middleware used after this middleware, the result will always be 200.
log.Println(status)
}
}
func main() {
r := gin.New()
r.Use(Timeout())
r.Use(Logger())
r.GET("/test", func(c *gin.Context) {
c.Status(http.StatusInternalServerError)
})
// Listen and serve on 0.0.0.0:8080
r.Run(":8080")
}Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.