dl/internal/version, dl/gotip: corrupted output on SIGQUIT #36976

zikaeroh · 2020-02-02T07:23:54Z

What version of Go are you using (`go version`)?

$ go version
go version devel +866920a Sat Feb 1 06:01:05 2020 +0000 linux/amd64

Does this issue reproduce with the latest release?

1.13.7, no. Tip, yes.

What operating system and processor architecture are you using (`go env`)?

go env Output

$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/jake/nobackup/gotip_home/cache"
GOENV="/home/jake/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/jake/nobackup/gotip_home/gopath"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/home/jake/sdk/gotip"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/jake/sdk/gotip/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/home/jake/testproj/badquit/go.mod"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build408391790=/tmp/go-build -gno-record-gcc-switches"
GOROOT/bin/go version: go version devel +866920a Sat Feb 1 06:01:05 2020 +0000 linux/amd64
GOROOT/bin/go tool compile -V: compile version devel +866920a Sat Feb 1 06:01:05 2020 +0000
uname -sr: Linux 5.5.0-1-mainline
/usr/lib/libc.so.6: GNU C Library (GNU libc) stable release version 2.30.

What did you do?

Ran code that blocked, like:

package main

import "time"

func main() {
	time.Sleep(time.Hour)
}

Then, hit Ctrl+\ to send SIGQUIT.

What did you expect to see?

"Good" output with a back trace, register contents, etc. On 1.13.7, that's:

^\SIGQUIT: quit
PC=0x44f053 m=0 sigcode=128

goroutine 5 [syscall]:
runtime.notetsleepg(0x4d4420, 0x34630b87115, 0x0)
	/usr/lib/go/src/runtime/lock_futex.go:227 +0x34 fp=0xc000034760 sp=0xc000034730 pc=0x409604
runtime.timerproc(0x4d4400)
	/usr/lib/go/src/runtime/time.go:311 +0x2f1 fp=0xc0000347d8 sp=0xc000034760 pc=0x43edc1
runtime.goexit()
	/usr/lib/go/src/runtime/asm_amd64.s:1357 +0x1 fp=0xc0000347e0 sp=0xc0000347d8 pc=0x44d151
created by runtime.(*timersBucket).addtimerLocked
	/usr/lib/go/src/runtime/time.go:169 +0x10e

goroutine 1 [sleep]:
runtime.goparkunlock(...)
	/usr/lib/go/src/runtime/proc.go:310
time.Sleep(0x34630b8a000)
	/usr/lib/go/src/runtime/time.go:105 +0x157
main.main()
	/home/jake/testproj/badquit/main.go:6 +0x30

rax    0xfffffffffffffffc
rbx    0x3b9a9b15
rcx    0x44f053
rdx    0x0
rdi    0x4d4420
rsi    0x80
rbp    0xc0000346e8
rsp    0xc0000346a0
r8     0x0
r9     0x0
r10    0xc0000346d8
r11    0x202
r12    0xff
r13    0x1ffffffffffffff
r14    0x488494
r15    0x39
rip    0x44f053
rflags 0x202
cs     0x33
fs     0x0
gs     0x0
exit status 2

What did you see instead?

The output is broken very broken, as though it's being output twice simultaneously.

^\SIGQUIT: quitSIGQUIT: quit

PC=PC=0x456e600x489f38 m= m=00 sigcode= sigcode=128128



goroutine goroutine 01 [ [idlesyscall]:
]:
runtime.epollwait(0x3, 0x7ffeea76fe10, syscall.Syscall60x36ee7f00000080(, 0xf70x0, , 0x10x36ee7f, , 0xcce30x0, , 0xc000040c500x0, , 0x10000040x0, , 0x00x0, , 0x00x0, , ...0xc000040c90)
, 	0x4948ec/home/jake/sdk/gotip/src/runtime/sys_linux_amd64.s, :0xc000098040705)
 +	0x20/usr/lib/go/src/syscall/asm_linux_amd64.s
:44runtime.netpoll +(0x50x34630b87429 fp=, 0xc000040c000xe0a18b77d01 sp=)
0xc000040bf8	 pc=/home/jake/sdk/gotip/src/runtime/netpoll_epoll.go0x489f15:
119 +os.(*Process).blockUntilWaitable0x92(
0xc000092060, 0x33, 0xcc4316c500020300runtime.findrunnable, (0x30xc000022800)
, 0x0	)
/usr/lib/go/src/os/wait_waitid.go	:/home/jake/sdk/gotip/src/runtime/proc.go31:2323 + +0x72b0x98
 fp=0xc000040cf0runtime.schedule( sp=)
0xc000040c00	/home/jake/sdk/gotip/src/runtime/proc.go pc=:0x497d582520
os.(*Process).wait +0x2fc(
0xc000092060runtime.park_m, (0x4f3c200xc000000180, 0x4f3c28)
, 	0x4f3c18/home/jake/sdk/gotip/src/runtime/proc.go)
:2690	 +/usr/lib/go/src/os/exec_unix.go0x9d:
22 +0x39 fp=runtime.mcall0xc000040d68( sp=0x00xc000040cf0)
 pc=	/home/jake/sdk/gotip/src/runtime/asm_amd64.s:0x4952e9318
 +0x5bos.(*Process).Wait
(...)

	goroutine /usr/lib/go/src/os/exec.go1: [125sleep
]:
os/exec.(*Cmd).Wait(time.Sleep0xc0000a0000(, 0x34630b8a0000x0)
, 	0x0/home/jake/sdk/gotip/src/runtime/time.go)
:	198/usr/lib/go/src/os/exec/exec.go +:0xba501
 +main.main0x60( fp=)
0xc000040de0	 sp=/home/jake/testproj/badquit/main.go0xc000040d68: pc=60x4aa710 +
0x30os/exec.(*Cmd).Run
(
0xc0000a0000rax    , 0xfffffffffffffffc0xc000089c00
, rbx    0x340x36ee7f)

	rcx    /usr/lib/go/src/os/exec/exec.go0x456e60:
341rdx     +0x800x5c
 fp=rdi    0xc000040e080x3 sp=
0xc000040de0rsi     pc=0x7ffeea76fe100x4a9bac

rbp    0x7ffeea770410main.main
(rsp    )
0x7ffeea76fdc0	
/home/jake/go/pkg/mod/golang.org/dl@v0.0.0-20200128181350-716300cef114/gotip/main.gor8     :0x059
 +r9     0x5120x0 fp=
0xc000040f60r10     sp=0x36ee7f0xc000040e08
 pc=r11    0x4ad7b20x246

r12    runtime.main0x3
(r13    )
0x4dd640	
/usr/lib/go/src/runtime/proc.gor14    :0x48bba9203
 +r15    0x21e0x0 fp=
0xc000040fe0rip     sp=0x456e600xc000040f60
 pc=rflags 0x42d87e0x246

runtime.goexitcs     (0x33)

	fs     /usr/lib/go/src/runtime/asm_amd64.s0x0:
1357gs      +0x00x1
 fp=0xc000040fe8 sp=0xc000040fe0 pc=0x457851

rax    0xf7
rbx    0xc000024500
rcx    0x489f3a
rdx    0xc000040c50
rdi    0x1
rsi    0xcce3
rbp    0xc000040ce0
rsp    0xc000040bf8
r8     0x0
r9     0x0
r10    0x1000004
r11    0x216
r12    0xffffffffffffffff
r13    0x3
r14    0x2
r15    0xaa
rip    0x489f38
rflags 0x216
cs     0x33
fs     0x0
gs     0x0
exit status 2

The text was updated successfully, but these errors were encountered:

zikaeroh · 2020-02-02T07:34:10Z

This also appears if timer code isn't in use, e.g.:

package main

import "runtime"

func main() {
	go func() {
		for {
			runtime.Gosched()
		}
	}()

	<-make(chan bool)
}

Which gives:

^\SIGQUIT: quit
PC=0x430ea3 m=0 sigcode=128

goroutine 0 [idle]:
SIGQUIT: quit
PC=runtime.findrunnable0x489f38( m=0xc0000200000,  sigcode=0x0128)

	
/home/jake/sdk/gotip/src/runtime/proc.go:goroutine 20921 + [0x863syscall
]:
runtime.schedule()
	/home/jake/sdk/gotip/src/runtime/proc.go:2520 +0x2fc
runtime.goschedImplsyscall.Syscall6((0xc0000010800xf7)
, 	0x1/home/jake/sdk/gotip/src/runtime/proc.go, :0xd93f2705,  +0xc000045c500xd6, 
0x1000004, runtime.gosched_m0x0(, 0xc0000010800x0)
, 	0xc000045c90/home/jake/sdk/gotip/src/runtime/proc.go, :0x4948ec2713,  +0xc0000163200x34)

	/usr/lib/go/src/syscall/asm_linux_amd64.sruntime.mcall:(440x0 +)
0x5	 fp=/home/jake/sdk/gotip/src/runtime/asm_amd64.s0xc000045c00: sp=3180xc000045bf8 + pc=0x5b0x489f15


goroutine os.(*Process).blockUntilWaitable1( [0xc00001a1e0chan receive, ]:
0x33, 0x591ee95400010300main.main, (0x3)
)
		/home/jake/testproj/badquit/main.go/usr/lib/go/src/os/wait_waitid.go::1231 + +0x650x98
 fp=0xc000045cf0
 sp=goroutine 0xc000045c005 pc= [0x497d58runnable
]:
os.(*Process).wait(runtime.Gosched0xc00001a1e0(...)
, 	0x4f3c20/home/jake/sdk/gotip/src/runtime/proc.go, :0x4f3c28269, 
0x4f3c18)
main.main.func1	(/usr/lib/go/src/os/exec_unix.go)
:	22/home/jake/testproj/badquit/main.go +:0x398 fp= +0xc000045d680x2d sp=
0xc000045cf0 pc=created by 0x4952e9main.main

	os.(*Process).Wait/home/jake/testproj/badquit/main.go(...)
:	6/usr/lib/go/src/os/exec.go +:0x35125


os/exec.(*Cmd).Waitrax    (0x00xc000092000
, rbx    0x00x2, 
0x0rcx    )
0x0	
/usr/lib/go/src/os/exec/exec.gordx    :0x0501
 +rdi    0x600x0 fp=
0xc000045de0rsi     sp=0x00xc000045d68
 pc=rbp    0x4aa7100x7ffd5e1b4c98

rsp    os/exec.(*Cmd).Run0x7ffd5e1b4bc0(
0xc000092000r8     , 0x10xc000085c00
, r9     0x340x0)

	r10    /usr/lib/go/src/os/exec/exec.go0xc0000160e0:
341r11     +0x20x5c
 fp=r12    0xc000045e080x3 sp=
0xc000045de0r13     pc=0x4d0aa00x4a9bac

r14    main.main0x1(
)
r15    	0x55/home/jake/go/pkg/mod/golang.org/dl@v0.0.0-20200128181350-716300cef114/gotip/main.go
:rip    590x430ea3 +
0x512rflags  fp=0x2060xc000045f60
 sp=cs     0xc000045e080x33 pc=
0x4ad7b2fs     
0x0
gs     runtime.main0x0(
)
	/usr/lib/go/src/runtime/proc.go:203 +0x21e fp=0xc000045fe0 sp=0xc000045f60 pc=0x42d87e
runtime.goexit()
	/usr/lib/go/src/runtime/asm_amd64.s:1357 +0x1 fp=0xc000045fe8 sp=0xc000045fe0 pc=0x457851

rax    0xf7
rbx    0xc000022000
rcx    0x489f3a
rdx    0xc000045c50
rdi    0x1
rsi    0xd93f
rbp    0xc000045ce0
rsp    0xc000045bf8
r8     0x0
r9     0x0
r10    0x1000004
r11    0x216
r12    0xffffffffffffffff
r13    0xb
r14    0xa
r15    0xaa
rip    0x489f38
rflags 0x216
cs     0x33
fs     0x0
gs     0x0
exit status 2

josharian · 2020-02-02T16:12:53Z

cc @aclements @ianlancetaylor

zikaeroh · 2020-02-02T18:57:10Z

Okay, this is entirely and completely strange. I've been trying to bisect this and went all the way back to the 1.13 release, but it still reproduced.

But I think I've figured it out; it only happens when I use gotip. If I run go directly out of ~/sdk/gotip, there's no issue.

$ gotip version
go version devel +753d56d364 Sun Feb 2 09:23:27 2020 +0000 linux/amd64

$ gotip run .  
^\SIGQUIT: quitSIGQUIT: quit

PC=PC=0x456e600x489f38 m= m=00 sigcode= sigcode=128128



goroutine goroutine 01 [ [idlesyscall]:
]:
runtime.epollwait(0x3, 0x7fffc5c00300, 0x36ee7f00000080syscall.Syscall6, (0x00xf7, , 0x36ee7f0x1, , 0x00x1d415, , 0x00xc000040c50, , 0x00x1000004, , 0x00x0, , 0x00x0, ..., )
0xc000040c90	, /home/jake/sdk/gotip/src/runtime/sys_linux_amd64.s0x4948ec:, 7050xc000098040 +)
0x20	
/usr/lib/go/src/syscall/asm_linux_amd64.sruntime.netpoll:(440x34630b8731b +, 0x50x1453e0cbde01 fp=)
0xc000040c00	 sp=/home/jake/sdk/gotip/src/runtime/netpoll_epoll.go0xc000040bf8: pc=1190x489f15 +
0x92
os.(*Process).blockUntilWaitable(0xc000092060, 0x33, 0x301a636400020300runtime.findrunnable, (0x30xc000020000)
, 	0x0/usr/lib/go/src/os/wait_waitid.go)
:	31/home/jake/sdk/gotip/src/runtime/proc.go +:0x982323 fp= +0xc000040cf00x72b sp=
0xc000040c00 pc=runtime.schedule0x497d58(
)
	os.(*Process).wait/home/jake/sdk/gotip/src/runtime/proc.go:2520( +0xc0000920600x2fc, 
0x4f3c20, runtime.park_m0x4f3c28(, 0xc0000001800x4f3c18)
)
		/home/jake/sdk/gotip/src/runtime/proc.go/usr/lib/go/src/os/exec_unix.go::269022 + +0x9d0x39
 fp=0xc000040d68 sp=0xc000040cf0 pc=0x4952e9
os.(*Process).Waitruntime.mcall(...)
(	0x0/usr/lib/go/src/os/exec.go)
:	125/home/jake/sdk/gotip/src/runtime/asm_amd64.s
:os/exec.(*Cmd).Wait318( +0xc0000a00000x5b, 
0x0, 
0x0goroutine )
1	 [/usr/lib/go/src/os/exec/exec.gosleep:]:
501 +0x60 fp=time.Sleep0xc000040de0( sp=0x34630b8a0000xc000040d68)
 pc=	0x4aa710/home/jake/sdk/gotip/src/runtime/time.go
:198os/exec.(*Cmd).Run +(0xba0xc0000a0000
, 0xc000089c00main.main, (0x34)
)
		/home/jake/testproj/badquit/main.go/usr/lib/go/src/os/exec/exec.go::6341 + +0x300x5c

rax    0xfffffffffffffffc
rbx    0x36ee7f
rcx     fp=0x456e60
0xc000040e08rdx     sp=0x800xc000040de0
 pc=rdi    0x4a9bac0x3

rsi    0x7fffc5c00300main.main
(rbp    )
0x7fffc5c00900	
/home/jake/go/pkg/mod/golang.org/dl@v0.0.0-20200128181350-716300cef114/gotip/main.gorsp    :0x7fffc5c002b059
 +r8     0x5120x0 fp=
0xc000040f60r9      sp=0x00xc000040e08
 pc=r10    0x4ad7b20x36ee7f

runtime.mainr11    (0x246)

	r12    /usr/lib/go/src/runtime/proc.go0x3:
203r13     +0x4dd6400x21e
 fp=r14    0xc000040fe00x2 sp=
0xc000040f60r15     pc=0x4000x42d87e

rip    0x456e60runtime.goexit
(rflags )
0x246	
/usr/lib/go/src/runtime/asm_amd64.scs     :0x331357
 +fs     0x10x0 fp=
0xc000040fe8gs      sp=0x00xc000040fe0
 pc=0x457851

rax    0xf7
rbx    0xc000024500
rcx    0x489f3a
rdx    0xc000040c50
rdi    0x1
rsi    0x1d415
rbp    0xc000040ce0
rsp    0xc000040bf8
r8     0x0
r9     0x0
r10    0x1000004
r11    0x216
r12    0xffffffffffffffff
r13    0x3
r14    0x2
r15    0xaa
rip    0x489f38
rflags 0x216
cs     0x33
fs     0x0
gs     0x0
exit status 2

$ ~/sdk/gotip/bin/go version
go version devel +753d56d364 Sun Feb 2 09:23:27 2020 +0000 linux/amd64

$ ~/sdk/gotip/bin/go run .  
^\SIGQUIT: quit
PC=0x456e60 m=0 sigcode=128

goroutine 0 [idle]:
runtime.epollwait(0x3, 0x7ffdc17f8230, 0x36ee7f00000080, 0x0, 0x36ee7f, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/home/jake/sdk/gotip/src/runtime/sys_linux_amd64.s:705 +0x20
runtime.netpoll(0x34630b88455, 0x14568604c401)
	/home/jake/sdk/gotip/src/runtime/netpoll_epoll.go:119 +0x92
runtime.findrunnable(0xc000020000, 0x0)
	/home/jake/sdk/gotip/src/runtime/proc.go:2323 +0x72b
runtime.schedule()
	/home/jake/sdk/gotip/src/runtime/proc.go:2520 +0x2fc
runtime.park_m(0xc000000180)
	/home/jake/sdk/gotip/src/runtime/proc.go:2690 +0x9d
runtime.mcall(0x0)
	/home/jake/sdk/gotip/src/runtime/asm_amd64.s:318 +0x5b

goroutine 1 [sleep]:
time.Sleep(0x34630b8a000)
	/home/jake/sdk/gotip/src/runtime/time.go:198 +0xba
main.main()
	/home/jake/testproj/badquit/main.go:6 +0x30

rax    0xfffffffffffffffc
rbx    0x36ee7f
rcx    0x456e60
rdx    0x80
rdi    0x3
rsi    0x7ffdc17f8230
rbp    0x7ffdc17f8830
rsp    0x7ffdc17f81e0
r8     0x0
r9     0x0
r10    0x36ee7f
r11    0x246
r12    0x3
r13    0x4dd640
r14    0x2
r15    0x400
rip    0x456e60
rflags 0x246
cs     0x33
fs     0x0
gs     0x0
exit status 2

I think this is an issue with the way gotip is managing its signals (or, how it doesn't appear to exec the go binary, but runs it as a child). You can probably drop the release blocker label.

zikaeroh · 2020-02-02T19:00:54Z

Yep, this is exclusive to the dl binaries. Here's 1.11.13:

$ go1.11.13 run .   
^\SIGQUIT: quitSIGQUIT: quit

PC=PC=0x44c4530x49c518 m= m=00 sigcode= sigcode=128128



goroutine goroutine 41 [ [syscallsyscall]:
]:
runtime.notetsleepg(0x4c5060, 0x34630b87aa3syscall.Syscall6, (0x00xf7)
, 	0x1/home/jake/sdk/go1.11.13/src/runtime/lock_futex.go, :0x1d71c227,  +0xc000045be00x37,  fp=0x10000040xc000031f58,  sp=0x00xc000031f28,  pc=0x00x408c07, 
0xc000045c20, 0x4b15bcruntime.timerproc, (0xc0000183e00x4c5040)
)
	/usr/lib/go/src/syscall/asm_linux_amd64.s	:/home/jake/sdk/go1.11.13/src/runtime/time.go44: +2880x5 + fp=0xc000045b90 sp=0x30e0xc000045b88 fp= pc=0xc000031fd80x49c4f5
 sp=0xc000031f58 pc=0x43c4de
os.(*Process).blockUntilWaitableruntime.goexit((0xc000016210)
, 	0x33/home/jake/sdk/go1.11.13/src/runtime/asm_amd64.s, :0x2aa35393000203001333,  +0x30x1)
 fp=	0xc000031fe0/usr/lib/go/src/os/wait_waitid.go sp=:0xc000031fd831 pc= +0x44a6010x98
 fp=created by 0xc000045c80runtime.(*timersBucket).addtimerLocked sp=0xc000045b90 pc=
0x4b66c8
	os.(*Process).wait/home/jake/sdk/go1.11.13/src/runtime/time.go(:0xc000016210170,  +0x71c3100x114, 
0x71c318
, goroutine 0x71c3081)
 [	sleep/usr/lib/go/src/os/exec_unix.go]:
:22 +time.Sleep0x39( fp=0x34630b8a0000xc000045cf8)
 sp=	0xc000045c80/home/jake/sdk/go1.11.13/src/runtime/time.go pc=:0x4b1fb9105
 +0x14fos.(*Process).Wait
(...)
main.main	(/usr/lib/go/src/os/exec.go)
:	125/home/jake/testproj/badquit/main.go
:os/exec.(*Cmd).Wait6( +0xc0000ae8400x30, 
0x0, 
0x0rax    )
0xfffffffffffffffc	
/usr/lib/go/src/os/exec/exec.gorbx    :0x3b9aa4a3501
 +rcx    0x600x44c453 fp=
0xc000045d70rdx     sp=0x00xc000045cf8
 pc=rdi    0x6612800x4c5060

os/exec.(*Cmd).Runrsi    (0x800xc0000ae840
, rbp    0xc0000863000xc000031ee0, 
0x34rsp    )
0xc000031e98	
/usr/lib/go/src/os/exec/exec.gor8     :0x0341
 +r9     0x5c0x0 fp=
0xc000045d98r10     sp=0xc000031ed00xc000045d70
 pc=r11    0x66071c0x206

golang.org/dl/internal/version.Runr12    (0x300x7061cb
, r13    0x90x11)

	r14    /home/jake/go/pkg/mod/golang.org/dl@v0.0.0-20200128181350-716300cef114/internal/version/version.go0x47c040:
63r15     +0x00x516
 fp=rip    0xc000045f400x44c453 sp=
0xc000045d98rflags  pc=0x2060x662b86

cs     main.main0x33(
)
fs     	0x0/home/jake/go/pkg/mod/golang.org/dl@v0.0.0-20200128181350-716300cef114/go1.11.13/main.go
:gs     230x0 +
0x36 fp=0xc000045f60 sp=0xc000045f40 pc=0x667256
runtime.main()
	/usr/lib/go/src/runtime/proc.go:203 +0x21e fp=0xc000045fe0 sp=0xc000045f60 pc=0x43064e
runtime.goexit()
	/usr/lib/go/src/runtime/asm_amd64.s:1357 +0x1 fp=0xc000045fe8 sp=0xc000045fe0 pc=0x45afd1

rax    0xf7
rbx    0xc000022000
rcx    0x49c51a
rdx    0xc000045be0
rdi    0x1
rsi    0x1d71c
rbp    0xc000045c70
rsp    0xc000045b88
r8     0x0
r9     0x0
r10    0x1000004
r11    0x212
r12    0xffffffffffffffff
r13    0xc
r14    0xb
r15    0xaa
rip    0x49c518
rflags 0x212
cs     0x33
fs     0x0
gs     0x0
exit status 2

I've edited the title, though I can't say I've ever seen an issue for the dl repo so I've got no clue what the correct prefix is.

ianlancetaylor · 2020-02-03T07:22:44Z

I bet that you are running the program using go run. When you type ^\ the SIGQUIT is being sent to both the go tool and the actual program. Both are crashing with a stack dump, and you are seeing an interleaving of the two stack dumps.

Try using go build and running the program directly.

zikaeroh · 2020-02-03T07:26:28Z

This behavior doesn't show up with go run, only with gotip run or goX.Y.Z run via the golang.org/dl binaries.

When I do gotip run, I get a process tree like:

Versus one fewer layer with just a plain go run (or ~/sdk/gotip/bin/go run):

zikaeroh · 2020-02-03T07:30:07Z

The extra layer seems to be what's causing the issue. I don't know exactly what all go run does internally, but it must be doing something to avoid this problem (as SIGQUIT-ting go run works fine).

I would have assumed that the golang.org/dl binaries would exec the Go binaries they intend to invoke, but maybe they don't to make non-Unix OSs work (I don't know what the equivalent to exec is on Windows). Perhaps some of the magic go run does could be reused.

dmitshur · 2020-02-03T16:25:41Z

I would have assumed that the golang.org/dl binaries would exec the Go binaries they intend to invoke

The dl binaries know nothing about internal details of the go run command. They are very thin wrappers around the underlying version of the go binary that they run. See here.

aclements · 2020-02-03T17:23:09Z

go run (and the go command in general) traps SIGQUIT (see here and here) so it doesn't go the runtime and cause a traceback in the go process itself.

You're right that the dl binaries could do the same. It would require just a little code that's different between UNIX/non-UNIX. Alternatively, as you point out, it could directly exec the go binary instead of using cmd.Run, which would take the dl binary out of the picture entirely. I'm pretty sure all platforms have syscall.Exec with the same signature, and it might even make the code simpler.

zikaeroh · 2020-02-03T17:52:11Z

Thanks for the info; I wasn't sure where to look for that.

I swapped out the exec.Command for a syscall.Exec, and it does fix the issue. I'll likely try to send a CL tonight.

dmitshur · 2020-02-03T19:49:02Z

For information, all versions of go other than gotip use package golang.org/dl/internal/version to start the "go" binary. golang.org/dl/gotip has a slightly different copy of that code. I'll retitle this issue so it covers both.

zikaeroh · 2020-02-03T19:53:13Z

Indeed, my CL would fix both.

I'd also submit something to deduplicate those two a bit (since they have copies of the same helpers), but that's perhaps a different issue. 😄

dmitshur · 2020-02-03T19:54:09Z

Indeed, my CL would fix both.

Great, thank you.

I'd also submit something to deduplicate those two a bit (since they have copies of the same helpers), but that's perhaps a different issue. 😄

Please file a separate issue for that.

zikaeroh · 2020-02-03T23:11:44Z

Hmm, unfortunately the implementation of syscall.Exec on Windows is:

func Exec(argv0 string, argv []string, envv []string) (err error) {
	return EWINDOWS
}

So even though it exists it's not going to work. Bummer. Guess I'll look into trapping the signals before the final go invocation, like the base package does:

go/src/cmd/go/internal/base/base.go

Lines 160 to 170 in 753d56d

    
           func RunStdin(cmdline []string) { 
        
           	cmd := exec.Command(cmdline[0], cmdline[1:]...) 
        
           	cmd.Stdin = os.Stdin 
        
           	cmd.Stdout = os.Stdout 
        
           	cmd.Stderr = os.Stderr 
        
           	cmd.Env = cfg.OrigEnv 
        
           	StartSigHandlers() 
        
           	if err := cmd.Run(); err != nil { 
        
           		Errorf("%v", err) 
        
           	} 
        
           }

gopherbot · 2020-02-05T08:28:40Z

Change https://golang.org/cl/217765 mentions this issue: internal/version: ignore signals intended for the child process

ianlancetaylor · 2020-06-16T02:41:16Z

Moving to backlog milestone.

josharian added this to the Go1.14 milestone Feb 2, 2020

josharian added the release-blocker label Feb 2, 2020

dmitshur added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Feb 2, 2020

zikaeroh changed the title ~~runtime: corrupted output on SIGQUIT~~ dl: corrupted output on SIGQUIT Feb 2, 2020

josharian modified the milestones: Go1.14, Go1.15 Feb 2, 2020

josharian removed the release-blocker label Feb 2, 2020

dmitshur changed the title ~~dl: corrupted output on SIGQUIT~~ dl/internal/version, dl/gotip: corrupted output on SIGQUIT Feb 3, 2020

zikaeroh mentioned this issue Feb 5, 2020

dl/internal/version, dl/gotip: merge gotip into internal/version #37037

Closed

ianlancetaylor modified the milestones: Go1.15, Backlog Jun 16, 2020

ianlancetaylor added help wanted NeedsFix The path to resolution is known, but the work has not been done. labels Jun 16, 2020

gopherbot removed the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Jun 16, 2020

zikaeroh mentioned this issue Sep 14, 2020

cmd/go: run does not relay signals to child process #40467

Open

zikaeroh mentioned this issue Mar 15, 2021

cmd/vet, os/signal: possible false-positive in sigchanyzer check when os.Signal channel is unused #45043

Closed

gopherbot closed this as completed in golang/dl@5564b1e Mar 18, 2021

perillo mentioned this issue Apr 16, 2021

dl/internal/version: misuse of unbuffered os.Signal channel as argument to signal.Notify #45604

Closed

golang locked and limited conversation to collaborators Mar 18, 2022

gopherbot added the FrozenDueToAge label Mar 18, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

dl/internal/version, dl/gotip: corrupted output on SIGQUIT #36976

dl/internal/version, dl/gotip: corrupted output on SIGQUIT #36976

zikaeroh commented Feb 2, 2020

zikaeroh commented Feb 2, 2020

josharian commented Feb 2, 2020

zikaeroh commented Feb 2, 2020

zikaeroh commented Feb 2, 2020 •

edited

Loading

ianlancetaylor commented Feb 3, 2020

zikaeroh commented Feb 3, 2020

zikaeroh commented Feb 3, 2020

dmitshur commented Feb 3, 2020 •

edited

Loading

aclements commented Feb 3, 2020

zikaeroh commented Feb 3, 2020

dmitshur commented Feb 3, 2020 •

edited

Loading

zikaeroh commented Feb 3, 2020

dmitshur commented Feb 3, 2020

zikaeroh commented Feb 3, 2020 •

edited

Loading

gopherbot commented Feb 5, 2020

ianlancetaylor commented Jun 16, 2020

dl/internal/version, dl/gotip: corrupted output on SIGQUIT #36976

dl/internal/version, dl/gotip: corrupted output on SIGQUIT #36976

Comments

zikaeroh commented Feb 2, 2020

What version of Go are you using (go version)?

Does this issue reproduce with the latest release?

What operating system and processor architecture are you using (go env)?

What did you do?

What did you expect to see?

What did you see instead?

zikaeroh commented Feb 2, 2020

josharian commented Feb 2, 2020

zikaeroh commented Feb 2, 2020

zikaeroh commented Feb 2, 2020 • edited Loading

ianlancetaylor commented Feb 3, 2020

zikaeroh commented Feb 3, 2020

zikaeroh commented Feb 3, 2020

dmitshur commented Feb 3, 2020 • edited Loading

aclements commented Feb 3, 2020

zikaeroh commented Feb 3, 2020

dmitshur commented Feb 3, 2020 • edited Loading

zikaeroh commented Feb 3, 2020

dmitshur commented Feb 3, 2020

zikaeroh commented Feb 3, 2020 • edited Loading

gopherbot commented Feb 5, 2020

ianlancetaylor commented Jun 16, 2020

What version of Go are you using (`go version`)?

What operating system and processor architecture are you using (`go env`)?

zikaeroh commented Feb 2, 2020 •

edited

Loading

dmitshur commented Feb 3, 2020 •

edited

Loading

dmitshur commented Feb 3, 2020 •

edited

Loading

zikaeroh commented Feb 3, 2020 •

edited

Loading