Description
What version of Go are you using (go version)?
$ go version go version go1.17.2 darwin/amd64
Does this issue reproduce with the latest release?
What operating system and processor architecture are you using (go env)?
go env Output
$ go env GO111MODULE="on" GOARCH="amd64" GOBIN="" GOCACHE="/Users/samutamm/Library/Caches/go-build" GOENV="/Users/samutamm/Library/Application Support/go/env" GOEXE="" GOEXPERIMENT="" GOFLAGS="" GOHOSTARCH="amd64" GOHOSTOS="darwin" GOINSECURE="" GOMODCACHE="/Users/samutamm/go/pkg/mod" GONOPROXY="on" GONOSUMDB="" GOOS="darwin" GOPATH="/Users/samutamm/go" GOPRIVATE="" GOPROXY="https://proxy.golang.org,direct" GOROOT="/usr/local/Cellar/go/1.17.2/libexec" GOSUMDB="sum.golang.org" GOTMPDIR="" GOTOOLDIR="/usr/local/Cellar/go/1.17.2/libexec/pkg/tool/darwin_amd64" GOVCS="" GOVERSION="go1.17.2" GCCGO="gccgo" AR="ar" CC="clang" CXX="clang++" CGO_ENABLED="1" GOMOD="/dev/null" CGO_CFLAGS="-g -O2" CGO_CPPFLAGS="" CGO_CXXFLAGS="-g -O2" CGO_FFLAGS="-g -O2" CGO_LDFLAGS="-g -O2" PKG_CONFIG="pkg-config" GOROOT/bin/go version: go version go1.17.2 darwin/amd64 GOROOT/bin/go tool compile -V: compile version go1.17.2 uname -v: Darwin Kernel Version 21.1.0: Wed Oct 13 17:33:23 PDT 2021; root:xnu-8019.41.5~1/RELEASE_X86_64 ProductName: macOS ProductVersion: 12.0.1 BuildVersion: 21A559 lldb --version: lldb-1300.0.32.4 Swift version 5.5.1-dev
What did you do?
I have very simple Reader that has a channel and Read function:
type MyReader struct {
ch chan bool
}
func (mr *MyReader) Read(p []byte) (n int, err error) {
fmt.Printf("my reader read\n")
close(mr.ch)
return 0, io.EOF
}The Read function returns 0, io.EOF to indicate that the reader has reached to the end of the file and should not be called again.
I use MyReader as HTTP request body, like in the complete example below, and I send 1000000 such a requests to a simple web server.
package main
import (
"fmt"
"io"
"net/http"
"sync"
"time"
"math/rand"
)
type MyReader struct {
ch chan bool
}
func (mr *MyReader) Read(p []byte) (n int, err error) {
fmt.Printf("my reader read\n")
close(mr.ch)
return 0, io.EOF // tell callers that reached EOF
}
func NewMyReader() io.Reader {
return &MyReader{ch: make(chan bool)}
}
func checkStart(w http.ResponseWriter, r *http.Request) {
}
func getServer(addr string) *http.Server {
mux := http.NewServeMux()
mux.HandleFunc("/", checkStart)
server := &http.Server{
Addr: addr,
Handler: mux,
}
go func() {
err := server.ListenAndServe()
if err != nil {
panic(err)
}
}()
started := false
for i := 0; i < 10; i++ {
req, err := http.NewRequest(http.MethodGet, "http://"+addr, nil)
if err != nil {
panic(err)
}
_, err = http.DefaultClient.Do(req)
if err == nil {
started = true
break
}
time.Sleep(50 * time.Millisecond)
}
if !started {
fmt.Printf("server not started\n")
}
return server
}
func main() {
server := getServer("127.0.0.1:8080")
defer server.Close()
wg := sync.WaitGroup{}
for i := 0; i < 1000000; i++ {
wg.Add(1)
time.Sleep(time.Duration(10 + rand.Intn(100)) * time.Microsecond) // sleep 10 - 110 ms between queries
go func(i int) {
defer wg.Done()
req, err := http.NewRequest(http.MethodGet, "http://127.0.0.1:8080", NewMyReader())
if err != nil {
return
}
fmt.Printf("%v\n", i)
resp, err := http.DefaultClient.Do(req)
if err != nil {
return
}
resp.Body.Close()
}(i)
}
wg.Wait()
}I execute the code above on command line
go run main.goand I get an panic: close of closed channel quite consistently. The error is not thrown every time but about one out of three runs.
I noticed that if the sleep between the request is fixed to some value, the error is thrown much less frequently. But with random sleep interval between 10-110 microseconds, the error is easier to reproduce.
What did you expect to see?
I expect that the Read function would not be called after the MyReader has returned (0, io.EOF). I noticed that some of the Reader implementations (like this one) use sync.Mutex and boolean flags to return early from Read call when EOF had been seen first time.
However, it seems like a bug that most of the time the first io.EOF is enough to liberate the Reader from reading, but sometimes there are still Read calls after (0, io.EOF) has been returned.
What did you see instead?
After running the program few times, I see following stack trace:
...
my reader read
509670
my reader read
my reader read
panic: close of closed channel
goroutine 1460930 [running]:
main.(*MyReader).Read(0xc0005ea268, {0x1, 0xc0008adab8, 0x12010cf})
/Users/samutamm/sandbox/performance_test/main.go:19 +0x52
net/http.(*readTrackingBody).Read(0x0, {0xc000862000, 0xc0008adb00, 0x104a512})
/usr/local/Cellar/go/1.17.2/libexec/src/net/http/transport.go:634 +0x2a
io.(*multiReader).Read(0xc0005f4120, {0xc000862000, 0x8000, 0x8000})
/usr/local/Cellar/go/1.17.2/libexec/src/io/multi.go:26 +0x9b
io.copyBuffer({0x9a9c008, 0xc0002cc270}, {0x12ded00, 0xc0005f4120}, {0x0, 0x0, 0x0})
/usr/local/Cellar/go/1.17.2/libexec/src/io/io.go:423 +0x1b2
io.Copy(...)
/usr/local/Cellar/go/1.17.2/libexec/src/io/io.go:382
net/http.(*transferWriter).doBodyCopy(0xc0000baaa0, {0x9a9c008, 0xc0002cc270}, {0x12ded00, 0xc0005f4120})
/usr/local/Cellar/go/1.17.2/libexec/src/net/http/transfer.go:410 +0x4d
net/http.(*transferWriter).writeBody(0xc0000baaa0, {0x12deb60, 0xc0001ca200})
/usr/local/Cellar/go/1.17.2/libexec/src/net/http/transfer.go:357 +0x225
net/http.(*Request).write(0xc0004c1100, {0x12deb60, 0xc0001ca200}, 0x0, 0xc000717200, 0x0)
/usr/local/Cellar/go/1.17.2/libexec/src/net/http/request.go:698 +0xb4e
net/http.(*persistConn).writeLoop(0xc0005c85a0)
/usr/local/Cellar/go/1.17.2/libexec/src/net/http/transport.go:2389 +0x189
created by net/http.(*Transport).dialConn
/usr/local/Cellar/go/1.17.2/libexec/src/net/http/transport.go:1748 +0x1e65
exit status 2