net: KeepAlive is disabled by write to dead link

[networkimprov]

Was: net.Dialer.Dial() doesn't respect .KeepAlive

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

$ go version
go version go1.12 linux/amd64

Does this issue reproduce with the latest release?

Haven't tried 1.12.1+

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

go env Output

$ go env
GOARCH="amd64"
GOBIN=""
GOCACHE="/root/.cache/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/root/go"
GOPROXY=""
GORACE=""
GOROOT="/usr/lib/go"
GOTMPDIR=""
GOTOOLDIR="/usr/lib/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build601953146=/tmp/go-build -gno-record-gcc-switches"

What did you do/see?

For a TLS connection that's been dropped, c.Read() returns a net.Error with e.Timeout()==true after ~18 minutes, apparently due to KeepAlive failure. The connection is closed by the server while the client (laptop running VMWare with Linux) is suspended. Error string:
"read tcp n.n.n.n:p->n.n.n.n:p: read: connection timed out"

The note on 5bd7e9c5 (discussed in #23459) says the default for net.Dialer keepalive failure is just 2-3min. With an explicit KeepAlive, I also see odd waits:

net.Dialer{KeepAlive: 30 * time.Second} 18min
net.Dialer{KeepAlive: 25 * time.Second} 18min
net.Dialer{KeepAlive: 10 * time.Second} 16min
net.Dialer{KeepAlive: 5 * time.Second} <1min, but at least once 18min

Measurements aren't precise; 16-18 minutes could be 1000 or 1024 seconds. Code has:

   aDlr := net.Dialer{Timeout: 3*time.Second} // default KeepAlive
   aCfgTls := tls.Config{InsecureSkipVerify: true}
   aConn, err := tls.DialWithDialer(&aDlr, "tcp", "host:port", &aCfgTls)
   if err != nil { return err }
   err = aConn.Write(...) // <256 bytes
   // brief exchange of short messages
   aLen, err := aConn.Read(...)

Also filed #31449 to report that the error due to keepalive doesn't comply with the docs re connection timeout.

cc @FiloSottile @bradfitz

[bradfitz]

tls.DialWithDialer literally calls net.Dialer.Dial, so I don't think there's anything TLS-specific here.

[FiloSottile]

Yeah, I looked and while net/http used to mess with the keep-alives, crypto/tls does not.

Can you figure out the KEEPCNT value on your system?

[networkimprov]

I have the standard defaults:

$ cat /proc/sys/net/ipv4/tcp_keepalive_intvl
75
$ cat /proc/sys/net/ipv4/tcp_keepalive_probes
9
$ cat /proc/sys/net/ipv4/tcp_keepalive_time
7200

[networkimprov]

A likely factor... After resuming the client, its date jumps forward to the current time.

On my system, that happens after 0-10 mins (it isn't immediate due to a VMWare or Linux driver issue). But that should cause a max wait of 13mins for the default KeepAlive.

[networkimprov]

cc @mikioh

[pam4]

@networkimprov, I'm a little confused about your setup.
Your dialer has keep-alives active and you expect the dialed connection to die sooner, but the dialer side is the one being suspended, right?

Anyway I suspect that in your test case, a Write on the connection is happening after the network failure, therefore the keepalive state is abandoned or never reached.
A socket can only be in the keepalive state if it is idle. If there is outstanding data, the socket will be in the on state as it retransmits the data over and over because of the network failure.

It seems a common misconception that a connection with keep-alives enabled is going to return an error within TCP_KEEPIDLE + TCP_KEEPINTV * TCP_KEEPCNT seconds from a network failure. This is often not the case.

I reproduced the issue on Linux, with client and server on the same host, using iptables to cut the network:

# iptables -A INPUT -p tcp --dport 12345 -j DROP; iptables -A INPUT -p tcp --sport 12345 -j DROP; date

I used netcat as server, and a simple Go program with default keep-alives (15s) as client.
The client terminates on read error and has 2 modes: #1 writes 1 byte; #2 writes 1 byte, sleeps 10s, then writes another byte (during those 10s I cut the network).
In mode #1 I get the read error consistently after ~2m26s while in mode #2 I get it after ~16m.
It doesn't hang forever because tcp_retries2 is reached, but it could take as long as 30m.

This is the first web search result I found about the issue.