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: darwin mach error semaphore_wait: 49 #17161

Closed
bradfitz opened this issue Sep 19, 2016 · 12 comments

Comments

Projects
None yet
8 participants
@bradfitz
Copy link
Member

commented Sep 19, 2016

A trybot run failed, unable to build a package on Darwin:

https://go-review.googlesource.com/c/29390/
https://storage.googleapis.com/go-build-log/31a66204/darwin-amd64-10_11_93806cd8.log

ok      crypto/tls  0.991s
ok      crypto/x509 1.191s
ok      database/sql    0.075s
ok      database/sql/driver 0.022s
ok      debug/dwarf 0.031s
ok      debug/elf   0.063s
# testmain
mach error semaphore_wait: 49
fatal error: mach error

runtime stack:
runtime.throw(0x1c96ab, 0xa)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/panic.go:556 +0x95 fp=0xc42003fe20 sp=0xc42003fe00
runtime.macherror(0xc400000031, 0x1ca8e4, 0xe)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/os_darwin.go:241 +0xb7 fp=0xc42003fe40 sp=0xc42003fe20
runtime.semasleep1(0xffffffffffffffff, 0x0)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/os_darwin.go:462 +0x7c fp=0xc42003fe80 sp=0xc42003fe40
runtime.semasleep.func1()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/os_darwin.go:471 +0x33 fp=0xc42003fea8 sp=0xc42003fe80
runtime.systemstack(0xc42003fec0)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/asm_amd64.s:314 +0xab fp=0xc42003feb0 sp=0xc42003fea8
runtime.semasleep(0xffffffffffffffff, 0xc42003ff08)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/os_darwin.go:472 +0x44 fp=0xc42003fee8 sp=0xc42003feb0
runtime.notesleep(0x297e30)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/lock_sema.go:166 +0xb4 fp=0xc42003ff18 sp=0xc42003fee8
runtime.gcMark(0x1475caeb6df2b10b)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgc.go:1598 +0x459 fp=0xc42003ff60 sp=0xc42003ff18
runtime.gcMarkTermination.func1()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgc.go:1186 +0x2d fp=0xc42003ff78 sp=0xc42003ff60
runtime.systemstack(0xc42001f300)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/asm_amd64.s:298 +0x79 fp=0xc42003ff80 sp=0xc42003ff78
runtime.mstart()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/proc.go:1079 fp=0xc42003ff88 sp=0xc42003ff80

goroutine 17 [garbage collection]:
runtime.systemstack_switch()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/asm_amd64.s:252 fp=0xc42002a538 sp=0xc42002a530
runtime.gcMarkTermination()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgc.go:1194 +0x141 fp=0xc42002a728 sp=0xc42002a538
runtime.gcMarkDone()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgc.go:1158 +0x1d8 fp=0xc42002a748 sp=0xc42002a728
runtime.gcBgMarkWorker(0xc42001f300)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgc.go:1505 +0x2d4 fp=0xc42002a7b8 sp=0xc42002a748
runtime.goexit()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/asm_amd64.s:2163 +0x1 fp=0xc42002a7c0 sp=0xc42002a7b8
created by runtime.gcBgMarkStartWorkers
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgc.go:1349 +0x98

goroutine 1 [runnable]:
cmd/link/internal/ld.(*objReader).readInt32(0xc420073590, 0xc421b033e0)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/cmd/link/internal/ld/objfile.go:515 fp=0xc420073158 sp=0xc420073150
cmd/link/internal/ld.(*objReader).readSym(0xc420073590)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/cmd/link/internal/ld/objfile.go:327 +0x3fe fp=0xc420073348 sp=0xc420073158
cmd/link/internal/ld.(*objReader).loadObjFile(0xc420073590)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/cmd/link/internal/ld/objfile.go:223 +0x442 fp=0xc420073508 sp=0xc420073348
cmd/link/internal/ld.LoadObjFile(0xc4204a8000, 0xc4217a73a0, 0xc420eac200, 0x7, 0xfa9de, 0xc4217f92c0, 0x5e)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/cmd/link/internal/ld/objfile.go:162 +0x113 fp=0xc4200736b0 sp=0xc420073508
cmd/link/internal/ld.ldobj(0xc4204a8000, 0xc4217a73a0, 0xc420eac200, 0x7, 0xfaa70, 0xc4217f92c0, 0x5e, 0xc420f2ccc0, 0x56, 0x1, ...)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/cmd/link/internal/ld/lib.go:1309 +0xacc fp=0xc420073950 sp=0xc4200736b0
cmd/link/internal/ld.objfile(0xc4204a8000, 0xc420f2a850)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/cmd/link/internal/ld/lib.go:745 +0x42d fp=0xc420073b90 sp=0xc420073950
cmd/link/internal/ld.(*Link).loadlib(0xc4204a8000)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/cmd/link/internal/ld/lib.go:430 +0x1d8 fp=0xc420073d40 sp=0xc420073b90
cmd/link/internal/ld.Main()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/cmd/link/internal/ld/main.go:182 +0x7e0 fp=0xc420073ec8 sp=0xc420073d40
main.main()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/cmd/link/main.go:55 +0x139 fp=0xc420073f48 sp=0xc420073ec8
runtime.main()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/proc.go:183 +0x1f4 fp=0xc420073fa0 sp=0xc420073f48
runtime.goexit()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/asm_amd64.s:2163 +0x1 fp=0xc420073fa8 sp=0xc420073fa0

goroutine 2 [force gc (idle)]:
runtime.gopark(0x1d55b0, 0x297170, 0x1cac2b, 0xf, 0x1d5414, 0x1)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/proc.go:259 +0x13a fp=0xc42002e748 sp=0xc42002e718
runtime.goparkunlock(0x297170, 0x1cac2b, 0xf, 0xc420000114, 0x1)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/proc.go:265 +0x5e fp=0xc42002e788 sp=0xc42002e748
runtime.forcegchelper()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/proc.go:224 +0x9e fp=0xc42002e7c0 sp=0xc42002e788
runtime.goexit()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/asm_amd64.s:2163 +0x1 fp=0xc42002e7c8 sp=0xc42002e7c0
created by runtime.init.3
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/proc.go:213 +0x35

goroutine 3 [GC sweep wait]:
runtime.gopark(0x1d55b0, 0x297320, 0x1ca29d, 0xd, 0x4c014, 0x1)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/proc.go:259 +0x13a fp=0xc42002ef38 sp=0xc42002ef08
runtime.goparkunlock(0x297320, 0x1ca29d, 0xd, 0x14, 0x1)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/proc.go:265 +0x5e fp=0xc42002ef78 sp=0xc42002ef38
runtime.bgsweep(0xc420056000)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgcsweep.go:79 +0x12e fp=0xc42002efb8 sp=0xc42002ef78
runtime.goexit()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/asm_amd64.s:2163 +0x1 fp=0xc42002efc0 sp=0xc42002efb8
created by runtime.gcenable
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgc.go:204 +0x61

goroutine 4 [finalizer wait]:
runtime.gopark(0x1d55b0, 0x2b58b8, 0x1ca7a2, 0xe, 0x14, 0x1)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/proc.go:259 +0x13a fp=0xc42002f708 sp=0xc42002f6d8
runtime.goparkunlock(0x2b58b8, 0x1ca7a2, 0xe, 0x14, 0x1)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/proc.go:265 +0x5e fp=0xc42002f748 sp=0xc42002f708
runtime.runfinq()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mfinal.go:158 +0xaf fp=0xc42002f7c0 sp=0xc42002f748
runtime.goexit()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/asm_amd64.s:2163 +0x1 fp=0xc42002f7c8 sp=0xc42002f7c0
created by runtime.createfing
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mfinal.go:139 +0x62

goroutine 5 [GC worker (idle)]:
runtime.gopark(0x1d5460, 0xc420010570, 0x1caf10, 0x10, 0x14, 0x0)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/proc.go:259 +0x13a fp=0xc42002ff48 sp=0xc42002ff18
runtime.gcBgMarkWorker(0xc42001e000)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgc.go:1428 +0x108 fp=0xc42002ffb8 sp=0xc42002ff48
runtime.goexit()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/asm_amd64.s:2163 +0x1 fp=0xc42002ffc0 sp=0xc42002ffb8
created by runtime.gcBgMarkStartWorkers
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgc.go:1349 +0x98

goroutine 6 [GC worker (idle)]:
runtime.gopark(0x1d5460, 0xc420010580, 0x1caf10, 0x10, 0x14, 0x0)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/proc.go:259 +0x13a fp=0xc420030748 sp=0xc420030718
runtime.gcBgMarkWorker(0xc420020600)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgc.go:1428 +0x108 fp=0xc4200307b8 sp=0xc420030748
runtime.goexit()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/asm_amd64.s:2163 +0x1 fp=0xc4200307c0 sp=0xc4200307b8
created by runtime.gcBgMarkStartWorkers
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgc.go:1349 +0x98

goroutine 18 [GC worker (idle)]:
runtime.gopark(0x1d5460, 0xc42049c010, 0x1caf10, 0x10, 0x14, 0x0)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/proc.go:259 +0x13a fp=0xc42002af48 sp=0xc42002af18
runtime.gcBgMarkWorker(0xc420021900)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgc.go:1428 +0x108 fp=0xc42002afb8 sp=0xc42002af48
runtime.goexit()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/asm_amd64.s:2163 +0x1 fp=0xc42002afc0 sp=0xc42002afb8
created by runtime.gcBgMarkStartWorkers
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgc.go:1349 +0x98

goroutine 7 [GC worker (idle)]:
runtime.gopark(0x1d5460, 0xc420010590, 0x1caf10, 0x10, 0x14, 0x0)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/proc.go:259 +0x13a fp=0xc420030f48 sp=0xc420030f18
runtime.gcBgMarkWorker(0xc420022c00)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgc.go:1428 +0x108 fp=0xc420030fb8 sp=0xc420030f48
runtime.goexit()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/asm_amd64.s:2163 +0x1 fp=0xc420030fc0 sp=0xc420030fb8
created by runtime.gcBgMarkStartWorkers
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgc.go:1349 +0x98

goroutine 19 [GC worker (idle)]:
runtime.gopark(0x1d5460, 0xc42049c020, 0x1caf10, 0x10, 0x14, 0x0)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/proc.go:259 +0x13a fp=0xc42002b748 sp=0xc42002b718
runtime.gcBgMarkWorker(0xc420024000)
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgc.go:1428 +0x108 fp=0xc42002b7b8 sp=0xc42002b748
runtime.goexit()
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/asm_amd64.s:2163 +0x1 fp=0xc42002b7c0 sp=0xc42002b7b8
created by runtime.gcBgMarkStartWorkers
    /private/var/folders/dx/k53rs1s93538b4x20g46cj_w0000gn/T/workdir/go/src/runtime/mgc.go:1349 +0x98
ok      debug/gosym 0.571s
ok      debug/macho 0.027s
ok      debug/pe    0.031s
ok      debug/plan9obj  0.061s
ok      encoding/ascii85    0.027s
ok      encoding/asn1   0.062s
ok      encoding/base32 0.020s
FAIL    encoding/base64 [build failed]
ok      encoding/binary 0.027s
ok      encoding/csv    0.017s
ok      encoding/gob    0.083s
ok      encoding/hex    0.058s
ok      encoding/json   0.216s
ok      encoding/pem    0.064s
ok      encoding/xml    0.053s
ok      errors  0.088s
ok      expvar  0.016s
2016/09/19 10:52:48 Failed: exit status 2


Error: tests failed: dist test failed: go_test:debug/gosym: exit status 1

@bradfitz bradfitz added this to the Go1.8 milestone Sep 19, 2016

@bradfitz

This comment has been minimized.

Copy link
Member Author

commented Sep 19, 2016

@ianlancetaylor

This comment has been minimized.

Copy link
Contributor

commented Sep 19, 2016

Error 49 is KERN_OPERATION_TIMED_OUT. That error should, of course, be impossible for the case shown in the stack trace, as that case has no time out.

@aclements

This comment has been minimized.

Copy link
Member

commented Sep 19, 2016

Possibly related to #16646, which also shows a semaphore operation with no timeout failing, albeit on Windows.

@aclements

This comment has been minimized.

@bradfitz

This comment has been minimized.

Copy link
Member Author

commented Sep 21, 2016

@rsc

This comment has been minimized.

Copy link
Contributor

commented Oct 25, 2016

On the dashboard runs, this started in late July 2016. These are the dashboard failures (searching back to March):

rev/2016-07-26T05:28:06-ea2376f/darwin-amd64-10_9
rev/2016-07-28T03:03:42-be91515/darwin-amd64-10_9
rev/2016-07-29T01:09:55-111d590/darwin-amd64-10_9
rev/2016-08-04T21:42:44-da070be/darwin-amd64-10_8
rev/2016-08-06T19:30:57-219ca60/darwin-amd64-10_9
rev/2016-08-16T06:20:12-6fd2d2c/darwin-amd64-10_9
rev/2016-08-16T14:12:58-2cbe735/darwin-amd64-10_8
rev/2016-08-16T20:26:16-0cd8faf/darwin-amd64-10_9
rev/2016-08-16T21:32:09-504a104/darwin-amd64-10_8
rev/2016-08-17T20:21:08-ebcd179/darwin-amd64-10_9
rev/2016-08-21T02:04:43-4b17b15/darwin-amd64-10_9
rev/2016-08-23T06:15:35-80b31c0/darwin-amd64-10_8
rev/2016-09-16T01:10:51-e888b81/darwin-amd64-10_11
rev/2016-09-17T00:34:19-a1bf203/darwin-amd64-10_11
rev/2016-09-20T05:11:45-f964810/darwin-amd64-10_11
rev/2016-09-20T18:37:29-39ce6eb/darwin-amd64-10_11
rev/2016-09-21T22:08:45-e613470/darwin-amd64-10_11
rev/2016-09-26T17:22:42-c273503/darwin-amd64-10_11
rev/2016-09-27T16:01:01-a30b5a3/darwin-amd64-10_11
rev/2016-10-03T22:00:06-bf776a9/darwin-amd64-10_10
rev/2016-10-04T03:04:25-cb6bb40/darwin-amd64-10_11
rev/2016-10-04T22:45:01-57ae833/darwin-amd64-10_11
rev/2016-10-05T19:15:02-92b3e36/darwin-amd64-10_10
rev/2016-10-05T19:30:42-cb986de/darwin-amd64-10_11
rev/2016-10-06T18:41:23-b4f3c93/darwin-amd64-10_10
rev/2016-10-07T17:33:15-93d5f43/darwin-amd64-10_11
rev/2016-10-11T16:16:17-88562dc/darwin-amd64-10_8
rev/2016-10-12T17:04:28-8a11cb3/darwin-amd64-10_8
rev/2016-10-13T09:29:57-01bf5cc/darwin-amd64-10_11
rev/2016-10-17T09:02:28-516001f/darwin-amd64-10_11
rev/2016-10-17T15:22:17-237d7e3/darwin-amd64-10_11
rev/2016-10-17T20:01:17-2190f77/darwin-amd64-10_11
rev/2016-10-17T21:33:09-d1bfa3c/darwin-amd64-10_11
rev/2016-10-18T10:50:26-2ecaaf1/darwin-amd64-10_10
rev/2016-10-18T13:27:09-0c12bdf/darwin-amd64-10_10
rev/2016-10-18T20:11:01-8b3194a/darwin-amd64-10_8
rev/2016-10-18T21:53:31-97b0415/darwin-amd64-10_10
rev/2016-10-20T22:27:28-584e3ea/darwin-amd64-10_10
rev/2016-10-21T21:10:18-40d4be5/darwin-amd64-10_11
rev/2016-10-24T15:59:28-39690be/darwin-amd64-10_8

The first commit that failed (ea2376f) had nothing to do with OS X, nor did anything immediately before it.

The first obvious suspect before that commit is ff227b8 (CL 25104) but I can't see that doing anything.

The next obvious suspect is 50048a4 (CL 25047) but again I can't see a problem.

It does seem like there's just an OS X kernel bug here, but I don't know why it only started showing up recently. My comment in the meeting earlier today, that this was a recent Go change that made the code more strict, appears to be wrong. I'm not sure what I was thinking of, but this code is unchanged since the translation to Go in November 2014.

@bradfitz, did something about the OS X builders themselves change in late July?

@bradfitz

This comment has been minimized.

Copy link
Member Author

commented Oct 25, 2016

That might've been when we switched to VMWare-based builders. Can confirm after dinner.

@gopherbot

This comment has been minimized.

Copy link

commented Oct 25, 2016

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

@bradfitz

This comment has been minimized.

Copy link
Member Author

commented Oct 25, 2016

No, the builders didn't switch to VMWare until early September (Sep 6th/7th), with some testing starting Aug 30th.

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.