panic recovered: http2: stream closed

[mkfsn]

After upgrading from v1.1.2 to v1.6.2, I sometimes see 500 which is caused by the following error:

2020/04/23 06:04:36 [Recovery] 2020/04/23 - 06:04:36 panic recovered:
http2: stream closed
/go/pkg/mod/github.com/gin-gonic/gin@v1.6.2/context.go:845 (0x90eca2)
/go/pkg/mod/github.com/gin-gonic/gin@v1.6.2/context.go:934 (0x9f8b39)

Looks like before Render didn't return the error from Write():

https://github.com/gin-gonic/gin/blob/v1.1.4/render/data.go#L18

but in the latest code it is returning the error:

https://github.com/gin-gonic/gin/blob/v1.6.2/render/data.go#L18

---

(update)

I created a repo to reproduce the problem: https://github.com/mkfsn/gin-http2-panic

$ go run main.go
[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    /                         --> main.main.func1 (2 handlers)
[GIN-debug] Listening and serving HTTPS on localhost:8334
Warning: Binary output can mess up your terminal. Use "--output -" to tell
Warning: curl to output it to your terminal anyway, or consider "--output
Warning: <FILE>" to save to a file.
2020/04/23 20:42:52 http2: panic serving 127.0.0.1:51239: http2: stream closed
goroutine 50 [running]:
net/http.(*http2serverConn).runHandler.func1(0xc000256010, 0xc0000e5f67, 0xc00011aa80)
    /usr/local/opt/go/libexec/src/net/http/h2_bundle.go:5706 +0x16b
panic(0x15924e0, 0xc0000209c0)
    /usr/local/opt/go/libexec/src/runtime/panic.go:679 +0x1b2
github.com/gin-gonic/gin.(*Context).Render(0xc0002a20e0, 0xc8, 0x171c5a0, 0xc000246810)
    /Users/mkfsn/Workspaces/go/pkg/mod/github.com/gin-gonic/gin@v1.6.2/context.go:845 +0x173
github.com/gin-gonic/gin.(*Context).Data(...)
    /Users/mkfsn/Workspaces/go/pkg/mod/github.com/gin-gonic/gin@v1.6.2/context.go:934
main.main.func1(0xc0002a20e0)
    /Users/mkfsn/Workspaces/go/src/github.com/mkfsn/gin-http2-panic/main.go:34 +0x98
github.com/gin-gonic/gin.(*Context).Next(0xc0002a20e0)
    /Users/mkfsn/Workspaces/go/pkg/mod/github.com/gin-gonic/gin@v1.6.2/context.go:156 +0x3b
github.com/gin-gonic/gin.LoggerWithConfig.func1(0xc0002a20e0)
    /Users/mkfsn/Workspaces/go/pkg/mod/github.com/gin-gonic/gin@v1.6.2/logger.go:241 +0xe1
github.com/gin-gonic/gin.(*Context).Next(0xc0002a20e0)
    /Users/mkfsn/Workspaces/go/pkg/mod/github.com/gin-gonic/gin@v1.6.2/context.go:156 +0x3b
github.com/gin-gonic/gin.(*Engine).handleHTTPRequest(0xc00018dcc0, 0xc0002a20e0)
    /Users/mkfsn/Workspaces/go/pkg/mod/github.com/gin-gonic/gin@v1.6.2/gin.go:409 +0x66d
github.com/gin-gonic/gin.(*Engine).ServeHTTP(0xc00018dcc0, 0x1720260, 0xc000256010, 0xc000388100)
    /Users/mkfsn/Workspaces/go/pkg/mod/github.com/gin-gonic/gin@v1.6.2/gin.go:367 +0x17f
net/http.serverHandler.ServeHTTP(0xc0002a2000, 0x1720260, 0xc000256010, 0xc000388100)
    /usr/local/opt/go/libexec/src/net/http/server.go:2802 +0xa4
net/http.initNPNRequest.ServeHTTP(0x1721e60, 0xc0002467e0, 0xc0002d6000, 0xc0002a2000, 0x1720260, 0xc000256010, 0xc000388100)
    /usr/local/opt/go/libexec/src/net/http/server.go:3365 +0x8d
net/http.(*http2serverConn).runHandler(0xc00011aa80, 0xc000256010, 0xc000388100, 0xc000258020)
    /usr/local/opt/go/libexec/src/net/http/h2_bundle.go:5713 +0x9f
created by net/http.(*http2serverConn).processHeaders
    /usr/local/opt/go/libexec/src/net/http/h2_bundle.go:5447 +0x4eb

[Tnze]

I have this problem too. Is this(the panic) expected behavior?

[d01phin]

I think this is happening when the client closes the connection before the server "renders" reply. But I guess gin could handle this situation better than just "panic".

[bazuker]

Same here

2020/07/06 19:49:39 [Recovery] 2020/07/06 - 19:49:39 panic recovered:
http2: stream closed
/go/pkg/mod/github.com/gin-gonic/gin@v1.6.3/render/json.go:59 (0x90d353)
/go/pkg/mod/github.com/gin-gonic/gin@v1.6.3/context.go:841 (0x915765)
/go/pkg/mod/github.com/gin-gonic/gin@v1.6.3/context.go:884 (0xdc3da6)
/go/src/project/x/host/server/api/v1/events/events.go:1231 (0xdc3d36)
/go/pkg/mod/github.com/gin-gonic/gin@v1.6.3/context.go:161 (0x911c1a)
/go/src/project/x/host/server/api/antispam/antispam.go:37 (0xd61b30)
/go/pkg/mod/github.com/gin-gonic/gin@v1.6.3/context.go:161 (0x911c1a)
/go/src/project/x/host/server/access.go:71 (0xe2591a)
/go/pkg/mod/github.com/gin-gonic/gin@v1.6.3/context.go:161 (0x911c1a)
/go/src/project/x/host/server/access.go:58 (0xe2cc9a)
/go/pkg/mod/github.com/gin-gonic/gin@v1.6.3/context.go:161 (0x911c1a)
/go/pkg/mod/github.com/gin-gonic/gin@v1.6.3/recovery.go:83 (0x924fef)
/go/pkg/mod/github.com/gin-gonic/gin@v1.6.3/context.go:161 (0x911c1a)
/go/pkg/mod/github.com/gin-gonic/gin@v1.6.3/logger.go:241 (0x924120)
/go/pkg/mod/github.com/gin-gonic/gin@v1.6.3/context.go:161 (0x911c1a)
/go/src/project/x/host/server/server.go:82 (0xe2d086)
/go/pkg/mod/github.com/gin-gonic/gin@v1.6.3/context.go:161 (0x911c1a)
/go/pkg/mod/github.com/gin-gonic/gin@v1.6.3/gin.go:409 (0x91b6c5)
/go/pkg/mod/github.com/gin-gonic/gin@v1.6.3/gin.go:367 (0x91addc)
/usr/local/go/src/net/http/server.go:2807 (0x6f6d52)
/usr/local/go/src/net/http/server.go:3381 (0x6f88dc)
/usr/local/go/src/net/http/h2_bundle.go:5720 (0x6cb22a)
/usr/local/go/src/runtime/asm_amd64.s:1373 (0x4650d0)

[john8329]

Yeah this problem still happens, it pollutes the logs and the bug reporter. Clients may close the connection unexpectedly, and the server should hand it properly imo.

[syncplify]

Any news on this? Log pollution should not be underestimated. It generates a "boy who cried wolf" effect, so when an actual panic happens, a situation that would indeed require attention, it will end up going unnoticed, buried into all the other "panics" that should not have been panics.

[deepch]

+1

[Echo365]

+1