write: broken pipe in func (r Data) Render

[deepch]

i test gopkg.in/gin-gonic/gin.v1 and github.com/gin-gonic/gin

i disable log

gin.SetMode(gin.ReleaseMode)
public := gin.New()

and my log

http: TLS handshake error from 2.61.29.56:3467: tls: oversized record received with length 23801
http: TLS handshake error from 2.61.29.56:3468: tls: oversized record received with length 23801
http: TLS handshake error from 2.61.29.56:3474: tls: oversized record received with length 21536
http: TLS handshake error from 2.61.29.56:3475: EOF
http: TLS handshake error from 80.93.120.44:57317: EOF
http: TLS handshake error from 80.93.120.44:56541: EOF
http: TLS handshake error from 80.93.120.44:56021: tls: oversized record received with length 19029
http: TLS handshake error from 80.93.120.44:58616: tls: oversized record received with length 19030
http: TLS handshake error from 80.93.120.44:60805: tls: oversized record received with length 19030
http: TLS handshake error from 80.93.120.44:55553: tls: oversized record received with length 19030
http: TLS handshake error from 80.93.120.44:51292: tls: oversized record received with length 19031
http: TLS handshake error from 80.93.120.44:54123: tls: oversized record received with length 19030
http: TLS handshake error from 80.93.120.44:50073: tls: oversized record received with length 19035
http: TLS handshake error from 80.93.120.44:59981: tls: oversized record received with length 19035
http: TLS handshake error from 2.61.29.56:3512: tls: first record does not look like a TLS handshake
http: TLS handshake error from 2.61.29.56:3513: tls: first record does not look like a TLS handshake
http: TLS handshake error from 2.61.29.56:3517: tls: first record does not look like a TLS handshake
http: TLS handshake error from 2.61.29.56:3524: tls: oversized record received with length 21536
http: TLS handshake error from 2.61.29.56:3526: tls: oversized record received with length 21536
http: TLS handshake error from 2.61.29.56:3519: tls: first record does not look like a TLS handshake
http: panic serving 171.33.254.131:56942: write tcp 171.25.232.16:8080->171.33.254.131:56942: write: broken pipe
goroutine 1668770 [running]:
net/http.(*conn).serve.func1(0xc45aebc500)
    /usr/local/go/src/net/http/server.go:1697 +0xd0
panic(0xaf5480, 0xc468e93bd0)
    /usr/local/go/src/runtime/panic.go:491 +0x283
gopkg.in/gin-gonic/gin%2ev1.(*Context).Render(0xc45b260a50, 0xc8, 0x1112f40, 0xc45523c870)
    /home/deepweb/ivs/src/gopkg.in/gin-gonic/gin.v1/context.go:597 +0x160
gopkg.in/gin-gonic/gin%2ev1.(*Context).Data(0xc45b260a50, 0xc8, 0xbcb377, 0xa, 0xc445268000, 0x598c4, 0x7734a)
    /home/deepweb/ivs/src/gopkg.in/gin-gonic/gin.v1/context.go:650 +0xb8
main.AppHlsStreamTS(0xc45b260a50)
    /home/deepweb/ivs/ModuleServerAPI.go:717 +0x235
gopkg.in/gin-gonic/gin%2ev1.(*Context).Next(0xc45b260a50)
    /home/deepweb/ivs/src/gopkg.in/gin-gonic/gin.v1/context.go:104 +0x43
gopkg.in/gin-gonic/gin%2ev1.(*Engine).handleHTTPRequest(0xc421244000, 0xc45b260a50)
    /home/deepweb/ivs/src/gopkg.in/gin-gonic/gin.v1/gin.go:332 +0x5b4
gopkg.in/gin-gonic/gin%2ev1.(*Engine).ServeHTTP(0xc421244000, 0x1114700, 0xc47763c000, 0xc5944b0600)
    /home/deepweb/ivs/src/gopkg.in/gin-gonic/gin.v1/gin.go:296 +0x16b
net/http.serverHandler.ServeHTTP(0xc4212f21a0, 0x1114700, 0xc47763c000, 0xc5944b0600)
    /usr/local/go/src/net/http/server.go:2619 +0xb4
net/http.(*conn).serve(0xc45aebc500, 0x1115500, 0xc421dc7e00)
    /usr/local/go/src/net/http/server.go:1801 +0x71d
created by net/http.(*Server).Serve
    /usr/local/go/src/net/http/server.go:2720 +0x288
http: TLS handshake error from 2.61.29.56:3529: EOF
http: TLS handshake error from 176.213.126.183:1602: EOF

How can I turn off these errors. ? write: broken pipe - The client interrupted the download of the file and I do not see this as an error. http: TLS handshake error - I, too, would not want to see this.

[thinkerou]

Hi @deepch I don't reproduce it, I use the master branch and the version of golang is 1.9. Maybe you should post the whole codes, thanks.

[deepch]

im use golang 1.9 r my code is very standard. load server 100+- qps and download file

gin.SetMode(gin.ReleaseMode)

public := gin.New()

err := public.RunTLS(":"+IntToString(value), ConfigServer.GetAPIHTTPSCertFile(), ConfigServer.GetAPIHTTPSKeyFile())

....

http: panic serving - I think it happens when the client saves the file and interrupts the download or tears up the connection with the client. (I've just removed this (panic) message from you in the code. )

http: TLS handshake error from - this is a bug on git golang there you need to replace logger

[deepch]

c.Data(200, "video/MP2T", *wdata)

http: panic serving 85.140.4.7:29982: write tcp 171.5.22.11:11111->85.140.4.7:29982: write: broken pipe

goroutine 122782 [running]:
net/http.(*conn).serve.func1(0xc4432ac820)
    /usr/local/go/src/net/http/server.go:1697 +0xd0
panic(0xaf6d40, 0xc45d59d360)
    /usr/local/go/src/runtime/panic.go:491 +0x283
github.com/gin-gonic/gin.(*Context).Render(0xc4b697ea50, 0xc8, 0x1115fe0, 0xc4ee4c4e70)
    /home/deepweb/ivs/src/github.com/gin-gonic/gin/context.go:626 +0x160
github.com/gin-gonic/gin.(*Context).Data(0xc4b697ea50, 0xc8, 0xbcce39, 0xa, 0xc4e91d0000, 0x3e9b0, 0x7734a)
    /home/deepweb/ivs/src/github.com/gin-gonic/gin/context.go:686 +0xb8
main.AppHlsStreamTS(0xc4b697ea50)
    /home/deepweb/ivs/src/github.com/deepch/ipeye-cloud/ModuleTest.go:737 +0x235
github.com/gin-gonic/gin.(*Context).Next(0xc4b697ea50)
    /home/deepweb/ivs/src/github.com/gin-gonic/gin/context.go:110 +0x43
github.com/gin-gonic/gin.(*Engine).handleHTTPRequest(0xc4203e8360, 0xc4b697ea50)
    /home/deepweb/ivs/src/github.com/gin-gonic/gin/gin.go:344 +0x5c5
github.com/gin-gonic/gin.(*Engine).ServeHTTP(0xc4203e8360, 0x11177e0, 0xc626256000, 0xc5c6302100)
    /home/deepweb/ivs/src/github.com/gin-gonic/gin/gin.go:311 +0x16b
net/http.serverHandler.ServeHTTP(0xc420bb01a0, 0x11177e0, 0xc626256000, 0xc5c6302100)
    /usr/local/go/src/net/http/server.go:2619 +0xb4
net/http.(*conn).serve(0xc4432ac820, 0x11185e0, 0xc68117f400)
    /usr/local/go/src/net/http/server.go:1801 +0x71d
created by net/http.(*Server).Serve
    /usr/local/go/src/net/http/server.go:2720 +0x288

[deepch]

*wdata = 10MB data buffer if client cancel download or disconnect

write: broken pipe

context.go:626

it no panic if regular please delete panic broken pipe == client close socket

add test c.Data(200, "video/MP2T", *wdata) closed connection or interrupt

https://github.com/gin-gonic/gin/commit/963acc4b0ce297782405d4aefd6fe173ff657b1f#diff-aece76ea64cacf005bef81b966af51d3

old no problem

func (r Data) Render(w http.ResponseWriter) error {
    if len(r.ContentType) > 0 {
        w.Header()["Content-Type"] = []string{r.ContentType}
    }
    w.Write(r.Data)
    return nil
}

new

// Render (Data) writes data with custom ContentType
func (r Data) Render(w http.ResponseWriter) (err error) {
    r.WriteContentType(w)
    _, err = w.Write(r.Data)
    return
}

if client close connection it not panic

[justinfx]

I wanted to follow up on this ticket, because it touches on something I have been encountering and I wanted clarification.

I am seeing a Recovery panic dump like this when the client breaks there connection and the the 'broken pipe' results in Gin wanting to set a 500 status code. But it can't because the request had already started, so we see an error saying the status was trying to be changed after it had already been written.

Is it expected that we should be seeing this huge trace dump in this case? Should the recovery handler try and check for a broken pipe before trying to set a 500 status?

See: https://github.com/gin-gonic/gin/blob/master/recovery.go#L43

[wwjue]

I don't see why borken pipe need to set 500 status. The response is not gonna received by client anyway.

[justinfx]

@wwjue, exactly. But its indiscriminately setting that status for any panic recovery. It shouldn't be appropriate for broken pipes though.

[LeftyBC]

I see this a lot when running timed load tests with wrk (https://github.com/wg/wrk) - Once the load test hits the time limit, wrk closes any inflight requests and I get a big pile of panic recovery stack traces complaining about closed sockets.

In my case, a closed socket is not catastrophic and shouldn't trigger a panic - can we get a configurable perhaps that allows us to downgrade this from a panic?

For example, I'm doing a 1 minute load test, 500 open connections at a time, on a gin microservice using this commandline:

wrk --connections 500 --duration 1m --threads 2 --latency --timeout 30s http://<myservice>:/v0/meta/health

[justinfx]

@LeftyBC, I also see this all the time when I use siege to do load tests. But my production case for seeing this was another teams web application that would start and cancel http requests to my API depending on the user interaction. I really don't need to see a huge panic for this either. A configuration option would be great!

[drsect0r]

Friendly bump as we're also being affected by this issue.

[thinkerou]

1259 already merged, thanks!