Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

write: broken pipe in func (r Data) Render #1089

Closed
deepch opened this issue Aug 29, 2017 · 11 comments
Closed

write: broken pipe in func (r Data) Render #1089

deepch opened this issue Aug 29, 2017 · 11 comments

Comments

@deepch
Copy link

deepch commented Aug 29, 2017

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
Copy link
Member

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
Copy link
Author

deepch commented Sep 7, 2017

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
Copy link
Author

deepch commented Sep 14, 2017

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
Copy link
Author

deepch commented Sep 14, 2017

*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

963acc4#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

@deepch deepch changed the title disable log trash write: broken pipe in func (r Data) Render Sep 14, 2017
@justinfx
Copy link
Contributor

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
Copy link

wwjue commented Jan 25, 2018

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

@justinfx
Copy link
Contributor

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

@LeftyBC
Copy link

LeftyBC commented Feb 6, 2018

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
Copy link
Contributor

justinfx commented Feb 7, 2018

@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
Copy link

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

@thinkerou
Copy link
Member

#1259 already merged, thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

6 participants