[golang-dev] Re: code review 6903061: cmd/go: ignore some signals during "go run" and "go test" (issue 6903061)

Shows how much I know about signals I guess. Any ideas why, Dave?

At a guess the test process is exiting, but the go tool has lost a reference to it or has stopped waiting for it, and as we've ignored those signals, we can't use them to kill the go tool itself.

I have linux/386. I cannot make it hang. It does everything but hang:

# hg id
8b89b6326704+ tip
# go test net/http
ok net/http 5.946s
# go test net/http
^C# go test net/http
^\# go test net/http
^\SIGQUIT: quit
PC=0xffffe422

created by main.(*builder).do
/root/go/root/src/cmd/go/build.go:632 +0x2dd

goroutine 1 [semacquire]:
sync.runtime_Semacquire(0x18bb8f88, 0x18bb8f88)
/root/go/root/src/pkg/runtime/zsema_linux_386.c:165 +0x32
sync.(*WaitGroup).Wait(0x18c20e80, 0x18bb8ab8)
/root/go/root/src/pkg/sync/waitgroup.go:102 +0xda
main.(*builder).do(0x18ad08c0, 0x18ca3ee0, 0x18ac8160)
/root/go/root/src/cmd/go/build.go:635 +0x2fc
main.runTest(0x84b57c0, 0x18a5f010, 0x1)
/root/go/root/src/cmd/go/test.go:389 +0x19f0
main.main()
/root/go/root/src/cmd/go/main.go:148 +0x38b

goroutine 2 [syscall]:
created by runtime.main
/root/go/root/src/pkg/runtime/proc.c:225

goroutine 3 [syscall]:
os/signal.loop()
/root/go/root/src/pkg/os/signal/signal_unix.go:20 +0x1f
created by os/signal.init·1
/root/go/root/src/pkg/os/signal/signal_unix.go:26 +0x32

goroutine 12 [syscall]:
syscall.Syscall()
/root/go/root/src/pkg/syscall/asm_linux_386.s:20 +0x1f
syscall.read(0x4, 0x18cabc00, 0x200, 0x200, 0x0, ...)
/root/go/root/src/pkg/syscall/zerrors_linux_386.go:2310 +0x5d
syscall.Read(0x4, 0x18cabc00, 0x200, 0x200, 0x8098e46, ...)
/root/go/root/src/pkg/syscall/syscall_unix.go:132 +0x53
os.(*File).read(0x18bc9358, 0x18cabc00, 0x200, 0x200, 0x0, ...)
/root/go/root/src/pkg/os/file_unix.go:174 +0x58
os.(*File).Read(0x18bc9358, 0x18cabc00, 0x200, 0x200, 0x0, ...)
/root/go/root/src/pkg/os/file.go:95 +0x79
bytes.(*Buffer).ReadFrom(0x18aea600, 0x18a5f8c0, 0x18bc9358, 0x0, 0x0,
...)
/root/go/root/src/pkg/bytes/buffer.go:166 +0x196
io.Copy(0x18c20f40, 0x18aea600, 0x18a5f8c0, 0x18bc9358, 0x0, ...)
/root/go/root/src/pkg/io/io.go:357 +0x83
os/exec.func·003(0x18bc92f0, 0x18bc92f8, 0x80c2ff3, 0x82326f4,
0x808d4b6, ...)
/root/go/root/src/pkg/os/exec/exec.go:207 +0x46
os/exec.func·004(0x18bc9278, 0x18b86e40, 0x0)
/root/go/root/src/pkg/os/exec/exec.go:274 +0x23
created by os/exec.(*Cmd).Start
/root/go/root/src/pkg/os/exec/exec.go:275 +0x52e
eax 0x72
ebx 0x157d
ecx 0x18bc94d8
edx 0x0
edi 0x0
esi 0x18caa230
ebp 0x0
esp 0xb759b79c
eip 0xffffe422
eflags 0x282
cs 0x73
fs 0x0
gs 0x33
#

How can I reproduce what you are seeing? Perhaps your net/http test does
not exit on signal, and go waits for it forever?

Alex

https://codereview.appspot.com/6903061/

https://codereview.appspot.com/6903061/diff/13001/src/cmd/go/signal.go
File src/cmd/go/signal.go (right):

https://codereview.appspot.com/6903061/diff/13001/src/cmd/go/signal.go#newcode16
src/cmd/go/signal.go:16: // interrupted returns true, if go process
received signal.
Done.

https://codereview.appspot.com/6903061/

Can you explain your theory in more details, please. I still do not see
why go would be waiting. What would it be waiting for? Thank you.

Alex

https://codereview.appspot.com/6903061/

I have stared plenty at my change. I cannot see any problems.

Dave, I will wait for you to decide what to do. If you have suggestions
about how I can reproduce your problem here, I am happy to listen. Thank
you.

Alex

https://codereview.appspot.com/6903061/

Thank Alex, I'm having a look now. What I see is also a lot of unhandled
signals

ok launchpad.net/juju-core/cert 2.583s
ok launchpad.net/juju-core/charm 0.405s
ok launchpad.net/juju-core/cloudinit 0.011s
ok launchpad.net/juju-core/cmd 0.019s
? launchpad.net/juju-core/cmd/builddb [no test files]
? launchpad.net/juju-core/cmd/charmd [no test files]
? launchpad.net/juju-core/cmd/charmload [no test files]
^Cgo build testmain: signal 2
lucky(~/src/launchpad.net/juju-core) % go test ./...
warning: building out-of-date packages:
launchpad.net/gocheck
launchpad.net/goamz/ec2/ec2test
launchpad.net/goamz/s3/s3test
installing these packages with 'go test -i ./...' will speed future
tests.

ok launchpad.net/juju-core/cert 1.992s
ok launchpad.net/juju-core/charm 0.381s
ok launchpad.net/juju-core/cloudinit 0.013s
ok launchpad.net/juju-core/cmd 0.019s
? launchpad.net/juju-core/cmd/builddb [no test files]
? launchpad.net/juju-core/cmd/charmd [no test files]
? launchpad.net/juju-core/cmd/charmload [no test files]
^\^Cgo build testmain: signal 3 (core dumped)
go build testmain: signal 3 (core dumped)
go build testmain: signal 3 (core dumped)
lucky(~/src/launchpad.net/juju-core) % go test ./...
warning: building out-of-date packages:
launchpad.net/gocheck
launchpad.net/goamz/ec2/ec2test
launchpad.net/goamz/s3/s3test
installing these packages with 'go test -i ./...' will speed future
tests.

ok launchpad.net/juju-core/cert 2.519s
ok launchpad.net/juju-core/charm 0.333s
ok launchpad.net/juju-core/cloudinit 0.013s
ok launchpad.net/juju-core/cmd 0.017s
? launchpad.net/juju-core/cmd/builddb [no test files]
? launchpad.net/juju-core/cmd/charmd [no test files]
? launchpad.net/juju-core/cmd/charmload [no test files]
^Cgo build testmain: signal 2


https://codereview.appspot.com/6903061/

ok, what I see in the simple case (go test go/build) is the go process
waiting on the waitgroup to become ready. Once the ^C hits the test
process it has exited, but the parent process has may have lost track of
it.

^C^\SIGQUIT: quit
PC=0x45bfd3

created by addtimer
/home/dfc/go/src/pkg/runtime/ztime_linux_amd64.c:73

goroutine 1 [semacquire]:
sync.runtime_Semacquire(0xc2001f5c00, 0xc2001f5c00)
/home/dfc/go/src/pkg/runtime/zsema_linux_amd64.c:165 +0x2e
sync.(*WaitGroup).Wait(0xc200165440, 0xc2001f5828)
/home/dfc/go/src/pkg/sync/waitgroup.go:102 +0xf2
main.(*builder).do(0xc2001175b0, 0xc20032d5b0, 0xc20010e580, 0x1)
/home/dfc/go/src/cmd/go/build.go:635 +0x3f0
main.runTest(0x9a9b28, 0xc20009e020, 0x2, 0x2)
/home/dfc/go/src/cmd/go/test.go:389 +0x1e8c
main.main()
/home/dfc/go/src/cmd/go/main.go:148 +0x490

goroutine 2 [syscall]:
created by runtime.main
/home/dfc/go/src/pkg/runtime/proc.c:225

goroutine 3 [syscall]:
os/signal.loop()
/home/dfc/go/src/pkg/os/signal/signal_unix.go:20 +0x1c
created by os/signal.init·1
/home/dfc/go/src/pkg/os/signal/signal_unix.go:26 +0x2f

goroutine 6 [chan receive]:
main.func·005(0xc200165440, 0xc2001f5828, 0xc2001f5bf8, 0x0, 0x0, ...)
/home/dfc/go/src/cmd/go/build.go:615 +0x5b
created by main.(*builder).do
/home/dfc/go/src/cmd/go/build.go:632 +0x3c6

goroutine 8 [chan receive]:
main.func·005(0xc200165440, 0xc2001f5828, 0xc2001f5bf8, 0x0, 0x0, ...)
/home/dfc/go/src/cmd/go/build.go:615 +0x5b
created by main.(*builder).do
/home/dfc/go/src/cmd/go/build.go:632 +0x3c6

goroutine 17 [chan receive]:
main.func·024(0xc2000fc260, 0x0)
/home/dfc/go/src/cmd/go/signal.go:26 +0x3b
created by main.ignoreSignals
/home/dfc/go/src/cmd/go/signal.go:29 +0x99
rax 0xfffffffffffffffc
rbx 0xc2000d58b8
rcx 0xffffffffffffffff
rdx 0x0
rdi 0x9aff48
rsi 0x0
rbp 0xc2001d3d08
rsp 0x7f43a093deb8
r8 0x0
r9 0x0
r10 0x7f43a093df00
r11 0x283
r12 0x7895b0
r13 0x2
r14 0x0
r15 0x2
rip 0x45bfd3
rflags 0x283
cs 0x33
fs 0x0
gs 0x0


https://codereview.appspot.com/6903061/

Hi Alex, please consider this alternative.
https://codereview.appspot.com/6943043

I believe the problem is because my host has 4 cores, there were several
workers blocked waiting on the readSema to close, which blocked the main
goroutine.

https://codereview.appspot.com/6903061/

goroutine.

I can see where the problem is. Your fix looks ok to me. Do you want to
use your CL or should I change mine?

Alex

https://codereview.appspot.com/6903061/

You've done the hard work on this CL, you should take the credit. I
think just integrate the two files from 6943043 and hg mail.