cmd/go: add a flag to report test compile time

[roopakv]

I want to shard my go package tests across different containers based on the time each package takes to test + compile. Right now we have packages that run in ~20ms and some that take ~15 seconds. Go test only reports the time taken to run the test not compile them. So if I use circleCIs sharding functionality it drops the 15second test package on a container on its own, but that compiles pretty quickly. It however drops many packages that take 20ms on another container and since i dont give circle ci the time compilation takes my sharding will never be optimal.

if there was go test --compile-time which included the compile time in the rest run time reports my problem would be resolved

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

$ go version 1.12.5

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="/Users/roopak/Library/Caches/go-build"
GOEXE=""
GOFLAGS="-mod=vendor"
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/roopak/workspace/go/default"
GOPROXY=""
GORACE=""
GOROOT="/usr/local/go"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD="/Users/roopak/workspace/go/hail/src/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 -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/s3/mcr5r_9973z0pznr8vzdkkzw0000gn/T/go-build903117269=/tmp/go-build -gno-record-gcc-switches -fno-common"

What did you do?

1.) Run go test on any package
2) Look at test timing.

What did you expect to see?

2. flag to include compile time in test report

What did you see instead?

3. test time only includes actual test running time

[bcmills]

Thanks for the suggestion. Note that go test today does quite a bit of caching under the hood, so its reported compilation time would necessarily depend on the state of the cache (which would presumably vary across your CI shards).

[ALTree]

Are your test files so slow to compile that this actually makes a measurable difference in the optimal sharding configuration? Tests execution can take a long time, but I would assume that any reasonable test file would compile in less time that it takes to spin up a container or whatever you are using for sharding.

[roopakv]

@bcmills we spin up ~14 containers and shard our packages across these containers. Since the containers are brand new, there is no cache at this point. granted that between packages go test might do caching, but that doesnt seem to help too much

Also i tried running go test -i and go build ./... before to see fi that sped up anything, but it looks like it didnt.

@ALTree as an example.
time go test package/name/here
gives us

services/api/processing/cart (26.526s)

DONE 1 tests in 58.690s
real	0m58.739s
user	1m9.086s
sys	0m22.096s

this means that compiling took 32 seconds, while testing took 26. in some cases we even have compiling taking ~20 seconds and tests taking ~100ms.

This really skews our sharding.

with our 14 containers, we seem to have some that finish in ~2 minutes while others go up to ~6 minutes

[ALTree]

Ah, I see. Thanks. These are certainly some extreme examples.

[beoran]

Why not simply compile your tests first using time go test -c -o test_binary? Then you could even move the compiled test binaries and distribute them over worker nodes as is necessary.

[roopakv]

@beoran i might be missing something, but if i build the test binary once, go test still seems to recompile. if you are suggesting running the test binary, how do i run only some packages? Also can I build a test binary for only some packages or am i forced to build one for all packages?

@bradfitz was also looking at sharding tests, dunno how far he got.

[beoran]

Yes, AFAIK go test will always recompile the test binary. If you don't want that, then you'll need a build sustem such as a makefile or Basel to only build when the sources have been updated. If you use go test to compile test executables, then you will obtain a test binary per package. I would use something like cd <package_dir> ; time go test -c -o test_<package_name> for every package I want to build a test executable for. Like that you can build a binary only for some packages and selectively run the binaries of only a few packages as well.

[bcmills]

AFAIK go test will always recompile the test binary

To expand on that: in normal operation, go test does not need to run the test if its inputs have not changed, because the test result and output is itself already cached.

Since the only time we need to run the test is when the inputs have changed, there isn't much point in caching the resulting binary: it won't be run again until it needs to be rebuilt again anyway.

[roopakv]

@beoran so it seems like irrespective of building binaries, if this time was reported by go test sharding would be a breeze. If i manually had to record build times and add them to the junit reports, it becomes a fragile process which is sort of hard to implement.

[roopakv]

A sample of what is causing my woes. Since i only have the time reported by go test, i shard based on that, but in reality build time is what is killing me

[bcmills]

@roopakv, if a shard can contain more than one package, the build time is going to be nonlinear anyway (but still monotonic) — and that's true for any compiled language, not just Go.

If you want high-precision sharding, fundamentally you'll either need a very deep graph analysis (perhaps using the unstable -debug-actiongraph flag) or a feedback-based controller.

[roopakv]

@bcmills So i think im missing something.

but say that gotest reported time per package including build instead of just time per run. My sharding would work perfectly. I sort of simulated this in a hacky manner to test, by simply finding the build time per package and adding it to the test run time and the sharding was great. Except i dont want to productionize my hack. I think it might be beneficial to get it into go test.

LMK what i am missing

[bcmills]

@roopakv, the go command can only report timings for things that it actually did. When it builds a test, it starts by building all of the transitive dependencies of that test (in parallel), and those transitive dependencies may be shared with other packages that other tests also depend on.

So the best it could do would be to report how long it took to build each individual dependency, but that still doesn't tell you how long it would take to build any given set of tests starting from scratch, because it doesn't tell you how much their dependencies overlap, or how much each dependency slows the builds for the others executed in parallel.

[roopakv]

@bcmills I guess that is fair!

So i tried adding go build ./... on each shard to build all packages, this way the tests are building only themselves and not the non test packages(right?).

even if I can get that time it would be helpful.

Also when running go test pkg/a am i right that only the test package is recompiled and not all the transitive depenencies?

[bcmills]

So i tried adding go build ./... on each shard to build all packages, this way the tests are building only themselves and not the non test packages(right?).

Not necessarily: the tests may import packages that are not needed by the non-test package variants. go test -c is probably a more reliable way to build the dependencies of the test.

[bcmills]

when running go test pkg/a am i right that only the test package is recompiled and not all the transitive depenencies?

Correct. In fact, most of the cost is typically in the linking phase (after compiling).

[roopakv]

@bcmills I spent a bunch of time looking at build times using -x in go test and go build and you are right, the cost is in linking.

It sort of seems like our project has MANY packages, and even though the builds are cached, linking takes its own sweet time which means that that this is the biggest time sync. Is there any way that we can improve the time take to link?

[ianlancetaylor]

There is active work to speed up linking time. I'm not aware of any specific steps you can take.

[bcmills]

There is active work to speed up linking time.

See in particular #32094, #14624, #12259, and https://golang.org/s/better-linker.

[bcmills]

Given #33527 (comment), I don't think it is feasible to report a meaningful “compile time” for tests, and one that is less meaningful does not seem worth the complexity to implement.

We could potentially report the final link time per test, but that also depends on factors like the load on the machine, and at any rate you can already approximate that pretty well using go build […] && time go test -c […].

For sharding, probably your best bet is to use some sort of more sophisticated feedback-driven controller, or a system explicitly designed for distributed incremental builds.