cmd/go: occasional "failed to cache compiled Go files" when 'go list -compiled' runs in parallel #29667

cespare · 2019-01-10T23:38:27Z

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

Go 1.11.4

Does this issue reproduce with the latest release?

~~It does not reproduce with Go 1.12beta1.~~ It reproduces at tip at a somewhat lower rate. See @dominikh's comment, below.

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

linux/amd64

What did you do?

@dominikh wrote a small reproducer: https://play.golang.org/p/ghOtMwBnGu7

It may take a few runs to fail. Clean out your build cache or use GOCACHE=/tmp/empty to make it more reliably fail.

What did you expect to see?

Calling go list in parallel should succeed.

What did you see instead?

go build <some package>: failed to cache compiled Go files

I think this happens only when -compiled is provided to go list (which is new in Go 1.11?)

The context in which this comes up is multiple tools running golang.org/x/tools/go/packages.Load at the same time. I believe the issue is in go list but possibly the bug (or at least the workaround) should be in golang.org/x/tools/go/packages.

I also believe this is much more likely to happen with an empty GOCACHE. We've mainly been seeing this our CI environment. github.com/google/wire has also been seeing this in Travis: google/wire#66.

The effects of this issue tend to be pretty far away from the go list invocation. We've run into it via staticcheck (http://staticcheck.io/) as well as our own go/packages-using code.

~~I can't get this to reproduce in 1.12beta1. It would be helpful if someone can find the CL that fixed it. I think it would also be valuable if the fix could be backported to Go 1.11 in the meantime.~~ (It does reproduce at tip.)

The ecosystem is rapidly converging on the new, go list-based way of writing tooling (typically via go/packages) so I expect this will arise often.

/cc @bcmills @dominikh @zombiezen @ianthehat

The text was updated successfully, but these errors were encountered:

cespare · 2019-01-10T23:42:38Z

Note that while this bug resembles #26794, it occurs when modules aren't involved (GOPATH mode).

(I haven't tried to reproduce it in conjunction with modules.)

bcmills · 2019-01-11T16:29:46Z

I can't get this to reproduce in 1.12beta1.

Nor can I, and I really have no idea how it would have been fixed.

If someone wants to bisect we can at least consider a backport, but given that we can't reproduce it in 1.12, and that it occurs only rarely (and under unusual load) in 1.11, I can't justify putting a lot of effort into tracking it down.

dominikh · 2019-01-11T18:22:54Z

I'll bisect it.

dominikh · 2019-01-11T19:01:17Z

Actually, there is no need to bisect it. The issue still occurs as of go version devel +a2bb68de4d Fri Jan 11 16:08:59 2019 +0000 linux/amd64. When GOCACHE is on a tmpfs, the error occurs at a rate of roughly 1% on my system. It is easier to hit the issue on slower media, at a rate of anywhere from 53% to 93% on an NFS mount, which isn't very surprising if we assume that this is a race condition. It seems that 1.11.4 has vastly more instances of this error at a rate of 80% when on NFS, versus tip at 52%

bcmills · 2019-01-11T19:15:26Z

Good to know — thanks for the investigation!

CC @jayconrod

cespare · 2019-01-11T20:45:45Z

@dominikh thanks for that info. I updated the original description too.

fho · 2019-01-15T16:48:40Z

We are using Go 1.11.2 in our CI system and running parallel jobs that are accessing the same GOCACHE dir by the command:

go list -e -json -compiled -test=false -export=false -deps=true -- ./...

Recently we implemented to boot additional CI workers on demand. The worker are started with an empty GOCACHE directory.
Since this change we run into the failed to cache compiled Go files multiples times a day.

golang/go#29667 Co-authored-by: Maria Shaldibina <mshaldibina@pivotal.io>

cespare · 2019-02-02T01:19:18Z

This bug has been biting us a lot as we run more and more tools in CI environments which use go/packages. In case it helps other people, the workaround we recently started using is a shim binary that passes its arguments to the go tool. If it sees that it is being called as go list, it uses a global lock file to prevent simultaneous go list executions. In CI and script environments where the workaround is needed, the fake go is put in a directory at the front of the $PATH.

I also looked into writing a GOPACKAGESDRIVER tool which would apply the same lockfile-based mutual exclusion around go list but it looked like that would require copy-pasting a lot of code out of go/packages.

nmiyake · 2019-03-08T22:21:18Z

I'm still seeing this failure even after upgrading to Go 1.12 -- we're encountering this error when running checks in parallel in a CI environment. The CI environment uses Go 1.12 and the checks are compiled with Go 1.12 as well. The projects use GOPATH mode (it is not a module project).

Is there anything that we can do to help with the investigation or fix for this issue?

jayconrod · 2019-03-08T23:45:50Z

@nmiyake If you could describe your CI environment file system, operating system, architecture and any other platform information relevant to file locking, that would be a useful data point.

nmiyake · 2019-03-08T23:55:34Z

This is on an enterprise deployment of CircleCI 2. The Docker image used to run the CI is the official golang:1.12 image.

Output of go env:

root@1965526c4de7:/go# go env
GOARCH="amd64"
GOBIN=""
GOCACHE="/root/.cache/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/go"
GOPROXY=""
GORACE=""
GOROOT="/usr/local/go"
GOTMPDIR=""
GOTOOLDIR="/usr/local/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-build212534544=/tmp/go-build -gno-record-gcc-switches"

viveklak · 2019-03-19T21:55:19Z

Also seeing this locally as well as on CircleCI (cloud hosted offering). Running on official Go 1.12.1 image.

ConradKurth · 2019-05-24T22:31:08Z

Having this same problem. Our CI/CD is running golangci-lint, which underlying is the go list. Strange part is when I ssh into the box, i can run it fine, but when the program runs on its normal workflow it works

env is

GOARCH="amd64"
GOBIN=""
GOCACHE="/root/.cache/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/go"
GOPROXY=""
GORACE=""
GOROOT="/usr/local/go"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/go/src/github.com/HeadspaceMeditation/go-service-template/go.mod"
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-build389910482=/tmp/go-build -gno-record-gcc-switches"

jwm · 2019-06-11T15:36:15Z

We're seeing this with go 1.11.5 and 1.12.5 (both the official Docker images).

After reading @cespare's comment about putting a mutex on go list, we added this go wrapper to our build process, which works around the problem nicely, letting us perform parallel builds.

#!/bin/sh

set -e

for i in "$@"; do
	if [ "$i" = list ]; then
		set -o noclobber
		while ! echo "$$" >/tmp/go-list-lock; do
			sleep 0.25
		done
		trap 'rm -f /tmp/go-list-lock' EXIT
	fi
done

/usr/local/go/bin/go "$@"

bcmills · 2019-06-28T14:42:47Z

Here's one via the x/tools tests:
https://build.golang.org/log/bcf9572ff6f39f405e18be4d5f2dfea98e4764ed

gopherbot · 2019-07-30T14:33:47Z

Change https://golang.org/cl/188157 mentions this issue: cmd/go/internal/cache: avoid ioutil.WriteFile for writing cache entries

gopherbot · 2019-07-30T19:34:53Z

Change https://golang.org/cl/188020 mentions this issue: cmd/go/internal/cache: verify that timestamp is positive

gopherbot · 2019-07-30T19:34:54Z

Change https://golang.org/cl/188021 mentions this issue: cmd/go/internal/cache: include detail in errors from (*cache).Get

An apparent typo caused us to re-check size instead. Updates #29667 Change-Id: Icc1fb9cef1ba77b8490c8fbe6c343be06ff48d8d Reviewed-on: https://go-review.googlesource.com/c/go/+/188020 Run-TryBot: Bryan C. Mills <bcmills@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Jay Conrod <jayconrod@google.com>

Since the cache has been required since Go 1.12, also remove redundant checks for a nil cache. Updates #29127 Updates #29667 Change-Id: Ibc59b659306a4eef2d4f0e3d0b651986d6cf84ad Reviewed-on: https://go-review.googlesource.com/c/go/+/188021 Run-TryBot: Bryan C. Mills <bcmills@google.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Jay Conrod <jayconrod@google.com>

cespare mentioned this issue Jan 10, 2019

wire: test flakes on Travis with "failed to cache compiled Go files" google/wire#66

Closed

julieqiu added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Jan 10, 2019

julieqiu added this to the Go1.12 milestone Jan 10, 2019

bcmills modified the milestones: Go1.12, Go1.11.5 Jan 11, 2019

bcmills modified the milestones: Go1.11.5, Go1.13 Jan 11, 2019

jayconrod added the GoCommand cmd/go label Jan 11, 2019

jayconrod self-assigned this Jan 11, 2019

mariash added a commit to cloudfoundry/diego-release that referenced this issue Jan 18, 2019

fix for GOCACHE failing in parallel

97b35fa

golang/go#29667 Co-authored-by: Maria Shaldibina <mshaldibina@pivotal.io>

jayconrod mentioned this issue Feb 4, 2019

cmd/go: race causes go mod download to error with mkdir /go/pkg/mod..: no such file or directory #30068

Closed

dominikh mentioned this issue Jun 28, 2019

Problems when running staticcheck concurrently dominikh/go-tools#530

Closed

andybons modified the milestones: Go1.13, Go1.14 Jul 8, 2019

gopherbot closed this as completed in 2fc7574 Jul 30, 2019

RaduBerinde mentioned this issue Oct 22, 2019

teamcity: failed test: TestLint cockroachdb/cockroach#41789

Closed

jayconrod mentioned this issue Feb 18, 2020

ctrl+] behavior does not navigate to symbols in the same module but different source file fatih/vim-go#2716

Closed

bricerisingalgorand mentioned this issue Jun 9, 2020

Eric/use mule in jenkins algorand/go-algorand#1072

Merged

golang locked and limited conversation to collaborators Jul 29, 2020

gopherbot added the FrozenDueToAge label Jul 29, 2020

rsc unassigned jayconrod Jun 23, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

cmd/go: occasional "failed to cache compiled Go files" when 'go list -compiled' runs in parallel #29667

cmd/go: occasional "failed to cache compiled Go files" when 'go list -compiled' runs in parallel #29667

cespare commented Jan 10, 2019 •

edited

cespare commented Jan 10, 2019

bcmills commented Jan 11, 2019

dominikh commented Jan 11, 2019

dominikh commented Jan 11, 2019

bcmills commented Jan 11, 2019

cespare commented Jan 11, 2019

fho commented Jan 15, 2019

cespare commented Feb 2, 2019

nmiyake commented Mar 8, 2019

jayconrod commented Mar 8, 2019

nmiyake commented Mar 8, 2019

viveklak commented Mar 19, 2019

ConradKurth commented May 24, 2019

jwm commented Jun 11, 2019

bcmills commented Jun 28, 2019

gopherbot commented Jul 30, 2019

gopherbot commented Jul 30, 2019

gopherbot commented Jul 30, 2019

cmd/go: occasional "failed to cache compiled Go files" when 'go list -compiled' runs in parallel #29667

cmd/go: occasional "failed to cache compiled Go files" when 'go list -compiled' runs in parallel #29667

Comments

cespare commented Jan 10, 2019 • edited

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

Does this issue reproduce with the latest release?

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

What did you do?

What did you expect to see?

What did you see instead?

cespare commented Jan 10, 2019

bcmills commented Jan 11, 2019

dominikh commented Jan 11, 2019

dominikh commented Jan 11, 2019

bcmills commented Jan 11, 2019

cespare commented Jan 11, 2019

fho commented Jan 15, 2019

cespare commented Feb 2, 2019

nmiyake commented Mar 8, 2019

jayconrod commented Mar 8, 2019

nmiyake commented Mar 8, 2019

viveklak commented Mar 19, 2019

ConradKurth commented May 24, 2019

jwm commented Jun 11, 2019

bcmills commented Jun 28, 2019

gopherbot commented Jul 30, 2019

gopherbot commented Jul 30, 2019

gopherbot commented Jul 30, 2019

cespare commented Jan 10, 2019 •

edited

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

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