Skip to content
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

Jump to bottom

runtime/race: Tests pass with amd64 but fail with arm64 and ppc64le gohugoio/hugo #35308

Closed
anthonyfok opened this issue Nov 1, 2019 · 4 comments
Closed

runtime/race: Tests pass with amd64 but fail with arm64 and ppc64le gohugoio/hugo #35308

anthonyfok opened this issue Nov 1, 2019 · 4 comments
Labels
FrozenDueToAge WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Milestone
Unplanned

Comments

@anthonyfok
Copy link

While trying to add Travis CI’s new Multi-CPU feature—arm64 build—to Hugo (gohugoio/hugo#6467), I saw that go test -race ./... passes on AMD64, it fails Arm64: not that it detected a race condition, but certain tests are found to FAIL.

Debian’s arm64 porterbox amdahl.debian.org is down, but I was able to see similar failures on Debian’s ppc64le porterbox plummer.debian.org.

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

$ go version
go version go1.12.10 linux/arm64
go version go1.13.1 linux/arm64
go version devel +5b31021525 Fri Nov 1 07:59:09 2019 +0000 linux/arm64
go version go1.13.3 linux/ppc64le

Does this issue reproduce with the latest release?

Yes, it fails with Go 1.14 tip too, see https://travis-ci.org/gohugoio/hugo/jobs/605965543?utm_medium=notification&utm_source=github_status

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

go env Output on arm64 on Travis CI
$ go env
GO111MODULE="on"
GOARCH="arm64"
GOBIN=""
GOCACHE="/home/travis/.cache/go-build"
GOENV="/home/travis/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="arm64"
GOHOSTOS="linux"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/travis/gopath"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org"
GOROOT="/home/travis/.gimme/versions/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/travis/.gimme/versions/go/pkg/tool/linux_arm64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/home/travis/gopath/src/github.com/gohugoio/hugo/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 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build872332584=/tmp/go-build -gno-record-gcc-switches"
go env Output on ppc64le on Debian porterbox
(sid_ppc64el-dchroot)foka@plummer:~$ go env
GO111MODULE="on"
GOARCH="ppc64le"
GOBIN=""
GOCACHE="/home/foka/.cache/go-build"
GOENV="/home/foka/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="ppc64le"
GOHOSTOS="linux"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/foka/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/lib/go-1.13"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/lib/go-1.13/pkg/tool/linux_ppc64le"
GCCGO="gccgo"
GOPPC64="power8"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/dev/null"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build482247064=/tmp/go-build -gno-record-gcc-switches"

What did you do?

On arm64: Run mage -v check where gohugoio/hugo/magefile.go calls go test -race ./... in a Travis CI run.

On ppc64le:

export GO111MODULE=on
go get github.com/gohugoio/hugo
go test -race github.com/gohugoio/hugo/hugolib

What did you expect to see?

All tests pass, just like on amd64.

What did you see instead?

On arm64, from https://travis-ci.org/gohugoio/hugo/jobs/605965543#L515-L524:

--- FAIL: TestPageBundlerSiteRegular (0.01s)
    pagebundler_test.go:97: Build failed: "/work/base/b/my-bundle/index.md:1:1": timed out initializing value. This is most likely a circular loop in a shortcode
    --- FAIL: TestPageBundlerSiteRegular/ugly=true,canonify=false,path=NONE (41.57s)
        testing.go:870: test executed panic(nil) or runtime.Goexit: subtest may have called FailNow on a parent test
    pagebundler_test.go:97: Build failed: "/work/base/b/my-bundle/index.md:1:1": timed out initializing value. This is most likely a circular loop in a shortcode
    --- FAIL: TestPageBundlerSiteRegular/ugly=true,canonify=true,path=NONE (44.51s)
        testing.go:870: test executed panic(nil) or runtime.Goexit: subtest may have called FailNow on a parent test
    pagebundler_test.go:97: Build failed: "/work/base/b/my-bundle/index.md:1:1": timed out initializing value. This is most likely a circular loop in a shortcode
    --- FAIL: TestPageBundlerSiteRegular/ugly=false,canonify=true,path=NONE (47.44s)
        testing.go:870: test executed panic(nil) or runtime.Goexit: subtest may have called FailNow on a parent test

On ppc64le, tested on plummer.debian.org:

(sid_ppc64el-dchroot)foka@plummer:~$ go test -race -run TestPageBundlerSiteRegular github.com/gohugoio/hugo/hugolib
--- FAIL: TestPageBundlerSiteRegular (0.00s)
    pagebundler_test.go:97: Build failed: "/work/base/b/my-bundle/index.md:1:1": timed out initializing value. This is most likely a circular loop in a shortcode
    --- FAIL: TestPageBundlerSiteRegular/ugly=true,canonify=false,path=NONE (49.77s)
        testing.go:864: test executed panic(nil) or runtime.Goexit: subtest may have called FailNow on a parent test
    pagebundler_test.go:97: Build failed: "/work/base/b/my-bundle/index.md:1:1": timed out initializing value. This is most likely a circular loop in a shortcode
    --- FAIL: TestPageBundlerSiteRegular/ugly=true,canonify=true,path=NONE (53.89s)
        testing.go:864: test executed panic(nil) or runtime.Goexit: subtest may have called FailNow on a parent test
    pagebundler_test.go:97: Build failed: "/work/base/b/my-bundle/index.md:1:1": timed out initializing value. This is most likely a circular loop in a shortcode
    --- FAIL: TestPageBundlerSiteRegular/ugly=false,canonify=false,path=/hugo (58.00s)
        testing.go:864: test executed panic(nil) or runtime.Goexit: subtest may have called FailNow on a parent test
    pagebundler_test.go:97: Build failed: "/work/base/b/my-bundle/index.md:1:1": timed out initializing value. This is most likely a circular loop in a shortcode
    --- FAIL: TestPageBundlerSiteRegular/ugly=false,canonify=true,path=NONE (62.14s)
        testing.go:864: test executed panic(nil) or runtime.Goexit: subtest may have called FailNow on a parent test
    pagebundler_test.go:97: Build failed: "/work/base/b/my-bundle/index.md:1:1": timed out initializing value. This is most likely a circular loop in a shortcode
    --- FAIL: TestPageBundlerSiteRegular/ugly=false,canonify=true,path=/hugo (66.42s)
        testing.go:864: test executed panic(nil) or runtime.Goexit: subtest may have called FailNow on a parent test
FAIL
FAIL	github.com/gohugoio/hugo/hugolib	66.555s
FAIL
@anthonyfok anthonyfok mentioned this issue Nov 1, 2019
Merged
@ceseo
Copy link
Contributor

ceseo commented Nov 4, 2019

@laboger FYI

@FiloSottile
Copy link
Contributor

It looks like you are hitting a timeout, and -race and arm64 might happen to be slow enough. Any reason to think this is a compiler or standard library issue? Does the failure go away if you increase the timeout?

@FiloSottile FiloSottile added the WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. label Nov 5, 2019
@FiloSottile FiloSottile added this to the Unplanned milestone Nov 5, 2019
@anthonyfok
Copy link
Author

Thank you so much @FiloSottile. I think you are right, as some days later, I saw this apparent timeout when running the same test on my own amd64 laptop too when it was busy.

I will try to increase the timeout once I manage to find where it is set, and report back once I got the results on arm64 and ppc64le. Thanks again!

anthonyfok added a commit to anthonyfok/hugo that referenced this issue Nov 7, 2019
@anthonyfok
travis: Increase timeout to 30000 for mage -v check
ed1a511 
The default timeout of 15000 millisecond is too short
for go test -race on arm64.

See golang/go#35308
@anthonyfok anthonyfok mentioned this issue Nov 7, 2019
Merged
@anthonyfok
Copy link
Author

I finally found an easy way to increase the timeout. Indeed, doubling the timeout from the default of 15000ms to 30000ms (by setting HUGO_TIMEOUT=30000) for arm64 on Travis CI solves the issue! (45000ms needed for plummer.debian.org). See gohugoio/hugo#6485 for details.

Thanks again for looking into this, and my apologies for the false alarm. I am glad that there is no cross-platform issue with Go’s race detector. :-) Closing this issue.

bep pushed a commit to gohugoio/hugo that referenced this issue Nov 8, 2019
@anthonyfok @bep
travis: Increase timeout to 30000 for mage -v check
cafecca 
The default timeout of 15000 millisecond is too short
for go test -race on arm64.

See golang/go#35308
@golang golang locked and limited conversation to collaborators Nov 7, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Projects
None yet
Milestone
Unplanned
Development

No branches or pull requests
4 participants
@FiloSottile @anthonyfok @ceseo @gopherbot