On Tue, Oct 27, 2020 at 10:30 AM Craig Silverstein <csilv...@khanacademy.org> wrote: > > Thanks Ian, that was very helpful. > > It looks like ~50% of the time difference is due to `go vet` calls. I didn't > explore that any further we don't need a vet-run for our use case; I just > disabled it. > > According to my analysis of the `/usr/bin/time` output, the rest of the time > difference is entirely due to linking. (I was also able to confirm that > running the tests one at a time didn't cause any extra compiling to be done, > so that was already a useful result.) Here is a sample of the difference: > > -- AS PART OF `go test [flags] ./pkg/...`: > /usr/bin/time /usr/local/go/pkg/tool/linux_amd64/link -o $WORK/b674/web.test > -importcfg $WORK/b674/importcfg.link -s -w -buildmode=exe > -buildid=xlo1rhZ4fSqnq2f0090T/zrKinvuitz15kdis6cgV/TiXPK6tw8c4z-r2XpAzE/xlo1rhZ4fSqnq2f0090T > -extld=gcc > /home/csilvers/.cache/go-build/04/042d0fef4f6befffaefb8b14240f8d40a40632e7cc3157ae895ab0800369c448-d > 0.56user 0.07system 0:00.59elapsed 108%CPU (0avgtext+0avgdata > 161812maxresident)k > > -- AS PART OF `go test [flags] ./pkg/web`: > /usr/bin/time /usr/local/go/pkg/tool/linux_amd64/link -o $WORK/b001/web.test > -importcfg $WORK/b001/importcfg.link -s -w -buildmode=exe > -buildid=xlo1rhZ4fSqnq2f0090T/zrKinvuitz15kdis6cgV/TiXPK6tw8c4z-r2XpAzE/xlo1rhZ4fSqnq2f0090T > -extld=gcc > /home/csilvers/.cache/go-build/04/042d0fef4f6befffaefb8b14240f8d40a40632e7cc3157ae895ab0800369c448-d > 2.69user 0.20system 0:03.29elapsed 88%CPU (0avgtext+0avgdata > 535280maxresident)k > > The commands are identical, well with the possible exception of the contents > of importcfg.link, but when I examined them they looked identical as well. > > The main difference is user-time, and I don't know how to get more insight > into that. I tried using `ltrace`, but the linker doesn't have the symbol > tables it needs. > > I did run with `-toolexec=strace -f -c`, and it indicated that the > time-difference is due to `futex` calls: between them, the 32 linker calls > (for the 32 packages) spent 12.5 seconds in futex() for the ./pkg/... run, > and 20 seconds in futex() for the individual-package runs. This accounts for > almost all the difference in the test-run times. I don't know what to make > of that though.
The linker is definitely slow, though it got faster in 1.15 and will get faster again in the future 1.16 (I don't know which version you are running). The build cache only applies to object files. Fully linked executables are not cached. Or, more precisely, they are not put into the build cache. If you run "go build -o x PKG" for some main package PKG, and x already exists, and is fully up to date, then it will not be relinked. But test binaries are not normally saved anywhere. That said, I don't know if this will help for your use case, but you can use "go test -c PKG" to build the test binary for PKG. Then you can just run the resulting PKG.test file directly to run the tests. But if you want to distribute the test building time as well as the test running time, that may not help. But it might help to save the test binaries across runs, and use "go test -c -o saved-test". Ian > On Monday, October 26, 2020 at 10:04:27 PM UTC-7 Ian Lance Taylor wrote: >> >> On Mon, Oct 26, 2020 at 8:46 AM Craig Silverstein >> <csil...@khanacademy.org> wrote: >> > >> > > You realize that the flag "-count 1" disable the cache, right? >> > >> > Well, it disables *a* cache. The docs don't make it clear, but it >> > seems like it only disables the test-cache. I don't see why it would >> > affect the build caches -- build time being my theory as to why the >> > tests are slower. But maybe it does? Or maybe the extra time isn't >> > being spent in building after all. >> >> Hi Craig. >> >> That's correct: -count 1 disables the test cache but not the build >> cache. But it does take some time to check all the source files and >> verify that the build cache is correct. Also, you can use "go test >> -x" to see the commands that it is running. Perhaps the build cache >> is being invoked after all. If there are commands being run, you can >> get some idea of how long they take by using "go test >> -toolexec=/usr/bin/time -x". >> >> Ian > > -- > You received this message because you are subscribed to the Google Groups > "golang-nuts" group. > To unsubscribe from this group and stop receiving emails from it, send an > email to golang-nuts+unsubscr...@googlegroups.com. > To view this discussion on the web visit > https://groups.google.com/d/msgid/golang-nuts/69498b58-7907-48ab-b721-4790db8f983bn%40googlegroups.com. -- You received this message because you are subscribed to the Google Groups "golang-nuts" group. To unsubscribe from this group and stop receiving emails from it, send an email to golang-nuts+unsubscr...@googlegroups.com. To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/CAOyqgcWAYMRt_4reftuVnT%2BU8wwSJae-rnRpu72-oe3syyvzew%40mail.gmail.com.
