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

cmd/go: TestScript timing out on Plan 9 #29033

Open
0intro opened this Issue Nov 30, 2018 · 8 comments

Comments

Projects
None yet
6 participants
@0intro
Member

0intro commented Nov 30, 2018

Since CL 146382, which made use of the newly introduced lockedfile package (CL 145178), TestScript is timing out on Plan 9 when running on ramfs filesystem. However, it still works correctly on Fossil filesystem.

go test proxy starting
go test proxy running at GOPROXY=http://127.0.0.1:43585/mod
go proxy: no archive rsc.io v1.5.0
go proxy: no archive example.com/split/subpkg v1.0.0
panic: test timed out after 18m0s

goroutine 3595 [running]:
testing.(*M).startAlarm.func1()
	/tmp/workdir/go/src/testing/testing.go:1331 +0xca
created by time.goFunc
	/tmp/workdir/go/src/time/sleep.go:169 +0x36

goroutine 1 [chan receive, 15 minutes]:
testing.(*T).Run(0x10cd3360, 0x533a98, 0xa, 0x57e5a4, 0x1)
	/tmp/workdir/go/src/testing/testing.go:914 +0x2c7
testing.runTests.func1(0x10cd20a0)
	/tmp/workdir/go/src/testing/testing.go:1154 +0x59
testing.tRunner(0x10cd20a0, 0x10d9bd7c)
	/tmp/workdir/go/src/testing/testing.go:862 +0x95
testing.runTests(0x10c17dc0, 0x964980, 0x10f, 0x10f, 0x766e652f)
	/tmp/workdir/go/src/testing/testing.go:1152 +0x22c
testing.(*M).Run(0x10d50d80, 0x0)
	/tmp/workdir/go/src/testing/testing.go:1069 +0x114
cmd/go_test.TestMain(0x10d50d80)
	/tmp/workdir/go/src/cmd/go/go_test.go:256 +0x34e
main.main()
	_testmain.go:582 +0x108

goroutine 5 [syscall, 17 minutes]:
os/signal.signal_recv(0x0, 0x0)
	/tmp/workdir/go/src/runtime/sigqueue_plan9.go:109 +0x61
os/signal.loop()
	/tmp/workdir/go/src/os/signal/signal_plan9.go:28 +0x19
created by os/signal.init.0
	/tmp/workdir/go/src/os/signal/signal_plan9.go:23 +0x36

FAIL	cmd/go	1090.838s

See https://build.golang.org/log/70abb97c6a26e7bd7ee55570a47589ef5407106a

@0intro 0intro added the OS-Plan9 label Nov 30, 2018

@0intro 0intro added this to the Go1.12 milestone Nov 30, 2018

@0intro 0intro self-assigned this Nov 30, 2018

@0intro 0intro changed the title from cmd/go: StartProxy timing out on Plan 9 to cmd/go: TestScript timing out on Plan 9 Nov 30, 2018

@tklauser

This comment has been minimized.

Member

tklauser commented Nov 30, 2018

Similar (or same) failure can be observed on the aix builder, see https://build.golang.org/log/cc420a1f3eaab84c7d7cfe3d1c8e4d9d40db1b40

/cc @Helflym

@Helflym

This comment has been minimized.

Contributor

Helflym commented Nov 30, 2018

Have you tried with a fresh install fetched from git ? Because, it doesn't happen with it on aix. Only the builder triggers this timeout. So, it might be related to the builder environment which is a different bug.

However, I have noticed that a "sleep 86400" process remains for every build. These should be killed by "cmd/go/testdata/script/script_wait.txt". This timeout might be related to this test. Do you have the same on Plan9 ?

@0intro

This comment has been minimized.

Member

0intro commented Nov 30, 2018

The issue is different on Plan 9.

When running TestScript on ramfs, sometimes the lock file previously opened with exclusive mode remains open, even after a successful close, so the program is stuck in the waiting lock loop.

stat /tmp/cmd-go-test-894260621/script-mod_upgrade_patch/gopath/pkg/mod/cache/download/rsc.io/quote/@v/list.lock
exist /tmp/cmd-go-test-894260621/script-mod_upgrade_patch/gopath/pkg/mod/cache/download/rsc.io/quote/@v/list.lock
open /tmp/cmd-go-test-894260621/script-mod_upgrade_patch/gopath/pkg/mod/cache/download/rsc.io/quote/@v/list.lock
close /tmp/cmd-go-test-894260621/script-mod_upgrade_patch/gopath/pkg/mod/cache/download/rsc.io/quote/@v/list.lock
stat /tmp/cmd-go-test-894260621/script-mod_upgrade_patch/gopath/pkg/mod/cache/download/rsc.io/sampler/@v/list.lock
exist /tmp/cmd-go-test-894260621/script-mod_upgrade_patch/gopath/pkg/mod/cache/download/rsc.io/sampler/@v/list.lock
open /tmp/cmd-go-test-894260621/script-mod_upgrade_patch/gopath/pkg/mod/cache/download/rsc.io/sampler/@v/list.lock
locked open /tmp/cmd-go-test-894260621/script-mod_upgrade_patch/gopath/pkg/mod/cache/download/rsc.io/sampler/@v/list.lock: '.../pkg/mod/cache/download/rsc.io/sampler/@v/list.lock' exclusive use file already open
open /tmp/cmd-go-test-894260621/script-mod_upgrade_patch/gopath/pkg/mod/cache/download/rsc.io/sampler/@v/list.lock
locked open /tmp/cmd-go-test-894260621/script-mod_upgrade_patch/gopath/pkg/mod/cache/download/rsc.io/sampler/@v/list.lock: '.../pkg/mod/cache/download/rsc.io/sampler/@v/list.lock' exclusive use file already open
[...]

It doesn't fail on this specific test, but it fails randomly.

@0intro

This comment has been minimized.

Member

0intro commented Nov 30, 2018

There was an issue in ramfs where the number of open file descriptors wasn't correctly initialized when creating a file. Consequently, a file created with the DMEXCL bit set might not be opened again after close.

I'll submit a new Plan 9 image to be deployed on GCE.

@bcmills

@gopherbot

This comment has been minimized.

gopherbot commented Nov 30, 2018

Change https://golang.org/cl/152037 mentions this issue: env: update Plan 9 image

@bcmills

This comment has been minimized.

Member

bcmills commented Nov 30, 2018

@tklauser, please file a separate issue for aix. The lockedfile implementation for plan9 is completely different from the other platforms.

@bradfitz

This comment has been minimized.

Member

bradfitz commented Dec 3, 2018

@dmitshur, @bcmills: one of you want to deploy this image?

@bcmills

This comment has been minimized.

Member

bcmills commented Dec 3, 2018

I'll do it. I was having some qemu trouble last week but it looks like I got it sorted out.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment