code review 6903061: cmd/go: handle os signals

cmd/go: handle os signals

Ignore signals during "go run" and wait for running child
process to exit. Stop executing further tests during "go test",
wait for running tests to exit and report error exit code.

Original CL 6351053 by dfc.

Fixes issue 3572.
Fixes issue 3581.

[brainman, 2012-12-10 02:00:19]

Hello golang-dev@googlegroups.com (cc: dave@cheney.net),

I'd like you to review this change to
https://go.googlecode.com/hg/

[dave_cheney.net, 2012-12-10 02:34:53]

Thank you for tackling this. In 6351053 rsc ask that signals be ignored for go
test as well.

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

https://codereview.appspot.com/6903061/diff/5001/src/cmd/go/signal.go#newcode21
src/cmd/go/signal.go:21: fmt.Fprintf(os.Stderr, "\n%s received\n", s)
I'm not sure if ignore should print something. If it does, it should probably do
something like "\n%s: %s received, ignoring\n", os.Args[0], s

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

https://codereview.appspot.com/6903061/diff/5001/src/cmd/go/signal_notunix.go...
src/cmd/go/signal_notunix.go:4: 
cute name

[brainman, 2012-12-10 03:34:55]

Hello golang-dev@googlegroups.com, dave@cheney.net (cc:
golang-dev@googlegroups.com),

Please take another look.

[brainman, 2012-12-10 03:35:39]

On 2012/12/10 02:34:53, dfc wrote:
> ... In 6351053 rsc ask that signals be ignored for go
> test as well.
> 

Done.

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

https://codereview.appspot.com/6903061/diff/5001/src/cmd/go/signal.go#newcode21
src/cmd/go/signal.go:21: fmt.Fprintf(os.Stderr, "\n%s received\n", s)
On 2012/12/10 02:34:53, dfc wrote:
> I'm not sure if ignore should print something. ...
I am thinking about the case when you press ctrl+c and nothing happens. Changed
error message as per your suggestion.

[dave_cheney.net, 2012-12-10 03:52:52]

LGTM. This works as expected on linux.

Interesting sidebar, if you do go test ./... in a large tree, SIGQUIT now
terminates the runtime.NumCPU() test jobs currently running and will move on to
the next ones in the queue.  

FAIL    launchpad.net/juju-core/worker/provisioner      0.271s
^\
go: quit received, ignoring
go build testmain: signal 3 (core dumped)
FAIL    launchpad.net/juju-core/worker/uniter [build failed]
go build testmain: signal 3 (core dumped)
go build testmain: signal 3 (core dumped)

[dave_cheney.net, 2012-12-10 05:07:49]

Actually, one more thing

^c go test now does not stop the tests, it should prevent starting new tests if
you're doing go test ./...

[rsc, 2012-12-10 06:41:16]

Thanks very much for working on this. 

I agree with Dave: the loop should set a flag saying it received an interrupt,
and that should stop other work.

It looks to me like if you set the flag in the handler you can check it in
cmd/go/build.go:611 or so, both before and after handle(a). If interrupted, just
return from the goroutine.

The workers stopping early will require replacing the done channel and <-done at
end with a waitgroup and defer wg.Done() in the workers.

Once the workers are done (wg.Wait returns in the main goroutine) if go test was
interrupted it should os.Exit(1).

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

https://codereview.appspot.com/6903061/diff/3/src/cmd/go/signal.go#newcode20
src/cmd/go/signal.go:20: fmt.Fprintf(os.Stderr, "\n%s: %s received, ignoring\n",
os.Args[0], s)
I don't think anything needs to be printed.

On Unix typing ^C the signal will go to all the foreground processes so both 'go
test' and what it is running. The thing it's running should die quickly, and
then the go command will exit. So I don't think any printing needs to be done
there.

On Windows I don't know where ^C goes exactly. It might be necessary to relay
the signal, although I would expect the child to get it before the parent.

So in both cases I think the print can just go away.

[brainman, 2012-12-11 06:25:36]

Hello golang-dev@googlegroups.com, dave@cheney.net, rsc@golang.org (cc:
golang-dev@googlegroups.com),

Please take another look.

[brainman, 2012-12-11 06:25:42]

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

https://codereview.appspot.com/6903061/diff/3/src/cmd/go/signal.go#newcode20
src/cmd/go/signal.go:20: fmt.Fprintf(os.Stderr, "\n%s: %s received, ignoring\n",
os.Args[0], s)
On 2012/12/10 06:41:16, rsc wrote:
> ...
> On Windows I don't know where ^C goes exactly. It might be necessary to relay
> the signal, although I would expect the child to get it before the parent.

^C goes to "process group", and go process ignores it now, but the children will
die on receipt of ^C, unless they protect against it. So, it looks like it works
like unix.

> 
> So in both cases I think the print can just go away.

Removed it.

[rsc, 2012-12-11 16:34:58]

LGTM

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.
s/returns true, if/reports whether the/

[dave_cheney.net, 2012-12-13 02:10:03]

NOT LGTM

try go test net/http

send SIGQUIT to the test process via ^\

go test itself will hang, ^C or ^\ will not fix it.

[rsc, 2012-12-13 02:48:55]

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

[brainman, 2012-12-13 02:49:03]

On 2012/12/13 02:10:03, dfc wrote:
>  ...
> go test itself will hang, ^C or ^\ will not fix it.

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

[dave_cheney.net, 2012-12-13 02:54:16]

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. 

On 13/12/2012, at 13:48, Russ Cox <rsc@golang.org> wrote:

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

[brainman, 2012-12-13 03:18:51]

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.
On 2012/12/11 16:34:58, rsc wrote:
> s/returns true, if/reports whether the/

Done.

[brainman, 2012-12-13 03:21:19]

On 2012/12/13 02:54:16, dfc wrote:
> 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. 
> 

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

[brainman, 2012-12-13 06:11:27]

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

[dave_cheney.net, 2012-12-13 08:45:24]

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

[dave_cheney.net, 2012-12-13 08:50:57]

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

[dave_cheney.net, 2012-12-13 10:57:30]

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.

[brainman, 2012-12-13 23:13:51]

On 2012/12/13 10:57:30, dfc wrote:
> 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.

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

[dave_cheney.net, 2012-12-13 23:15:53]

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.

On Fri, Dec 14, 2012 at 10:13 AM,  <alex.brainman@gmail.com> wrote:
> On 2012/12/13 10:57:30, dfc wrote:
>>
>> 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.
>
> 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/

[brainman, 2012-12-13 23:40:26]

Hello golang-dev@googlegroups.com, dave@cheney.net, rsc@golang.org (cc:
golang-dev@googlegroups.com),

Please take another look.

[dave_cheney.net, 2012-12-13 23:45:54]

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

https://codereview.appspot.com/6903061/diff/22002/src/cmd/go/signal.go#newcode28
src/cmd/go/signal.go:28: onceCloseInterrupted.Do(closeInterrupted)
Why do we need to keep this func running once a signal which would interrupt the
downstream process has arrived ?

[brainman, 2012-12-13 23:53:19]

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

https://codereview.appspot.com/6903061/diff/22002/src/cmd/go/signal.go#newcode28
src/cmd/go/signal.go:28: onceCloseInterrupted.Do(closeInterrupted)
On 2012/12/13 23:45:54, dfc wrote:
> Why do we need to keep this func running once a signal which would interrupt
the
> downstream process has arrived ?

go process is ignoring these signals, so, I think, we can get second signal
while we doing something else. We should be prepared.

[dave_cheney.net, 2012-12-13 23:56:20]

> go process is ignoring these signals, so, I think, we can get second signal
> while we doing something else. We should be prepared.

ignoredSignals is maybe not accurate. The go process doesn't ignore the signals,
in fact, it watches for them. The downstream go test/run/whatever process
doesn't ignore them either, it reacts to them.

Maybe s/ignored/interruptible/ then it is clearer that the func waiting on the
sig chan closes the interrupted chan and then it is done.

[brainman, 2012-12-14 00:06:01]

Hello golang-dev@googlegroups.com, dave@cheney.net, rsc@golang.org (cc:
golang-dev@googlegroups.com),

Please take another look.

[dave_cheney.net, 2012-12-14 00:16:44]

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

https://codereview.appspot.com/6903061/diff/29009/src/cmd/go/signal.go#newcode28
src/cmd/go/signal.go:28: onceCloseInterrupted.Do(closeInterrupted)
I'm sorry to harp on this. I don't think the sync.Once handler is adding
anything that 

go func() {
   <- sig
   close(closeInterrupted)
}()

wouldn't do

[dave_cheney.net, 2012-12-14 00:17:30]

Sorry, I meant to write
go func() {
    <- sig
    close(interrupted)
}()

[brainman, 2012-12-14 00:26:14]

Hello golang-dev@googlegroups.com, dave@cheney.net, rsc@golang.org (cc:
golang-dev@googlegroups.com),

Please take another look.

[dave_cheney.net, 2012-12-14 00:39:16]

LGTM. All my manual tests pass.

Thank you for your persistence, this is going to be a really useful feature.

[brainman, 2012-12-14 00:41:58]

On 2012/12/14 00:39:16, dfc wrote:
> LGTM. All my manual tests pass.
> 

Thank you for your help. I will submit it tonight - give others chance to
comment.

Alex

[brainman, 2012-12-14 06:34:10]

*** Submitted as https://code.google.com/p/go/source/detail?r=ee5afd4b14b7 ***

cmd/go: handle os signals

Ignore signals during "go run" and wait for running child
process to exit. Stop executing further tests during "go test",
wait for running tests to exit and report error exit code.

Original CL 6351053 by dfc.

Fixes issue 3572.
Fixes issue 3581.

R=golang-dev, dave, rsc
CC=golang-dev
https://codereview.appspot.com/6903061