net/http: fail to trigger io/read timeout

[lujiajing1126]

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

go version go1.9 linux/amd64

Does this issue reproduce with the latest release?

not sure

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

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/go"
GORACE=""
GOROOT="/usr/local/go"
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build938167298=/tmp/go-build -gno-record-gcc-switches"
CXX="g++"
CGO_ENABLED="1"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"

What did you do?

package main

import (
	"github.com/valyala/fasthttp"
	"time"
	"fmt"
	"log"
	"net/http"
	_ "net/http/pprof"
)

func main() {
	go func() {
		log.Println(http.ListenAndServe("localhost:6060", nil))
	}()
	timeoutInt := 35
	timeout := time.Second * time.Duration(timeoutInt)
	c := fasthttp.Client{ReadTimeout: timeout, WriteTimeout: timeout}
	req := fasthttp.AcquireRequest()
	req.SetRequestURI("http://127.0.0.1:2345/")
	req.Header.SetMethod("POST")
	resp := fasthttp.AcquireResponse()
	if err := c.Do(req, resp); err != nil {
		fmt.Printf("%v", err)
	}
	fasthttp.ReleaseRequest(req)
	fasthttp.ReleaseResponse(resp)
}

Just something like that, I sent an HTTP request to the remote server. But got stuck on the network request.

What did you expect to see?

if read timeout:

send request failed, read tcp4 192.168.16.5:34478->112.124.219.10:80: i/o timeout

What did you see instead?

I saw many io/timeout in the logs which means the read timeout setting worked.

However, it finally got stuck.

I dump the following goroutine information with something unimportant omitted.

...
goroutine 10 [IO wait, 1708 minutes]:
internal/poll.runtime_pollWait(0x7f1f8e8635b0, 0x72, 0x0)
	/usr/local/go/src/runtime/netpoll.go:173 +0x57
internal/poll.(*pollDesc).wait(0xc420104098, 0x72, 0xffffffffffffff00, 0xe49a20, 0xe43810)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:85 +0xae
internal/poll.(*pollDesc).waitRead(0xc420104098, 0xc420851000, 0x1000, 0x1000)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Read(0xc420104080, 0xc420851000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	/usr/local/go/src/internal/poll/fd_unix.go:125 +0x18a
net.(*netFD).Read(0xc420104080, 0xc420851000, 0x1000, 0x1000, 0x5ac, 0x0, 0x0)
	/usr/local/go/src/net/fd_unix.go:202 +0x52
net.(*conn).Read(0xc420fac008, 0xc420851000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
	/usr/local/go/src/net/net.go:176 +0x6d
bufio.(*Reader).Read(0xc420f86a80, 0xc420f459d9, 0x98, 0xa627, 0x5ac, 0x0, 0x0)
	/usr/local/go/src/bufio/bufio.go:213 +0x30b
agricola/vendor/github.com/valyala/fasthttp.appendBodyFixedSize(0xc420f86a80, 0xc420f40000, 0x0, 0x10000, 0x5a71, 0xc420797718, 0x89dd14, 0xe9c8d0, 0xc4201c40a0, 0xc4202d81c8)
	/go/src/agricola/vendor/github.com/valyala/fasthttp/http.go:1490 +0xe0
agricola/vendor/github.com/valyala/fasthttp.readBody(0xc420f86a80, 0x5a71, 0x0, 0xc420f40000, 0x0, 0x10000, 0x3684ad31, 0x3684ad310000017a, 0x5a276f1f, 0xc420797798, ...)
	/go/src/agricola/vendor/github.com/valyala/fasthttp/http.go:1434 +0x71
agricola/vendor/github.com/valyala/fasthttp.(*Response).ReadLimitBody(0xc4202d80f0, 0xc420f86a80, 0x0, 0xc420f86a80, 0x49a692bb10e1c)
	/go/src/agricola/vendor/github.com/valyala/fasthttp/http.go:920 +0x123
agricola/vendor/github.com/valyala/fasthttp.(*HostClient).doNonNilReqResp(0xc42007cb40, 0xc4200a0580, 0xc4202d80f0, 0x8a951e, 0xc4200a0698, 0xc4210c4547)
	/go/src/agricola/vendor/github.com/valyala/fasthttp/client.go:1061 +0x31c
agricola/vendor/github.com/valyala/fasthttp.(*HostClient).do(0xc42007cb40, 0xc4200a0580, 0xc4202d80f0, 0x2d, 0x1, 0xc0)
	/go/src/agricola/vendor/github.com/valyala/fasthttp/client.go:966 +0x51
agricola/vendor/github.com/valyala/fasthttp.(*HostClient).Do(0xc42007cb40, 0xc4200a0580, 0xc4202d80f0, 0x2d, 0xc42034e158)
	/go/src/agricola/vendor/github.com/valyala/fasthttp/client.go:945 +0x43
agricola/vendor/github.com/valyala/fasthttp.(*Client).Do(0xc42011c700, 0xc4200a0580, 0xc4202d80f0, 0xc420676810, 0x2c)
	/go/src/agricola/vendor/github.com/valyala/fasthttp/client.go:372 +0x1d9
agricola/vendor/github.com/lujiajing1126/ali_mns.(*aliMNSClient).Send(0xc4202168c0, 0xae824c, 0x3, 0xc420a0c960, 0x0, 0x0, 0xc420584e10, 0x41, 0xa54ba0, 0xc420797cf8, ...)
	/go/src/agricola/vendor/github.com/lujiajing1126/ali_mns/client.go:223 +0x8f0
agricola/vendor/github.com/lujiajing1126/ali_mns.send(0xe4e860, 0xc4202168c0, 0xe4d720, 0xebfbf0, 0xae824c, 0x3, 0x0, 0x0, 0x0, 0xc420584e10, ...)
	/go/src/agricola/vendor/github.com/lujiajing1126/ali_mns/utils.go:12 +0xc8
agricola/vendor/github.com/lujiajing1126/ali_mns.(*MNSQueue).BatchReceiveMessage(0xc42011a880, 0xc4200106c0, 0xc4200141e0, 0xc400000010, 0xc4204523a8, 0x1, 0x1)
	/go/src/agricola/vendor/github.com/lujiajing1126/ali_mns/queue.go:128 +0x38e
...

I could find the network connection is still established:

$ netstat -nlp
Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        0      0 127.0.0.1:6060          0.0.0.0:*               LISTEN      1/agricola
tcp        0      0 127.0.0.11:46638        0.0.0.0:*               LISTEN      -
tcp        0      0 192.168.16.5:38418      112.124.219.10:80       ESTABLISHED 1/agricola
udp        0      0 127.0.0.11:38589        0.0.0.0:*                           -
Active UNIX domain sockets (servers and established)
Proto RefCnt Flags       Type       State         I-Node   PID/Program name     Path

and no tcp packs on the wire is found:

$ tcpdump -nni eth0 -vvvnnn -s 0 -c 1000 host 112.124.219.10 -w package.cap
tcpdump: listening on eth0, link-type EN10MB (Ethernet), capture size 262144 bytes
Got 0

[mvdan]

You are not using net/http - you are using github.com/valyala/fasthttp. I suggest you open an issue over there, and only open one here if it really turns out to be a bug in the standard library somewhere.

[lujiajing1126]

Emmm, Sorry. But I want to figure out what net/http does during the http request.

I found that if no header is sent by the server, there is no ReadDeadline???

It just says:

the server closed connection before returning the first response byte. Make sure the server returns 'Connection: close' response header before closing the connection

And the client just wait for time longer than readTimeout

instead of showing:

send request failed, read tcp4 192.168.16.5:34478->112.124.219.10:80: i/o timeout

Is this a feature/problem related to the net/http?

[mvdan]

If you have any questions about Go, please use https://golang.org/wiki/Questions. The issue tracker is only used to report bugs and propose specific changes.