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
Closed

runtime: darwin mach error semaphore_wait: 49 #17161

bradfitz opened this issue Sep 19, 2016 · 12 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone

Comments

@bradfitz
Copy link
Contributor

bradfitz 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
Copy link
Contributor Author

@ianlancetaylor
Copy link
Contributor

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
Copy link
Member

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

@aclements
Copy link
Member

@bradfitz
Copy link
Contributor Author

@mundaym
Copy link
Member

mundaym commented Oct 6, 2016

@quentinmit quentinmit added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Oct 11, 2016
@JayNakrani
Copy link
Contributor

@rsc
Copy link
Contributor

rsc 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
Copy link
Contributor Author

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

@gopherbot
Copy link

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

@bradfitz
Copy link
Contributor Author

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.
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
None yet
Development

No branches or pull requests

8 participants