x/tools: freebsd-amd64-race builder is flaky

[dmitshur]

The freebsd-amd64-race builder was largely passing on x/tools before June 25, and started to fail often since then:

Before	After

(Screenshots from https://build.golang.org/?repo=golang.org%2fx%2ftools.)

The first failures started with CL 240019, but it seems likely that the parent commit, CL 239754, is more relevant (and just got lucky in that none of the tests happened to fail when it was submitted).

A lot of the failures mention "context deadline exceeded". A more underlying cause of them taking so long that the context deadline gets exceeded may be related to some sort of a problem related to to the environment. Many of the failures mention errors about "missing $GOPATH":

--- FAIL: TestGOMODCACHE (9.36s)
    --- FAIL: TestGOMODCACHE/forwarded (5.00s)
        runner.go:199: connection not closed: context deadline exceeded
lsprpc.go:341: unable to add local env to initialize request: err: exit status 1: stderr: missing $GOPATH
FAIL
FAIL	golang.org/x/tools/internal/lsp/regtest	467.318s

Some do not:

--- FAIL: TestDeleteFiles (24.08s)
    --- FAIL: TestDeleteFiles/delete_then_close (11.32s)
        --- FAIL: TestDeleteFiles/delete_then_close/forwarded (4.88s)
            watch_test.go:409: unmeetable expectations:
                	Unmeetable: no log message matching "a_unneeded.go"
                	Unmet: empty diagnostics
                
                state:
                #### log messages (see RPC logs for full text):
                	Info: "2020/07/06 20:51:49 Handshake session update\n\tup...
                	Info: "2020/07/06 20:51:50 Build info\n----------\nversio...
                	Info: "2020/07/06 20:51:51 go env for /tmp/workdir/tmp/go...
                	Info: "2020/07/06 20:51:51 go/packages.Load\n\tsnapshot=0...
                	Info: "2020/07/06 20:51:51 go/packages.Load\n\tsnapshot=3...
                	Info: "2020/07/06 20:51:51 go/packages.Load\n\tsnapshot=3...
                	Info: "2020/07/06 20:51:52 go/packages.Load\n\tsnapshot=3...
                
                #### diagnostics:
                	a/a_unneeded.go (version 0):
                	a/a.go (version 2):
                		(3, 1): undeclared name: fmt
                
                #### outstanding work:
                	diagnosing changed files: 0.00
                #### completed work:
                	diagnosing unknown file modification: 1
                	diagnosing files changed on disk: 1
                	diagnosing changed files: 1
                	diagnosing opened files: 2
            testing.go:1023: race detected during execution of test
        testing.go:1023: race detected during execution of test
    testing.go:1023: race detected during execution of test
FAIL
FAIL	golang.org/x/tools/internal/lsp/regtest	530.779s

The tests are executed with these environment variables (seen at the top of build log):

:: Running /tmp/workdir/go/bin/go with args ["/tmp/workdir/go/bin/go" "test" "-short" "-race" "golang.org/x/tools/..."] and env ["PATH=/tmp/workdir/go/bin:/bin:/sbin:/usr/bin:/usr/local/bin:/usr/local/bin" "PWD=/" "HOME=/" "RC_PID=22" "WORKDIR=/tmp/workdir" "GOROOT_BOOTSTRAP=/tmp/workdir/go1.4" "GO_BUILDER_NAME=freebsd-amd64-race" "CC=clang" "GOROOT=/tmp/workdir/go" "GOPATH=/tmp/workdir/gopath" "GOPROXY=http://10.240.0.3:30157" "TMPDIR=/tmp/workdir/tmp" "GOCACHE=/tmp/workdir/gocache"] in dir /tmp/workdir/gopath/src/golang.org/x/tools

Notably, GOROOT, GOPATH, GOCACHE are set. GOMODCACHE is not set (which means to use the default location, GOPATH[0]/pkg/mod), which seems fine for a builder.

Some of the failures are due to #39865 and not related.

This needs investigation to understand if code in x/tools is doing something wrong (and if so, why is this caught on the freebsd-amd64-race builder and not elsewhere), or if the freebsd-amd64-race builder is doing something wrong.

/cc @heschik

[heschi]

Sorry, I don't understand. You've discussed a lot of issues, but it seems to me like this is probably just the same race as everywhere else, #39865, which I am trying to get to as soon as I can. Am I missing something?

[dmitshur]

The problem with "unable to add local env to initialize request" doesn't look related to the race in #39865, but maybe I'm misunderstanding it.

If you think all of the recent failures on freebsd-amd64-race are caused by #39865, feel free to either close this now (we can re-visit after #39865 is resolved), or keep this open and check again after #39865 is resolved. Thanks for working on this!

[stamblerre]

Looks like the fix for the race hasn't fixed this test failure. https://build.golang.org/log/5ec2784264490ec6720b05036da440c3fb874d91 is from a recent failure. I'm a bit stumped by it - looks like the diagnostic isn't being cleared even though the code action happens as expected.

[gopherbot]

Change https://golang.org/cl/241521 mentions this issue: internal/lsp/regtest: remove stray short timeout

[heschi]

Still seeing: lsprpc.go:341: unable to add local env to initialize request: err: exit status 1: stderr: missing $GOPATH

[stamblerre]

I've been seeing these for a while: #37318 (comment). I'm not sure what their cause is / if they indicate a failure.

[heschi]

Fair. The log I was looking at was https://build.golang.org/log/ed6ca9cef9cde993b4007a38c3cef47dd239f813. I'll keep an eye on it for a little longer.

[heschi]

It's been clean for a day other than that one failure which I'm blaming on the builder.