go: x/build,cmd/go: frequent connection timeouts to github.com since 2022-03-04

#!watchflakes
post <- pkg ~ `cmd/go` && `github.com.*(Connection timed out|TLS connection)` && date < "2023-07-01"

# cd $WORK/tmp/d2/src/github.com/myitcv; git clone -- https://github.com/myitcv/vgo_example_compat $WORK/tmp/d2/src/github.com/myitcv/vgo_example_compat
            Cloning into '$WORK/tmp/d2/src/github.com/myitcv/vgo_example_compat'...
            fatal: unable to access 'https://github.com/myitcv/vgo_example_compat/': Failed to connect to github.com port 443: Connection timed out

greplogs --dashboard -md -l -e 'github.com.* Connection timed out' --since=2021-01-01

@golang/release: were there changes to the linux-.*-longtest image or network configuration around 2022-03-04 that might explain the increase in timeouts at that point?

About this issue

Original URL
State: closed
Created 2 years ago
Comments: 37 (27 by maintainers)

Commits related to this issue

cmd/go: add timestamps to script test output Go tests don't include timestamps by default, but we would like to have them in order to correlate builder failures with server and network logs. Since m... — committed to golang/go by bcmills 2 years ago
cmd/go: set GIT_TRACE_CURL for tests on builders We have noticed a pattern of connection timeouts connecting to github.com on the builders. Adding tracing may shed some light on the underlying cause.... — committed to golang/go by bcmills 2 years ago
cmd/go: declare net hosts in script tests Although we aren't precise about enforcing the hosts just yet, we can eventually use the declared hostnames to selectively skip tests (for example, if an ext... — committed to golang/go by bcmills a year ago
cmd/go: skip the 'git' part of get_insecure_redirect in short mode Invoking 'git' adds about 200ms to this test on a fast machine, probably more on a slow one. (As a general habit we skip the 'git' t... — committed to golang/go by bcmills a year ago
cmd/go: add a GODEBUG to limit the number of concurrent network connections I implemented this in order to debug connection failures on a new-to-me VM development environment that uses Cloud NAT. It ... — committed to golang/go by bcmills a year ago

Most upvoted comments

I’ve been able to reproduce this locally on a VM behind a Google Cloud NAT with a limit of 128 ports.

The root cause is a combination of having a low limit on the number of (statically-allocated or semi-static) NAT ports available to the host, and the tests making a lot of git requests (which always establish a new connection) repeatedly to the same github.com host.

Empirically, the socket for the github.com server does not end up in the TIME-WAIT state on the local machine, so it must be in the TIME-WAIT state on the server side. RFC-1122 says that a host MAY accept a SYN for a socket in the TIME-WAIT state, but only if the initial sequence number is larger than the largest sequence number used for the previous connection.

Perhaps something about the interaction between the VM and the NAT service causes that not to be the case here, or perhaps the Cloud NAT service refuses to reuse ports just in case the other host doesn’t support this optional behavior.

Either way, the NAT service ends up with all of the available ports in the host’s static range in the TIME-WAIT state on the server side, and something (either the NAT service or the GitHub server itself) drops the connections until the TIME_WAIT interval expires.

The general solution is to increase the number of ports available to the host, either by expanding the per-host static port range (as Heschi did) or by using dynamic NAT port assignments instead.

I suspect it could also be remedied by setting up a connection-pooling HTTPS proxy on the VM.

And, of course, we could reduce the number of times we connect to the same external hosts in tests. 😅

bcmills on Mar 3, 2023

In the course of chasing something else it occurred to me that this might be NAT port exhaustion. GCE monitoring does show low levels of packet drops due to OUT_OF_RESOURCES. I’ve doubled the per-VM port allocation from 256 to 512, let’s see if that helps.

heschi on Jul 20, 2022

Hmm, but as a diagnostic I wonder if GIT_TRACE_CURL_NO_DATA and/or GIT_CURL_VERBOSE in the script environment would help? I’ll give that a try, and we can see if it yields anything useful for debugging.

bcmills on May 31, 2022

Not that I’m aware of.

heschi on Apr 26, 2022