test/bench/shootout: shootout tests talke 30 mins on arm when run via go tool dist test shootout

[davecheney]

A few weeks ago they took ~ 1m40

##### ../test/bench/shootout
fasta
reverse-complement
nbody
binary-tree
binary-tree-freelist
fannkuch
fannkuch-parallel
Package libpcre was not found in the pkg-config search path.
Perhaps you should add the directory containing `libpcre.pc'
to the PKG_CONFIG_PATH environment variable
No package 'libpcre' found
regex-dna
regex-dna-parallel
spectral-norm
k-nucleotide
k-nucleotide-parallel
mandelbrot
meteor-contest
pidigits
threadring
chameneosredux
1855.90user 9.83system 30:34.56elapsed 101%CPU (0avgtext+0avgdata 35800maxresident)k
0inputs+71552outputs (0major+209564minor)pagefaults 0swaps

I don't think this is a compiler regression, spectral-norm takes 90% of the time of this test.

/cc @bradfitz

[davecheney]

This is very odd, if I run ./timing.sh -test directly at head it takes ~1m47 as expected.

If I run go tool dist test shootout, it takes ~30mins, but I've verified that the same command is being executed.

  │   ├─bash
  │   │   └─go tool dist test shootout
  │   │       ├─dist test shootout
  │   │       │   ├─time ./timing.sh -test
  │   │       │   │   └─bash ./timing.sh -test
  │   │       │   │       └─a.out
  │   │       │   │           └─{a.out}
  │   │       │   └─{dist}
  │   │       └─{go}

[bradfitz]

What do top and strace say?

[davecheney]

top is spectral norm is taking > 90% of the time

strace on the four threads reveals nothing except for one stuck doing

clock_gettime(CLOCK_REALTIME, {1442538363, 100350778}) = 0
select(0, NULL, NULL, NULL, {0, 10000}) = 0 (Timeout)
clock_gettime(CLOCK_MONOTONIC, {177161, 941332777}) = 0
clock_gettime(CLOCK_REALTIME, {1442538363, 110999147}) = 0
select(0, NULL, NULL, NULL, {0, 10000}) = 0 (Timeout)
clock_gettime(CLOCK_MONOTONIC, {177161, 951986303}) = 0
clock_gettime(CLOCK_REALTIME, {1442538363, 121654183}) = 0
select(0, NULL, NULL, NULL, {0, 10000}^C <unfinished ...>

I'm not sure this is related

[davecheney]

I believe the problem is the first thing ./timing.sh does is run go tool dist env, which returns

pi@raspberrypi ~/go/test/bench/shootout $ go tool dist env
CC="gcc"
CC_FOR_TARGET="gcc"
GOROOT="/home/pi/go"
GOBIN="/home/pi/go/bin"
GOARCH="arm"
GOOS="linux"
GOHOSTARCH="arm"
GOHOSTOS="linux"
GOTOOLDIR="/home/pi/go/pkg/tool/linux_arm"
GOARM="5"

Note GOARM=5, the same setting is not reported using, go env

pi@raspberrypi ~/go/test/bench/shootout $ go env
GOARCH="arm"
GOBIN=""
GOEXE=""
GOHOSTARCH="arm"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/pi"
GORACE=""
GOROOT="/home/pi/go"
GOTOOLDIR="/home/pi/go/pkg/tool/linux_arm"
GO15VENDOREXPERIMENT=""
CC="gcc"
GOGCCFLAGS="-fPIC -marm -pthread -fmessage-length=0"
CXX="g++"
CGO_ENABLED="1"

This must be causing the shootout tests to be compiled for softfloat, blowing out their runtime.

Open questions:

1. why is timing.sh using go tool dist env, rather than go env, this looks like it was made way back in 832dcec
2. is this regression related to 3f2baa3

/cc @minux

[bradfitz]

Related: #12623 is partially about rewriting timing.sh in Go.

[minux]

I think it should be fixed by https://golang.org/cl/14476.

[davecheney]

@minux confirmed this was a regression in 3f2baa3. I'm checking to see if https://go-review.googlesource.com/#/c/14476/ fixed it (it probably did)

[davecheney]

Fixed in 1fd78e1

##### ../test/bench/shootout
fasta
reverse-complement
nbody
binary-tree
binary-tree-freelist
fannkuch
fannkuch-parallel
Package libpcre was not found in the pkg-config search path.
Perhaps you should add the directory containing `libpcre.pc'
to the PKG_CONFIG_PATH environment variable
No package 'libpcre' found
regex-dna
regex-dna-parallel
spectral-norm
k-nucleotide
k-nucleotide-parallel
mandelbrot
meteor-contest
pidigits
threadring
chameneosredux
124.95user 7.46system 1:46.16elapsed 124%CPU (0avgtext+0avgdata 35608maxresident)k
0inputs+70048outputs (0major+209376minor)pagefaults 0swaps