golang/go

cmd/go: cache hit takes too long on a test that opens many files

Open

#26,726 opened on Jul 31, 2018

View on GitHub
 (16 comments) (0 reactions) (0 assignees)Go (19,008 forks)batch import
GoCommandNeedsInvestigationToolSpeedhelp wanted

Repository metrics

Stars
 (133,883 stars)
PR merge metrics
 (No merged PRs in 30d)

Description

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

go1.10.2

Does this issue reproduce with the latest release?

Yes.

ijt$ time go1.11beta1 test .                                                                                                                                                                                                                                                                                                 
ok      github.com/google/go-cloud/wire/internal/wire   38.037s

real    1m10.576s
user    1m22.899s
sys     0m52.377s
ijt$ time go1.11beta1 test .
ok      github.com/google/go-cloud/wire/internal/wire   (cached)

real    0m30.822s
user    0m11.384s
sys     0m20.135s

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

GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/issactrotts/Library/Caches/go-build"
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/issactrotts/gopath"
GORACE=""
GOROOT="/Users/issactrotts/homebrew/Cellar/go/1.10.2/libexec"
GOTMPDIR=""
GOTOOLDIR="/Users/issactrotts/homebrew/Cellar/go/1.10.2/libexec/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
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 -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/9z/3vhqmj_j18v6vsk1q2jr486r001n0v/T/go-build330802734=/tmp/go-build -gno-record-gcc-switches -fno-common"

What did you do?

m=github.com/google/go-cloud
go get $m
cd $(go list -f '{{.Dir}}' $m)
cd wire/internal/wire
# Run tests once.
time go test -v .
# Run tests again. This time the result is cached, but it still takes over 30s on a 2015 Macbook pro laptop.
time go test -v .

What did you expect to see?

The second test run should have taken under 1s since nothing changed.

What did you see instead?

It took over 30s.

@zombiezen suggested that the slowness arises from the wire tests opening many packages under $GOROOT for type checking, making go test spend a lot of time checking their hashes when deciding whether there is a cache hit.

Contributor guide