cmd/compile: fixedbug/issue10958.go failures

[ALTree]

The fixedbug/issue10958.go test, introduced in 7f1ff65 ( cmd/compile: insert scheduling checks on loop backedges), is flaky.

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

go version devel +7f1ff65 Mon Jan 9 21:01:29 2017 +0000 linux/amd64

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

GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="XXX/gocode"
GORACE=""
GOROOT="XXX/go1.7/go"
GOTOOLDIR="XXX/go1.7/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build124360425=/tmp/go-build"
CXX="g++"
CGO_ENABLED="1"
PKG_CONFIG="pkg-config"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"

What did you do?

Ran all.bash 3 times on a CentOS 6.5 server.

What did you see?

It failed reliably with:

##### ../test
# go run run.go -- fixedbugs/issue10958.go
signal: killed

It happened on the linux/mips64 builder too:

https://build.golang.org/log/3f4be6b0c792fd179683d0046a2e6f178f8928d2

[gopherbot]

CL https://golang.org/cl/35051 mentions this issue.

[dr2chase]

Can you try upping the timeout in that test? See https://go-review.googlesource.com/35051 for an example:

--- a/test/fixedbugs/issue10958.go
+++ b/test/fixedbugs/issue10958.go
@@ -1,5 +1,5 @@
 // +build !nacl
-// buildrun -t 2  -gcflags=-d=ssa/insert_resched_checks/on,ssa/check/on
+// buildrun -t 10  -gcflags=-d=ssa/insert_resched_checks/on,ssa/check/on
 
 // Copyright 2016 The Go Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style

I figure I get one try at not-flaky, if it fails, we yank the test.

[ALTree]

Do I have to launch the test via all.bash or running go run issue10958.go is enough?

Because if I go run it I hangs forever (there's a data race in the code, is that normal?).

[dr2chase]

In test directory go run run.go -- fixedbugs/issue10958.go.
Standalone, go run -gcflags -d=ssa/insert_resched_checks/on issue10958.go
I should add a test comment explaining that it is normally expected to hang.

The data race is more or less required -- the threads have to enter their actually-but-not-obviously infinite loops, and those loops cannot contain calls. The test is whether the compiler is properly inserting rescheduling checks into those loops, and if they have the intended effect.

[ALTree]

1. I patched the file bumping to 10s and ran all.bash and it still failed (same error)

2. $ go run run.go -- fixedbugs/issue10958.go in test gives:

# go run run.go -- fixedbugs/issue10958.go
exit status 2
# command-line-arguments
compile: Did not find a phase matching insert_resched_checks in -d=ssa/... debug option

3. go run -gcflags -d=ssa/insert_resched_checks/on issue10958.go in test/fixedbugs gives

# command-line-arguments
compile: Did not find a phase matching insert_resched_checks in -d=ssa/... debug option

[dr2chase]

That message is from an "old" compiler. There's a new phase in the one paired with that test, and the phase is present whether GOEXPERIMENT is set or not.

[ALTree]

Yeah sorry I set a bad GOROOT while trying.

go run run.go -- fixedbugs/issue10958.go never fails (not even with 2s).

Still seeing failures with all.bash and 10s.

[dr2chase]

Too much concurrency in all.bash, perhaps? Thanks for checking this.

[ALTree]

Ok. I'll let you decide what to do with this issue. all.bash has always been quite slow on that machine (not sure why) so maybe it's not worth yanking the test... or maybe we could wait to see how frequent the flake is.

[dr2chase]

It's worth disabling. It's only for an experiment, and flaky tests are vile.

[aclements]

A few thoughts:

You should be able to reproduce it with just go run run.go from the test directory, which runs everything in there with full concurrency, but doesn't require the full all.bash. If that succeeds, then something is weird about the all.bash environment.

If you run with GOTRACEBACK=crash and send it a SIGQUIT before it times out (maybe increase the timeout to something really high), the traceback may be useful.

[ALTree]

Thanks for the suggestion.

go run run.go fails (after a while), as expected:

$ gotip run run.go

# go run run.go -- fixedbugs/issue10958.go
signal: killed

FAIL	fixedbugs/issue10958.go	2.005s

In the meantime, another CL was merged, the builders tested it and two failed on this test:

freebsd/arm: https://build.golang.org/log/02cb9ac66d2d9a19feb6fb479917e709a50850d5
linux/mips: https://build.golang.org/log/9f3e8129e95710b42ac5528f523bfbcaf171a5f1

so yeah, it's really flaky.

[ALTree]

With a really high timeout (I tried 600) it does not fail, so I guess the machine is just choking a little on that test. It has been disabled now so we're fine.

[rsc]

@ALTree can you say more about the machine? Is it a VM? Hardware? Software? How many cores? What is GOMAXPROCS? Are there other things running on the machine?

It's possible the OS descheduled a thread for 10 seconds but that seems like a long time.

[ALTree]

Just to confirm that the timeout was correctly set to 10, I tried again (with all.bash):

##### ../test
# go run run.go -- fixedbugs/issue10958.go
signal: killed

FAIL	fixedbugs/issue10958.go	10.025s

(note 10.025s at the end).

No VM, it's real hardware. The machine is an old NeXtScale cluster (we'll dismiss it during 2017 I believe). OS is CentOS 6.5, uname -a says

Linux nodeXXX 2.6.32-431.el6.x86_64 #1 SMP x86_64 GNU/Linux

There are many nodes, and each node has 2 x Intel Xeon E5-2670v2 2.50 GHz and 128 GB ram, but the resources that I'm requesting to the jobs manager are select=1:ncpus=8:mem=32gb (8 cores, 32 gb ram, all on the same node).

Maybe what's happening is that all.bash sees the hardware of the whole node, and it spawns many threads (20? 40?), which are then pinned to the 8 cores I requested, chocking them a little.

What is GOMAXPROCS?

Not set.

Are there other things running on the machine?

Possibly. Since I've only requested about half a node, if another user asks for just a few cores the job manager could assign the job to the same node. The 8 cores I requested are mine though (and they're guaranteed).

[rsc]

I think all we need to do here is increase the timeout, for Go 1.9.

[dr2chase]

I modified the test (and the rescheduling code also) in this CL, it may work better now: https://go-review.googlesource.com/c/36206/

[alexbrainman]

Seen on our openbsd-amd64 builder https://build.golang.org/log/86fd5a7f6d52845eeecce77a39bb5e799ebf2b6a

Alex

[bradfitz]

The last four openbsd-386 builds all failed with this too.

I'm going to disable the test.

[gopherbot]

CL https://golang.org/cl/40651 mentions this issue.

[gopherbot]

CL https://golang.org/cl/42431 mentions this issue.

[dr2chase]

Moved to 1.12, the test will likely change or be obsoleted when we add signal-based preemption.

[randall77]

Punting to 1.13, we aren't going to do anything for this cycle.