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

net/http: background read can lose a byte #18535

Closed
bmizerany opened this issue Jan 6, 2017 · 9 comments
Closed

net/http: background read can lose a byte #18535

bmizerany opened this issue Jan 6, 2017 · 9 comments
Milestone

Comments

@bmizerany
Copy link
Contributor

bmizerany commented Jan 6, 2017

Please answer these questions before submitting your issue. Thanks!

What version of Go are you using (go version)?

go version devel +41908a5 Thu Dec 1 02:54:21 2016 +0000 darwin/amd64

What operating system and processor architecture are you using (go env)?

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/bmizerany"
GORACE=""
GOROOT="/usr/local/go"
GOTOOLDIR="/usr/local/go/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/dx/jcs03lw901vc05cjjqyjf8y00000gn/T/go-build129210763=/tmp/go-build -gno-record-gcc-switches -fno-common"
CXX="clang++"
CGO_ENABLED="1"
PKG_CONFIG="pkg-config"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"

What did you do?

I ran this benchmark:

func BenchmarkBug(b *testing.B) {
	hts := httptest.NewServer(http.HandlerFunc(http.NotFound))
	defer hts.Close()

	cn, err := net.Dial("tcp", hts.Listener.Addr().String())
	if err != nil {
		panic(err)
	}
	defer func() {
		println("CLOSING")
		cn.Close() // <-- getting called too early?
	}()

	go io.Copy(ioutil.Discard, cn) // discard responses

	reqBytes := []byte("GET / HTTP/1.1\r\nHost: e.com\r\n\r\n")

	b.RunParallel(func(pb *testing.PB) {
		for pb.Next() {
			_, err := cn.Write(reqBytes)
			if err != nil {
				panic(err)
			}
		}
		println("DONE")
	})
}

What did you expect to see?

PASS

What did you see instead?

$ go test -run=none -bench=BenchmarkBug
DONE
DONE
DONE
DONE
CLOSING
BenchmarkBug-4   	DONE
DONE
DONE
DONE
CLOSING
panic: write tcp 127.0.0.1:55752->127.0.0.1:55751: write: broken pipe

goroutine 66 [running]:
backplane2/server.BenchmarkBug.func2(0xc42000c2e0)
	/Users/bmizerany/src/bug/bench_test.go:261 +0xb7 // <--- The panic
testing.(*B).RunParallel.func1(0xc42011e0f0, 0xc42011e0e0, 0xc42011e0d8, 0xc4200b0000, 0xc420010810)
	/usr/local/go/src/testing/benchmark.go:606 +0xc2
created by testing.(*B).RunParallel
	/usr/local/go/src/testing/benchmark.go:607 +0x1af
FAIL	bug 2.385s
@bmizerany
Copy link
Contributor Author

I just tried on tip go version devel +867dcb5 Fri Jan 6 01:58:00 2017 +0000 darwin/amd64 and got the same result.

@ianlancetaylor
Copy link
Contributor

It's not a problem in the testing package. The net/http Server is seeing a bad request and closing the connection. You have a bunch of different goroutines, running in parallel, writing to the same network connection. As the socket buffer fills up, nothing guarantees that those writes are atomic. When I run an strace, I see that eventually a short write occurs. The Go code calls write again with the remaining bytes, but in the meantime another thread does a write to the same socket. The HTTP server sees a mangled request, returns a "400 Bad Request" error, and closes the connection. The next write fails with a broken pipe, and your code panics.

I don't think there is anything we can fix here, so closing.

@bmizerany
Copy link
Contributor Author

bmizerany commented Jan 6, 2017 via email

@bmizerany
Copy link
Contributor Author

I've modified the code to not share a connection but rather each running goroutine gets their own. I'm still seeing the issue and have dug around in dtruss looking for clues but I don't see any malformed requests expect when I copy the responses to stderr I do see a 400 response after many valid responses. I may be doing something very silly again but I can't seem to find it. Any help is appreciated.

Update bench:

package server

import (
	"io"
	"io/ioutil"
	"net"
	"net/http"
	"net/http/httptest"
	"testing"
)

func BenchmarkBug(b *testing.B) {
	hts := httptest.NewServer(http.HandlerFunc(http.NotFound))
	defer hts.Close()

	reqBytes := []byte("GET / HTTP/1.1\r\nHost: e.com\r\n\r\n")

	b.RunParallel(func(pb *testing.PB) {
		cn, err := net.Dial("tcp", hts.Listener.Addr().String())
		if err != nil {
			panic(err)
		}
		defer cn.Close()

		go io.Copy(ioutil.Discard, cn)

		for pb.Next() {
			_, err := cn.Write(reqBytes)
			if err != nil {
				panic(err)
			}
		}
	})
}

@ianlancetaylor
Copy link
Contributor

CC @bradfitz

This is a real bug. The net/http server is dropping an occasional byte.

If I add these lines to connReader.startBackgroundRead

	if cr.hasByte {
		panic("startBackgroundRead when already have byte")
	}

your program triggers the panic. Doing a background read when we already have a byte from an earlier background read is causing one of the bytes to be lost.

I don't understand exactly what triggers the condition. It has something to do with a full TCP buffer containing many GET requests and ending in the middle of a line.

I hope that Brad can take it from here.

@ianlancetaylor ianlancetaylor reopened this Jan 7, 2017
@ianlancetaylor ianlancetaylor changed the title RunParallel appears to exit earlier than documented net/http: background read can lose a byte Jan 7, 2017
@ianlancetaylor ianlancetaylor added this to the Go1.8 milestone Jan 7, 2017
@bradfitz
Copy link
Contributor

bradfitz commented Jan 7, 2017

I guess I now have weekend plans.

@ianlancetaylor
Copy link
Contributor

Your weekend is open again: https://golang.org/cl/34920.

@gopherbot
Copy link

CL https://golang.org/cl/34920 mentions this issue.

@bmizerany
Copy link
Contributor Author

Killer. Thank you @ianlancetaylor.

@golang golang locked and limited conversation to collaborators Jan 7, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

4 participants