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

runtime: trybot windows/amd64 failure in gc shade #18867

Closed
rsc opened this issue Jan 31, 2017 · 10 comments

Comments

Projects
None yet
5 participants
@rsc
Copy link
Contributor

commented Jan 31, 2017

This happened in the second trybot run (but not the first, same tree) on my recent CL to merge master into release-branch.go1.8:

https://storage.googleapis.com/go-build-log/d8d2f036/windows-amd64-gce_dc014ee3.log

ok  	net	28.337s
fatal error: unexpected signal during runtime execution
[signal 0xc0000005 code=0x0 addr=0xc041ff85e5 pc=0x41d0c5]

runtime stack:
runtime.throw(0x8a6dd3, 0x2a)
	C:/workdir/go/src/runtime/panic.go:596 +0x9c
runtime.sigpanic()
	C:/workdir/go/src/runtime/signal_windows.go:155 +0x18b
runtime.greyobject(0xc0420f4340, 0x0, 0x0, 0xc041ff85e5, 0xc000000000, 0x24e6e50, 0xc042017828, 0x2)
	C:/workdir/go/src/runtime/mgcmark.go:1399 +0x355
runtime.shade(0xc0420f4340)
	C:/workdir/go/src/runtime/mgcmark.go:1342 +0xcb
runtime.gcmarkwb_m(0xc0420f0090, 0xc0420f4340)
	C:/workdir/go/src/runtime/mbarrier.go:159 +0x7f
runtime.writebarrierptr_prewrite1.func1()
	C:/workdir/go/src/runtime/mbarrier.go:188 +0x6b
runtime.systemstack(0x28afe08)
	C:/workdir/go/src/runtime/asm_amd64.s:343 +0xb5
runtime.writebarrierptr_prewrite1(0xc0420f0090, 0xc0420f4340)
	C:/workdir/go/src/runtime/mbarrier.go:189 +0xcd
runtime.writebarrierptr(0xc0420f0090, 0xc0420f4340)
	C:/workdir/go/src/runtime/mbarrier.go:211 +0x4d
runtime.execute(0xc0420f4340, 0x0)
	C:/workdir/go/src/runtime/proc.go:1876 +0x16e
runtime.schedule()
	C:/workdir/go/src/runtime/proc.go:2239 +0x135
runtime.park_m(0xc0420f4680)
	C:/workdir/go/src/runtime/proc.go:2285 +0xc0
runtime.mcall(0x0)
	C:/workdir/go/src/runtime/asm_amd64.s:269 +0x5e

goroutine 1 [runnable]:
path/filepath.baseIsDotDot(0xc042468502, 0xb, 0x5c)
	C:/workdir/go/src/path/filepath/symlink_windows.go:45 +0xa9
path/filepath.toNorm(0xc042468502, 0xb, 0x8bc940, 0x15, 0x0, 0x0, 0x1)
	C:/workdir/go/src/path/filepath/symlink_windows.go:78 +0x157
path/filepath.evalSymlinks(0xc0421a7960, 0x15, 0x0, 0x0, 0xa60ba0, 0xc04242d740)
	C:/workdir/go/src/path/filepath/symlink_windows.go:114 +0x99
path/filepath.EvalSymlinks(0xc0421a7960, 0x15, 0x0, 0x0, 0xa60ba0, 0xc04242d740)
	C:/workdir/go/src/path/filepath/path.go:227 +0x3c
go/build.(*Context).hasSubdir(0xa98560, 0xc042002ba0, 0x15, 0xc0421a7960, 0x15, 0xc042217f70, 0x0, 0x1)
	C:/workdir/go/src/go/build/build.go:147 +0xd0
go/build.(*Context).Import.func3(0xc042002ba0, 0x15, 0x0, 0x0)
	C:/workdir/go/src/go/build/build.go:589 +0xb3
go/build.(*Context).Import(0xa98560, 0xc04243ec61, 0x15, 0xc0421a7960, 0x15, 0x4, 0xc04205cd80, 0x0, 0x0)
	C:/workdir/go/src/go/build/build.go:619 +0x7169
main.loadImport(0xc04243ec61, 0x15, 0xc0421a7960, 0x15, 0xc04230bb00, 0xc0420a3590, 0xc0422be420, 0x1, 0x1, 0x1, ...)
	C:/workdir/go/src/cmd/go/pkg.go:366 +0xbc7
main.(*Package).load(0xc04230bb00, 0xc0420a3590, 0xc04228d880, 0x0, 0x0, 0x4)
	C:/workdir/go/src/cmd/go/pkg.go:1038 +0x16cb
main.loadImport(0xc0422cddf1, 0x3, 0xc0422c5c20, 0x1d, 0xc042390900, 0xc0420a3590, 0xc04211fe50, 0x2, 0x2, 0x1, ...)
	C:/workdir/go/src/cmd/go/pkg.go:375 +0xc81
main.(*Package).load(0xc042390900, 0xc0420a3590, 0xc04232b180, 0x0, 0x0, 0x4)
	C:/workdir/go/src/cmd/go/pkg.go:1038 +0x16cb
main.loadImport(0xc0423be0f1, 0xb, 0xc042218480, 0x1c, 0xc04232fb00, 0xc0420a3590, 0xc042049e00, 0x7, 0x8, 0x1, ...)
	C:/workdir/go/src/cmd/go/pkg.go:375 +0xc81
main.(*Package).load(0xc04232fb00, 0xc0420a3590, 0xc042029880, 0x0, 0x0, 0x4)
	C:/workdir/go/src/cmd/go/pkg.go:1038 +0x16cb
main.loadImport(0xc04222f901, 0xa, 0xc042101080, 0x1a, 0xc0421f0000, 0xc0420a3590, 0xc04225a8c0, 0x6, 0x8, 0x1, ...)
	C:/workdir/go/src/cmd/go/pkg.go:375 +0xc81
main.(*Package).load(0xc0421f0000, 0xc0420a3590, 0xc0421cc380, 0x0, 0x0, 0xc)
	C:/workdir/go/src/cmd/go/pkg.go:1038 +0x16cb
main.loadImport(0xc0420082f0, 0x8, 0xc042009400, 0xa, 0x0, 0xc0420a3590, 0x0, 0x0, 0x0, 0x0, ...)
	C:/workdir/go/src/cmd/go/pkg.go:375 +0xc81
main.loadPackage(0xc0420082f0, 0x8, 0xc0420a3590, 0x0)
	C:/workdir/go/src/cmd/go/pkg.go:1730 +0x190
main.packagesAndErrors(0xc0420fcc00, 0x1, 0x1, 0xc0420082e1, 0x89590e, 0x867aa0)
	C:/workdir/go/src/cmd/go/pkg.go:1775 +0x33d
main.packagesForBuild(0xc0420fcbd0, 0x1, 0x1, 0xc0420fcbd0, 0x1, 0x1)
	C:/workdir/go/src/cmd/go/pkg.go:1791 +0x61
main.runTest(0xa91720, 0xc04202c090, 0x5, 0x5)
	C:/workdir/go/src/cmd/go/test.go:410 +0x130
main.main()
	C:/workdir/go/src/cmd/go/main.go:184 +0x67e

goroutine 5 [syscall]:
os/signal.signal_recv(0x0)
	C:/workdir/go/src/runtime/sigqueue.go:116 +0x10b
os/signal.loop()
	C:/workdir/go/src/os/signal/signal_unix.go:22 +0x29
created by os/signal.init.1
	C:/workdir/go/src/os/signal/signal_unix.go:28 +0x48
2017/01/31 14:58:46 Failed: exit status 2
Exception 0xc0000005 0x0 0xffffffffffffffff 0x7fefdcb0ccc
PC=0x7fefdcb0ccc

syscall.Syscall(0x779c4120, 0x1, 0x1, 0x0, 0x0, 0xed0229d26, 0xc042050280, 0x15)
	C:/workdir/go/src/runtime/syscall_windows.go:163 +0x6b
syscall.ExitProcess(0x1)
	C:/workdir/go/src/syscall/zsyscall_windows.go:289 +0x68
syscall.Exit(0x1)
	C:/workdir/go/src/syscall/syscall_windows.go:239 +0x31
os.Exit(0x1)
	C:/workdir/go/src/os/proc.go:54 +0x37
log.Fatalf(0x56ebc4, 0xa, 0xc04202baf0, 0x1, 0x1)
	C:/workdir/go/src/log/log.go:309 +0x98
main.(*tester).run(0xc0420841e0)
	C:/workdir/go/src/cmd/dist/test.go:209 +0xd02
main.cmdtest()
	C:/workdir/go/src/cmd/dist/test.go:41 +0x2c2
main.xmain()
	C:/workdir/go/src/cmd/dist/main.go:43 +0x23a
main.main()
	C:/workdir/go/src/cmd/dist/util.go:509 +0x299

goroutine 18 [select]:
main.bghelper()
	C:/workdir/go/src/cmd/dist/util.go:150 +0x16d
created by main.bginit
	C:/workdir/go/src/cmd/dist/util.go:143 +0x6b

goroutine 19 [select]:
main.bghelper()
	C:/workdir/go/src/cmd/dist/util.go:150 +0x16d
created by main.bginit
	C:/workdir/go/src/cmd/dist/util.go:143 +0x6b

goroutine 20 [select]:
main.bghelper()
	C:/workdir/go/src/cmd/dist/util.go:150 +0x16d
created by main.bginit
	C:/workdir/go/src/cmd/dist/util.go:143 +0x6b

goroutine 21 [select]:
main.bghelper()
	C:/workdir/go/src/cmd/dist/util.go:150 +0x16d
created by main.bginit
	C:/workdir/go/src/cmd/dist/util.go:143 +0x6b
rax     0x1f0fffffff73e9
rbx     0x0
rcx     0x7fefdc30000
rdi     0x1
rsi     0x1b6b78
rbp     0x1b6aa0
rsp     0x6fb20
r8      0x1
r9      0xd0082001d
r10     0x2
r11     0x6fb40
r12     0x1
r13     0x7fefdc30000
r14     0x77ad7be0
r15     0x77ad2670
rip     0x7fefdcb0ccc
rflags  0x10202
cs      0x33
fs      0x53
gs      0x2b


Error: tests failed: dist test failed: go_test:net/http: exit status 1

/cc @aclements @RLH

@rsc rsc added this to the Go1.8 milestone Jan 31, 2017

@rsc

This comment has been minimized.

Copy link
Contributor Author

commented Jan 31, 2017

There are two crashes here. The first one crashes accessing the heap bitmap for a goroutine pointer, which should be mapped.

The second is in cmd/dist when it makes a cgo call into the DLL to exit(1) (because the first crash happened). During that DLL call, the DLL itself faults on address -1.

It seems more likely that the machine is sick in some way than that both the net/http test and cmd/dist simultaneously hit memory faults due to problems in Go (unless there was a coordinated external event like a leap second!).

@rsc rsc closed this Jan 31, 2017

@bradfitz

This comment has been minimized.

Copy link
Member

commented Jan 31, 2017

The windows builders are all fresh VMs per build on GCE. No leap seconds.

I don't think this is bad hardware.

@bradfitz bradfitz reopened this Jan 31, 2017

@rsc

This comment has been minimized.

Copy link
Contributor Author

commented Jan 31, 2017

The leap second thing was a joke, but there's no useful information here for further debugging. Still looks like a hardware or OS problem to me. If this happens again we can look harder. Dunno if that state is open or closed.

@rsc rsc modified the milestones: Go1.8Maybe, Go1.8 Jan 31, 2017

@ALTree

This comment has been minimized.

Copy link
Member

commented Jan 31, 2017

I don't know if this is interesting, but Sunday night I started a trybot run and I noticed that there was something wrong with the windows-386-gce and windows-amd64-gce bots. They were super slow (like 20 minutes, all the other bots were done) and then they failed with a gce error message (something like "not enough resources on this zone").

@bradfitz

This comment has been minimized.

Copy link
Member

commented Jan 31, 2017

@ALTree, that's not interesting. That's just the build coordinator not having enough quota to run N VMs at once and giving up waiting. The trybots keep waiting for quota, though, so you'd only see that message if you click through to one of them from its web status page.

@ALTree

This comment has been minimized.

Copy link
Member

commented Jan 31, 2017

@bradfitz ah, thanks for the explanation. Sorry for the noise.

@bradfitz

This comment has been minimized.

Copy link
Member

commented Jan 31, 2017

@aclements, can you grep your collected failure logs for this?

@aclements

This comment has been minimized.

Copy link
Member

commented Jan 31, 2017

I only found one that looks similar, but it's actually from gcw.putFast inlined into greyobject, so it's not the same thing.

$ greplogs -dashboard -E "unexpected signal during runtime execution" -E 'runtime\.sigpanic.*\n.*\nruntime\.greyobject' -md
2016-07-26T14:53:38-8876061/plan9-arm:

# go run run.go -- 64bit.go
exit status: 'go 893206: 2'
fatal error: unexpected signal during runtime execution
[signal sys: trap: fault read code=0x0 addr=0x0 pc=0x8f5ac]

runtime stack:
runtime.throw(0x3f096c, 0x2a)
	/tmp/gobuilder-arm/plan9-arm-887606114902/go/src/runtime/panic.go:566 +0x78
runtime.sigpanic()
	/tmp/gobuilder-arm/plan9-arm-887606114902/go/src/runtime/os_plan9.go:78 +0x40
runtime.greyobject(0x107d5c00, 0x10870340, 0xc, 0xf6eea3f, 0x0, 0x307716c0, 0xfd5e0002, 0x10)
	/tmp/gobuilder-arm/plan9-arm-887606114902/go/src/runtime/mgcmark.go:1242 +0x358
runtime.scanobject(0x10870340, 0xfd5e0002)
	/tmp/gobuilder-arm/plan9-arm-887606114902/go/src/runtime/mgcmark.go:1165 +0x320
runtime.gcDrainN(0x800212, 0x7ac01, 0x200, 0x307bf9e8, 0x8f0f0)
	/tmp/gobuilder-arm/plan9-arm-887606114902/go/src/runtime/mgcmark.go:1053 +0x154
runtime.gcAssistAlloc.func1()
	/tmp/gobuilder-arm/plan9-arm-887606114902/go/src/runtime/mgcmark.go:457 +0x17c
...
@rsc

This comment has been minimized.

Copy link
Contributor Author

commented Feb 7, 2017

Not high enough frequency to worry for Go 1.8.

@rsc rsc modified the milestones: Go1.9Maybe, Go1.8Maybe Feb 7, 2017

@aclements

This comment has been minimized.

Copy link
Member

commented Jul 20, 2017

This has never been observed again on the dashboard. Closing.

@aclements aclements closed this Jul 20, 2017

@golang golang locked and limited conversation to collaborators Jul 20, 2018

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
You can’t perform that action at this time.