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

cmd/go: possible regression in test caching behaviour #29111

Open
rogpeppe opened this Issue Dec 5, 2018 · 10 comments

Comments

Projects
None yet
3 participants
@rogpeppe
Contributor

rogpeppe commented Dec 5, 2018

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

$ go version
go version devel +5e1727892b Wed Dec 5 14:12:14 2018 +0000 linux/amd64

Does this issue reproduce with the latest release?

yes

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

go env Output
$ go env
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/rog/.cache/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/rog/src/go"
GOPROXY="http://localhost:3000"
GORACE=""
GOROOT="/home/rog/go"
GOTMPDIR=""
GOTOOLDIR="/home/rog/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/home/rog/src/mod2godeps/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-build832393617=/tmp/go-build -gno-record-gcc-switches"

On a rather large closed source program, when using go1.11.2, if I run go test ., I see that the test has been cached. Using the same code and go tip, the tests are never cached.

With go1.11, if I pass the -test.testlogfile arg to the test binary, the difference in the testlog file when running each test is this:

3c3
< open /tmp/test-mgo073409022/keyfile
---
> open /tmp/test-mgo464881993/keyfile
48,51c48,51
< stat /tmp/test-mgo073409022
< open /tmp/test-mgo073409022
< stat /tmp/test-mgo073409022/journal
< open /tmp/test-mgo073409022/journal
---
> stat /tmp/test-mgo464881993
> open /tmp/test-mgo464881993
> stat /tmp/test-mgo464881993/journal
> open /tmp/test-mgo464881993/journal

With tip, the difference is:

3c3
< open /tmp/test-mgo213928049/keyfile
---
> open /tmp/test-mgo446671093/keyfile

A sample testlog output file on go1.11 is:

	# test log
	getenv TMPDIR
	open /tmp/test-mgo073409022/keyfile
	getenv JUJU_MONGOD
	stat /usr/lib/juju/mongo3.2/bin/mongod
	getenv PATH
	stat /home/rog/bin/mongod
	stat /usr/local/sbin/mongod
	stat /usr/local/bin/mongod
	stat /usr/sbin/mongod
	stat /usr/bin/mongod
	open /dev/null
	open /usr/bin/mongod
	getenv JUJU_MONGO_STORAGE_ENGINE
	open /dev/null
	open /usr/bin/mongod
	getenv GODEBUG
	getenv RES_OPTIONS
	getenv HOSTALIASES
	open /etc/nsswitch.conf
	open /etc/resolv.conf
	stat /etc/mdns.allow
	stat /etc/hosts
	open /etc/hosts
	getenv TEST_LOGGING_CONFIG
	getenv TEST_LOGGING_CONFIG
	getenv GODEBUG
	getenv GODEBUG
	getenv HTTP_PROXY
	getenv http_proxy
	getenv HTTPS_PROXY
	getenv https_proxy
	getenv NO_PROXY
	getenv no_proxy
	getenv REQUEST_METHOD
	getenv TEST_LOGGING_CONFIG
	getenv GODEBUG
	getenv TEST_LOGGING_CONFIG
	getenv GODEBUG
	getenv TEST_LOGGING_CONFIG
	getenv GODEBUG
	getenv TEST_LOGGING_CONFIG
	getenv GODEBUG
	getenv TEST_LOGGING_CONFIG
	getenv GODEBUG
	getenv TEST_LOGGING_CONFIG
	getenv GODEBUG
	stat /tmp/test-mgo073409022
	open /tmp/test-mgo073409022
	stat /tmp/test-mgo073409022/journal
	open /tmp/test-mgo073409022/journal

For tip, the testlog output looks like this:

	# test log
	getenv TMPDIR
	open /tmp/test-mgo213928049/keyfile
	open /proc/sys/net/core/somaxconn
	getenv JUJU_MONGOD
	stat /usr/lib/juju/mongo3.2/bin/mongod
	getenv PATH
	stat /home/rog/bin/mongod
	stat /usr/local/sbin/mongod
	stat /usr/local/bin/mongod
	stat /usr/sbin/mongod
	stat /usr/bin/mongod
	open /dev/null
	open /usr/bin/mongod
	getenv JUJU_MONGO_STORAGE_ENGINE
	open /dev/null
	open /usr/bin/mongod
	getenv GODEBUG
	getenv RES_OPTIONS
	getenv HOSTALIASES
	open /etc/nsswitch.conf
	open /etc/resolv.conf
	stat /etc/mdns.allow
	stat /etc/hosts
	open /etc/hosts
	getenv TEST_LOGGING_CONFIG
	getenv TEST_LOGGING_CONFIG
	getenv GODEBUG
	getenv GODEBUG
	getenv HTTP_PROXY
	getenv http_proxy
	getenv HTTPS_PROXY
	getenv https_proxy
	getenv NO_PROXY
	getenv no_proxy
	getenv REQUEST_METHOD
	getenv TEST_LOGGING_CONFIG
	getenv GODEBUG
	getenv TEST_LOGGING_CONFIG
	getenv GODEBUG
	getenv TEST_LOGGING_CONFIG
	getenv GODEBUG
	getenv TEST_LOGGING_CONFIG
	getenv GODEBUG
	getenv TEST_LOGGING_CONFIG
	getenv GODEBUG
	getenv TEST_LOGGING_CONFIG
	getenv GODEBUG
	open /tmp/

Note that all the files in /tmp are only created for the duration of the test.

@rogpeppe rogpeppe added this to the Go1.12 milestone Dec 5, 2018

@rogpeppe

This comment has been minimized.

Contributor

rogpeppe commented Dec 5, 2018

@bcmills bcmills added the GoCommand label Dec 5, 2018

@bcmills bcmills self-assigned this Dec 5, 2018

@gopherbot

This comment has been minimized.

gopherbot commented Dec 11, 2018

Change https://golang.org/cl/153639 mentions this issue: cmd/go: test that 'go test .' in module mode is cached

@bcmills

This comment has been minimized.

Member

bcmills commented Dec 11, 2018

@rogpeppe, I'm not able to reproduce the issue from the information provided.

https://golang.org/cl/153639 contains my attempt; could you have a look and see how it differs from the behavior of your example?

@bcmills bcmills modified the milestones: Go1.12, Go1.13 Dec 11, 2018

@rogpeppe

This comment has been minimized.

Contributor

rogpeppe commented Dec 12, 2018

I can reproduce the behaviour with the following:

-- go.mod --
module golang.org/issue/29111/foo

-- foo.go --
package foo

-- foo_test.go --
package foo_test

import (
	"io/ioutil"
	"path/filepath"
	"testing"
)

func TestX(t *testing.T) {
	dir, err := ioutil.TempDir("", "")
	if err != nil {
		t.Fatal(err)
	}
	defer os.RemoveAll(dir)
	err = ioutil.WriteFile(filepath.Join(dir, "x"), nil, 0666)
	if err != nil {
		t.Fatal(err)
	}
}
@rogpeppe

This comment has been minimized.

Contributor

rogpeppe commented Dec 12, 2018

Weirdly, although it's is a (very!) strict subset of what the original tests are doing, Go 1.11.2 doesn't cache the above example, so technically it doesn't exhibit the regression. :-\

@rogpeppe

This comment has been minimized.

Contributor

rogpeppe commented Dec 12, 2018

Ah, the issue was that the example didn't remove the directory afterwards. I've adjusted the example so it removes the directory afterwards, which does exhibit the regressive behaviour.

@bcmills

This comment has been minimized.

Member

bcmills commented Dec 13, 2018

Thanks, that example does the trick (modulo adding the missing "os" import).

@gopherbot

This comment has been minimized.

gopherbot commented Dec 13, 2018

Change https://golang.org/cl/154100 mentions this issue: cmd/go: in module mode, populate PackagePublic.Root with the module root

@rogpeppe

This comment has been minimized.

Contributor

rogpeppe commented Dec 14, 2018

Tangential comment: the link above should link to https://go-review.googlesource.com/c/go/+/154100 but it actually points to the unrelated https://codereview.appspot.com/154100, an issue from 2009!
Looks like there's some ambiguity in the golang.org/cl scheme.

@bcmills

This comment has been minimized.

Member

bcmills commented Dec 14, 2018

@rogpeppe, that's #28836.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment