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: Dial returns before connection complete #19289

Closed
bdarnell opened this issue Feb 25, 2017 · 10 comments
Closed

net: Dial returns before connection complete #19289

bdarnell opened this issue Feb 25, 2017 · 10 comments
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done.
Milestone

Comments

@bdarnell
Copy link

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

go version go1.8 linux/amd64

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="/x-tools/x86_64-unknown-linux-gnu/bin/x86_64-unknown-linux-gnu-gcc"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/go/src/github.com/cockroachdb/cockroach/artifacts/go-build659805865=/tmp/go-build -gno-record-gcc-switches"
CXX="/x-tools/x86_64-unknown-linux-gnu/bin/x86_64-unknown-linux-gnu-g++"
CGO_ENABLED="1"
PKG_CONFIG="pkg-config"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-static-libgcc -static-libstdc++"

What did you do?

Call net.Dial to connect to a remote host, and if it succeeds, Write to the connection. Simultaneously, kill -9 the listening process.

What did you expect to see?

I expect Dial to either return with nil error or an error like "connection refused". I expect Write to either succeed or return a different type of error, such as "connection reset". Specifically, I do not expect to see "connection refused" from anything but net.Dial.

What did you see instead?

Sometimes Write returns "connection refused". The fact that this is a non-temporary error (but most other errors that are possible for Write are temporary according to err.Temporary()) can cause error handling to get confused (see grpc/grpc-go#1026). This occurs with some regularity (~daily) on a CockroachDB test cluster, although we have not yet been able to reduce this to something simpler.

My hypothesis is that the net poller sometimes causes spurious wakeups, leading Dial to return too soon (with nil error) because getsockopt(..., SO_ERROR) does not yet have an error to return. This was observed in #14548, where the problem was more severe on Darwin and so it was given a Darwin-specific fix. If spurious wakeups are possible on Linux too (this was not determined one way or the other in #14548), one way this would manifest is connect-time errors leaking out into other system calls.

@bradfitz bradfitz changed the title net: Dial returns before connection complete net: Dial returns before connection complete Feb 26, 2017
@bradfitz
Copy link
Contributor

although we have not yet been able to reduce this to something simpler

So is the whole kill -9 thing just a theory or is that part for sure?

Have you tried a repeated loop of dial a child process in a loop while kill -9'ing the child and it yielded no results, or ...?

@bdarnell
Copy link
Author

It's a theory. The test cluster where we've observed this is used for "chaos" testing where we have a cron job that kills random processes periodically. I've tried to simply connect to a port where nothing is listening and haven't reproduced the problem, so that's where we get the theory that racing with the death of the remote process matters (or at least the closing of the listening socket). I also believe this requires a real network connection and not just two processes on localhost (some time needs to pass between the connect() and the connection refusal).

It's also possible that the missing link is something going on in the client process instead of specific network activity and timing. I had a theory back in #14548 that spurious wakeups were caused by reuse of runtime.pollDesc objects (and specifically the comment that "we can get ready notification from epoll/kqueue after the descriptor is closed/reused. Stale notifications are detected using seq variable", but seq is only consulted for deadlines, and not when netpoll_epoll.go calls netpollready). I haven't grokked this code well enough to understand how exactly stale notifications could happen.

@bradfitz
Copy link
Contributor

/cc @ianlancetaylor

@bdarnell
Copy link
Author

OK, I have a repro: https://gist.github.com/bdarnell/2d37a812368bb83090ab60d36ceae3c4

In the repro, we start a bunch of goroutines that dial an address where nothing is listening. We then cancel these dials, attempting to race the cancellation against the arrival of the "connection refused" packet. When we hit the race, here's what I think is going on:

  1. The "connection refused" packet arrives and is processed by the kernel.
  2. In the poller thread, epollwait returns, indicating that the socket FD is ready.
  3. In the cancellation goroutine, we cancel the context.
  4. The dialer's interrupter goroutine sees that the context is canceled and cancels polling by setting a deadline in the past.
  5. pd.WaitWrite returns an error which is passed up the stack. This dial attempt fails.
  6. When we close the file descriptor, the runtime.pollDesc (which the epoll thread above still holds a pointer to) is put back on the freelist.
  7. The next dial attempt starts, and gets the pollDesc from the freelist. We call connect() and start waiting for the results.
  8. The epoll thread from earlier finally gets scheduled again and wakes up the FD that is currently using this pollDesc
  9. The dialer goroutine checks the status of the connection by calling getsockopt. No error has yet occurred, so it returns nil. The dial succeeds.

I see two possible solutions:

  1. Prevent spurious wakeups at the poller level, by storing a pair (*pollDesc, seq) instead of just a *pollDesc in epollevent.data. Doing this naively would require a lot of additional allocations, but it might be possible to use another freelist.
  2. Tolerate spurious wakeups during the connection process. I believe other uses of the poller are generally safe, since they'll just get EAGAIN and try again; only the getsockopt in connect appears to be vulnerable to this issue. DJB suggests getpeername as a potential alternative to getsockopt.

@bradfitz bradfitz added this to the Go1.9 milestone Feb 27, 2017
@bradfitz
Copy link
Contributor

@ianlancetaylor, any theories? Or punt to Go 1.10.

@bradfitz bradfitz added the NeedsFix The path to resolution is known, but the work has not been done. label Jun 14, 2017
@ianlancetaylor
Copy link
Contributor

@bdarnell Thanks for test case and analysis. I am able to recreate the problem. One thing I don't yet understand, though, is that even with a spurious wakeup, the call to fetch SO_ERROR only happens after connect has been called on the socket and has returned EINPROGRESS. I don't yet understand why the SO_ERROR would return no error when the socket is not actually connected.

@ianlancetaylor
Copy link
Contributor

OK, I understand now. SO_ERROR only returns a meaningful value after the socket is ready for writing.

@gopherbot
Copy link

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

@bradfitz
Copy link
Contributor

Nice find.

@stevenh
Copy link
Contributor

stevenh commented Aug 22, 2017

Thanks for this fix, we've been chasing the same thing googleapis/google-api-go-client#220

@golang golang locked and limited conversation to collaborators Aug 22, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done.
Projects
None yet
Development

No branches or pull requests

5 participants