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

os/exec, syscall, runtime: hung system call starting process on OS X 10.8 #17033

Closed
bradfitz opened this issue Sep 8, 2016 · 2 comments
Closed

os/exec, syscall, runtime: hung system call starting process on OS X 10.8 #17033

bradfitz opened this issue Sep 8, 2016 · 2 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. OS-Darwin
Milestone
Unplanned

Comments

@bradfitz
Copy link
Contributor

bradfitz commented Sep 8, 2016

I just noticed an OS X 10.8 builder hung.

The root cause was the builder was stuck in a system call trying to start a child process.

Look at goroutine 511, which is what's blocking the other one:

goroutine 511 [syscall, 387 minutes]:
syscall.Syscall(0x3, 0x8, 0x42166db50, 0x8, 0x0, 0x0, 0x0)
    /home/bradfitz/go/src/syscall/asm_darwin_amd64.s:16 +0x5
syscall.readlen(0x8, 0x42166db50, 0x8, 0x2, 0x421796000, 0x18)
    /home/bradfitz/go/src/syscall/zsyscall_darwin_amd64.go:1393 +0x56
syscall.forkExec(0x420838010, 0xd, 0x420838000, 0x1, 0x1, 0x42166dce0, 0x1ffffffffffffff, 0x2ff875, 0x42179a680)
    /home/bradfitz/go/src/syscall/exec_unix.go:202 +0x33e
syscall.StartProcess(0x420838010, 0xd, 0x420838000, 0x1, 0x1, 0x42166dce0, 0x2, 0x4, 0x5c620, 0x4204e04c0)
    /home/bradfitz/go/src/syscall/exec_unix.go:240 +0x64
os.startProcess(0x420838010, 0xd, 0x420838000, 0x1, 0x1, 0x42166de88, 0x42171a000, 0x17, 0x17)
    /home/bradfitz/go/src/os/exec_posix.go:45 +0x1a3
os.StartProcess(0x420838010, 0xd, 0x420838000, 0x1, 0x1, 0x42166de88, 0x0, 0x0, 0x42166de28)
    /home/bradfitz/go/src/os/exec.go:94 +0x64
os/exec.(*Cmd).Start(0x4204dc420, 0x420838001, 0x4205421e0)
    /home/bradfitz/go/src/os/exec/exec.go:358 +0x3ce
os/exec.(*Cmd).Run(0x4204dc420, 0x4205421e0, 0x0)
    /home/bradfitz/go/src/os/exec/exec.go:276 +0x2b
golang.org/x/build/pargzip.(*writeChunk).compress(0x42054a000, 0x0, 0x0)
    /home/bradfitz/src/golang.org/x/build/pargzip/pargzip.go:81 +0x1c5
created by golang.org/x/build/pargzip.(*Writer).startChunk
    /home/bradfitz/src/golang.org/x/build/pargzip/pargzip.go:141 +0x16b

Where asm_darwin_amd64.s:16 is in the call to runtime·entersyscall:

//                                                                                                                             
// System call support for AMD64, Darwin                                                                                       
//                                                                                                                             

// Trap # in AX, args in DI SI DX, return in AX DX                                                                             

// func Syscall(trap, a1, a2, a3 uintptr) (r1, r2 uintptr, err Errno);                                                         
TEXT    ·Syscall(SB),NOSPLIT,$0-56
        CALL    runtime·entersyscall(SB)  // <==================== LINE 16                                                                           
        MOVQ    a1+8(FP), DI
        MOVQ    a2+16(FP), SI
        MOVQ    a3+24(FP), DX
        MOVQ    $0, R10
        MOVQ    $0, R8
        MOVQ    $0, R9
        MOVQ    trap+0(FP), AX  // syscall entry                                                                               
        ADDQ    $0x2000000, AX
        SYSCALL
        JCC     ok
        MOVQ    $-1, r1+32(FP)
        MOVQ    $0, r2+40(FP)
        MOVQ    AX, err+48(FP)
        CALL    runtime·exitsyscall(SB)
        RET
ok:
        MOVQ    AX, r1+32(FP)
        MOVQ    DX, r2+40(FP)
        MOVQ    $0, err+48(FP)
        CALL    runtime·exitsyscall(SB)
        RET

And the system call it's doing is from:

        // Read child error status from pipe.                                                                                  
        Close(p[1])
        n, err = readlen(p[0], (*byte)(unsafe.Pointer(&err1)), int(unsafe.Sizeof(err1)))
        Close(p[0])

Which is:

func readlen(fd int, p *byte, np int) (n int, err error) {
        r0, _, e1 := Syscall(SYS_READ, uintptr(fd), uintptr(unsafe.Pointer(p)), uintptr(np))
        n = int(r0)
        if e1 != 0 {
                err = errnoErr(e1)
        }
        return
}

Full SIGQUIT output:

kmr0000gn/T/workdir/go/src
2016/09/08 09:34:01 [0x420539600] Run = ok, after 1m14.526362819s
2016/09/08 09:34:01 Removing go/doc/gopher
2016/09/08 09:34:01 Removing go/pkg/bootstrap
^\SIGQUIT: quit
PC=0x65c6b m=0

goroutine 0 [idle]:
runtime.mach_semaphore_wait(0x207, 0x580000000e, 0x0, 0x0, 0x16ae97, 0x456100, 0x7fff5fbff9e8, 0x5c4b3, 0xffffffffffffffff, 0x0, ...)
    /home/bradfitz/go/src/runtime/sys_darwin_amd64.s:418 +0xb
runtime.semasleep1(0xffffffffffffffff, 0x0)
    /home/bradfitz/go/src/runtime/os_darwin.go:435 +0x4b
runtime.semasleep.func1()
    /home/bradfitz/go/src/runtime/os_darwin.go:451 +0x33
runtime.systemstack(0x7fff5fbffa10)
    /home/bradfitz/go/src/runtime/asm_amd64.s:314 +0xab
runtime.semasleep(0xffffffffffffffff, 0x0)
    /home/bradfitz/go/src/runtime/os_darwin.go:452 +0x44
runtime.notesleep(0x456830)
    /home/bradfitz/go/src/runtime/lock_sema.go:166 +0x81
runtime.stopm()
    /home/bradfitz/go/src/runtime/proc.go:1594 +0xad
runtime.findrunnable(0x4204e4000, 0x0)
    /home/bradfitz/go/src/runtime/proc.go:2021 +0x296
runtime.schedule()
    /home/bradfitz/go/src/runtime/proc.go:2120 +0x14c
runtime.goexit0(0x42091fa00)
    /home/bradfitz/go/src/runtime/proc.go:2257 +0x18c
runtime.mcall(0x7fff5fbffbf0)
    /home/bradfitz/go/src/runtime/asm_amd64.s:240 +0x5b

goroutine 1 [chan receive, 379 minutes]:
golang.org/x/build/revdial.(*Listener).Accept(0x42053d880, 0x311d68, 0x420548080, 0x439b80, 0x4204e2090)
    /home/bradfitz/src/golang.org/x/build/revdial/revdial.go:451 +0x5e
net/http.(*Server).Serve(0x4205e4a00, 0x4392c0, 0x42053d880, 0x0, 0x0)
    /home/bradfitz/go/src/net/http/server.go:2273 +0x1ce
main.dialCoordinator(0x2fe30d, 0x3)
    /home/bradfitz/src/golang.org/x/build/cmd/buildlet/reverse.go:140 +0xd7f
main.main()
    /home/bradfitz/src/golang.org/x/build/cmd/buildlet/buildlet.go:175 +0x63b

goroutine 35 [select, 387 minutes]:
golang.org/x/build/pargzip.(*Writer).startChunk(0x42175af50, 0x420672000, 0x100000, 0x100000)
    /home/bradfitz/src/golang.org/x/build/pargzip/pargzip.go:142 +0x23e
golang.org/x/build/pargzip.newChunkWriter.Write(0x42175af50, 0x420672000, 0x100000, 0x0, 0x3, 0x13, 0x4216c0000)
    /home/bradfitz/src/golang.org/x/build/pargzip/pargzip.go:214 +0xa0
bufio.(*Writer).flush(0x42053c900, 0x4216c0000, 0x1a00)
    /home/bradfitz/go/src/bufio/bufio.go:563 +0x75
bufio.(*Writer).Write(0x42053c900, 0x4216c0000, 0x6cde, 0x8000, 0x6cde, 0x0, 0x0)
    /home/bradfitz/go/src/bufio/bufio.go:599 +0xd2
golang.org/x/build/pargzip.(*Writer).Write(0x42175af50, 0x4216c0000, 0x6cde, 0x8000, 0x6cde, 0x0, 0x0)
    /home/bradfitz/src/golang.org/x/build/pargzip/pargzip.go:172 +0x56
archive/tar.(*Writer).Write(0x421764000, 0x4216c0000, 0x6cde, 0x8000, 0x6cde, 0x0, 0x0)
    /home/bradfitz/go/src/archive/tar/writer.go:372 +0x83
io.copyBuffer(0x434600, 0x421764000, 0x4355c0, 0x4204f2350, 0x4216c0000, 0x8000, 0x8000, 0xe99e, 0x42092f5f0, 0x42092f600)
    /home/bradfitz/go/src/io/io.go:392 +0x260
io.Copy(0x434600, 0x421764000, 0x4355c0, 0x4204f2350, 0x0, 0x0, 0x0)
    /home/bradfitz/go/src/io/io.go:360 +0x68
main.handleGetTGZ.func1(0x4205ec420, 0x55, 0x43ae20, 0x4217972b0, 0x0, 0x0, 0x0, 0x0)
    /home/bradfitz/src/golang.org/x/build/cmd/buildlet/buildlet.go:433 +0x342
path/filepath.walk(0x4205ec420, 0x55, 0x43ae20, 0x4217972b0, 0x4205e0cc0, 0x0, 0x0)
    /home/bradfitz/go/src/path/filepath/path.go:351 +0x81
path/filepath.walk(0x420880dc0, 0x4d, 0x43ae20, 0x421797110, 0x4205e0cc0, 0x0, 0x0)
    /home/bradfitz/go/src/path/filepath/path.go:376 +0x344
path/filepath.walk(0x420880c80, 0x48, 0x43ae20, 0x421796a90, 0x4205e0cc0, 0x0, 0x0)
    /home/bradfitz/go/src/path/filepath/path.go:376 +0x344
path/filepath.walk(0x4204e0940, 0x3f, 0x43ae20, 0x4205fe410, 0x4205e0cc0, 0x0, 0x0)
    /home/bradfitz/go/src/path/filepath/path.go:376 +0x344
path/filepath.walk(0x42053c840, 0x3b, 0x43ae20, 0x42171d6c0, 0x4205e0cc0, 0x0, 0x20)
    /home/bradfitz/go/src/path/filepath/path.go:376 +0x344
path/filepath.Walk(0x42053c840, 0x3b, 0x4205e0cc0, 0x42053c840, 0x3b)
    /home/bradfitz/go/src/path/filepath/path.go:398 +0x14c
main.handleGetTGZ(0x439540, 0x42171d5f0, 0x420598b40)
    /home/bradfitz/src/golang.org/x/build/cmd/buildlet/buildlet.go:438 +0x3e5
net/http.HandlerFunc.ServeHTTP(0x311b50, 0x439540, 0x42171d5f0, 0x420598b40)
    /home/bradfitz/go/src/net/http/server.go:1726 +0x44
main.requirePasswordHandler.ServeHTTP(0x436440, 0x311b50, 0x0, 0x0, 0x439540, 0x42171d5f0, 0x420598b40)
    /home/bradfitz/src/golang.org/x/build/cmd/buildlet/buildlet.go:1126 +0xe0
main.(*requirePasswordHandler).ServeHTTP(0x4204de980, 0x439540, 0x42171d5f0, 0x420598b40)
    <autogenerated>:25 +0x8b
net/http.(*ServeMux).ServeHTTP(0x455740, 0x439540, 0x42171d5f0, 0x420598b40)
    /home/bradfitz/go/src/net/http/server.go:2022 +0x7f
net/http.serverHandler.ServeHTTP(0x4205e4a00, 0x439540, 0x42171d5f0, 0x420598b40)
    /home/bradfitz/go/src/net/http/server.go:2202 +0x7d
net/http.(*conn).serve(0x4205e4400, 0x439ac0, 0x42053c340)
    /home/bradfitz/go/src/net/http/server.go:1579 +0x4b7
created by net/http.(*Server).Serve
    /home/bradfitz/go/src/net/http/server.go:2293 +0x44d

goroutine 37 [chan receive, 387 minutes]:
golang.org/x/build/pargzip.(*Writer).writeCompressedChunk(0x42175af50, 0x42054a000, 0x0, 0x0)
    /home/bradfitz/src/golang.org/x/build/pargzip/pargzip.go:160 +0x97
golang.org/x/build/pargzip.(*Writer).init.func1(0x42175af50)
    /home/bradfitz/src/golang.org/x/build/pargzip/pargzip.go:126 +0xaf
created by golang.org/x/build/pargzip.(*Writer).init
    /home/bradfitz/src/golang.org/x/build/pargzip/pargzip.go:131 +0x109

goroutine 16 [IO wait]:
net.runtime_pollWait(0x84206d2dd0, 0x72, 0x3)
    /home/bradfitz/go/src/runtime/netpoll.go:160 +0x59
net.(*pollDesc).wait(0x420516220, 0x72, 0x436f00, 0x4205240b0)
    /home/bradfitz/go/src/net/fd_poll_runtime.go:75 +0x38
net.(*pollDesc).waitRead(0x420516220, 0x420670000, 0x2000)
    /home/bradfitz/go/src/net/fd_poll_runtime.go:80 +0x34
net.(*netFD).Read(0x4205161c0, 0x420670000, 0x2000, 0x2000, 0x0, 0x436f00, 0x4205240b0)
    /home/bradfitz/go/src/net/fd_unix.go:243 +0x181
net.(*conn).Read(0x4204f2000, 0x420670000, 0x2000, 0x2000, 0x0, 0x0, 0x0)
    /home/bradfitz/go/src/net/net.go:173 +0x70
crypto/tls.(*block).readFromUntil(0x4208ffb90, 0x842053d368, 0x4204f2000, 0x5, 0x4204f2000, 0x0)
    /home/bradfitz/go/src/crypto/tls/conn.go:472 +0x91
crypto/tls.(*Conn).readRecord(0x4208fc000, 0x312317, 0x4208fc100, 0x420524020)
    /home/bradfitz/go/src/crypto/tls/conn.go:574 +0xc4
crypto/tls.(*Conn).Read(0x4208fc000, 0x420871000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /home/bradfitz/go/src/crypto/tls/conn.go:1109 +0x116
bufio.(*Reader).fill(0x42091cde0)
    /home/bradfitz/go/src/bufio/bufio.go:97 +0x10b
bufio.(*Reader).Read(0x42091cde0, 0x420839fe0, 0x7, 0x7, 0x70, 0x42175a000, 0x42054a750)
    /home/bradfitz/go/src/bufio/bufio.go:209 +0x1bc
io.ReadAtLeast(0x434640, 0x42091cde0, 0x420839fe0, 0x7, 0x7, 0x7, 0x0, 0x42054a730, 0x4204de180)
    /home/bradfitz/go/src/io/io.go:307 +0xa4
io.ReadFull(0x434640, 0x42091cde0, 0x420839fe0, 0x7, 0x7, 0x0, 0x0, 0x0)
    /home/bradfitz/go/src/io/io.go:325 +0x58
golang.org/x/build/revdial.readFrames(0x42091cde0, 0x434b80, 0x42053d880, 0x16ae3f, 0x420540200)
    /home/bradfitz/src/golang.org/x/build/revdial/revdial.go:373 +0xb4
golang.org/x/build/revdial.NewListener.func1(0x420839fb0, 0x42053d880)
    /home/bradfitz/src/golang.org/x/build/revdial/revdial.go:417 +0x5c
created by golang.org/x/build/revdial.NewListener
    /home/bradfitz/src/golang.org/x/build/revdial/revdial.go:431 +0x119

goroutine 511 [syscall, 387 minutes]:
syscall.Syscall(0x3, 0x8, 0x42166db50, 0x8, 0x0, 0x0, 0x0)
    /home/bradfitz/go/src/syscall/asm_darwin_amd64.s:16 +0x5
syscall.readlen(0x8, 0x42166db50, 0x8, 0x2, 0x421796000, 0x18)
    /home/bradfitz/go/src/syscall/zsyscall_darwin_amd64.go:1393 +0x56
syscall.forkExec(0x420838010, 0xd, 0x420838000, 0x1, 0x1, 0x42166dce0, 0x1ffffffffffffff, 0x2ff875, 0x42179a680)
    /home/bradfitz/go/src/syscall/exec_unix.go:202 +0x33e
syscall.StartProcess(0x420838010, 0xd, 0x420838000, 0x1, 0x1, 0x42166dce0, 0x2, 0x4, 0x5c620, 0x4204e04c0)
    /home/bradfitz/go/src/syscall/exec_unix.go:240 +0x64
os.startProcess(0x420838010, 0xd, 0x420838000, 0x1, 0x1, 0x42166de88, 0x42171a000, 0x17, 0x17)
    /home/bradfitz/go/src/os/exec_posix.go:45 +0x1a3
os.StartProcess(0x420838010, 0xd, 0x420838000, 0x1, 0x1, 0x42166de88, 0x0, 0x0, 0x42166de28)
    /home/bradfitz/go/src/os/exec.go:94 +0x64
os/exec.(*Cmd).Start(0x4204dc420, 0x420838001, 0x4205421e0)
    /home/bradfitz/go/src/os/exec/exec.go:358 +0x3ce
os/exec.(*Cmd).Run(0x4204dc420, 0x4205421e0, 0x0)
    /home/bradfitz/go/src/os/exec/exec.go:276 +0x2b
golang.org/x/build/pargzip.(*writeChunk).compress(0x42054a000, 0x0, 0x0)
    /home/bradfitz/src/golang.org/x/build/pargzip/pargzip.go:81 +0x1c5
created by golang.org/x/build/pargzip.(*Writer).startChunk
    /home/bradfitz/src/golang.org/x/build/pargzip/pargzip.go:141 +0x16b

goroutine 535 [semacquire]:
sync.runtime_notifyListWait(0x42053c6d0, 0x8d9)
    /home/bradfitz/go/src/runtime/sema.go:267 +0x121
sync.(*Cond).Wait(0x42053c6c0)
    /home/bradfitz/go/src/sync/cond.go:57 +0x80
golang.org/x/build/revdial.(*conn).Read(0x42054a730, 0x42095f000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /home/bradfitz/src/golang.org/x/build/revdial/revdial.go:296 +0xe5
net/http.(*connReader).Read(0x4204de120, 0x42095f000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /home/bradfitz/go/src/net/http/server.go:586 +0x144
bufio.(*Reader).fill(0x420522240)
    /home/bradfitz/go/src/bufio/bufio.go:97 +0x10b
bufio.(*Reader).ReadSlice(0x420522240, 0x42050ba0a, 0x84a6b, 0x4208fc1b0, 0x4205ae810, 0xac, 0x8000)
    /home/bradfitz/go/src/bufio/bufio.go:330 +0xb5
bufio.(*Reader).ReadLine(0x420522240, 0x4217620f0, 0xf0, 0xf0, 0x2f5040, 0x4208fc310, 0x1ee7b2)
    /home/bradfitz/go/src/bufio/bufio.go:359 +0x37
net/textproto.(*Reader).readLineSlice(0x4208fe7b0, 0x42050baa8, 0x42050baa8, 0x1e518, 0xf0, 0x2f5040)
    /home/bradfitz/go/src/net/textproto/reader.go:55 +0x5e
net/textproto.(*Reader).ReadLine(0x4208fe7b0, 0x4217620f0, 0x1000, 0x8f, 0x0)
    /home/bradfitz/go/src/net/textproto/reader.go:36 +0x2f
net/http.readRequest(0x420522240, 0x0, 0x4217620f0, 0x0, 0x0)
    /home/bradfitz/go/src/net/http/request.go:793 +0xa5
net/http.(*conn).readRequest(0x420548080, 0x439ac0, 0x42053c780, 0x0, 0x0, 0x0)
    /home/bradfitz/go/src/net/http/server.go:765 +0x10d
net/http.(*conn).serve(0x420548080, 0x439ac0, 0x42053c780)
    /home/bradfitz/go/src/net/http/server.go:1532 +0x3d3
created by net/http.(*Server).Serve
    /home/bradfitz/go/src/net/http/server.go:2293 +0x44d

rax    0xe
rbx    0x456720
rcx    0x7fff5fbff988
rdx    0x7fff5fbffa10
rdi    0x207
rsi    0xd3
rbp    0x7fff5fbff9c0
rsp    0x7fff5fbff988
r8     0x42091fa00
r9     0x3
r10    0x0
r11    0x246
r12    0x0
r13    0x42091fa00
r14    0x4b140
r15    0x377130
rip    0x65c6b
rflags 0x246
cs     0x7
fs     0x0
gs     0x0

/cc @ianlancetaylor @aclements @cherrymui @josharian
@bradfitz bradfitz added this to the Go1.8 milestone Sep 8, 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 10, 2016
@rsc
Copy link
Contributor

rsc commented Oct 27, 2016

Doubt we are going to fix this. Does anyone run OS X 10.8 anymore?

@rsc rsc modified the milestones: Go1.8Maybe, Go1.8, Unplanned Oct 27, 2016
@tklauser
Copy link
Member

Go 1.10 was the last release supported to run on OS X 10.8, see https://golang.org/doc/go1.10#ports. I think this can be closed.

@golang golang locked and limited conversation to collaborators Nov 13, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. OS-Darwin
Projects
None yet
Milestone
Unplanned
Development

No branches or pull requests
5 participants
@bradfitz @rsc @quentinmit @tklauser @gopherbot