runtime: send on channel panics with "unexpected signal during runtime execution" #19468
Labels
Milestone
Comments
|
Almost certainly a data race. Have you tested your application with the
race detector.
…On Thu, 9 Mar 2017, 12:55 mappu ***@***.***> wrote:
What version of Go are you using (go version)?
go version go1.8 windows/amd64
x86_64-w64-mingw32-gcc (GCC) 5.4.0
What operating system and processor architecture are you using (go env)?
set GOARCH=amd64
set GOBIN=
set GOEXE=.exe
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOOS=windows
set GOPATH=C:\repos\winio-zstd-panic-clone
set GORACE=
set GOROOT=C:\Go
set GOTOOLDIR=C:\Go\pkg\tool\windows_amd64
set GCCGO=gccgo
set CC=gcc
set GOGCCFLAGS=-m64 -mthreads -fmessage-length=0 -fdebug-prefix-map=C:\cygwin\tmp\go-build164083627=/tmp/go-build -gno-record-gcc-switches
set CXX=g++
set CGO_ENABLED=1
set PKG_CONFIG=pkg-config
set CGO_CFLAGS=-g -O2
set CGO_CPPFLAGS=
set CGO_CXXFLAGS=-g -O2
set CGO_FFLAGS=-g -O2
set CGO_LDFLAGS=-g -O2
What did you do?
1.
Have a working Go + CGO environment on Windows (here i use mingw-w64).
2.
Install test case: go get
github.com/mappu/winio-zstd-panic/src/winio-zstd-panic
3.
Run a few times: $GOPATH/bin/winio-zstd-panic - the bug happens maybe
1/10 executions on my machine (Intel i5 6400).
What did you expect to see?
******************************
client: making connection...
client: connected
server: recieved signal, shutting down
What did you see instead?
******************************
client: making connection...
fatal error:
client: connected
unexpected signal during runtime execution
[signal 0xc0000005 code=0x0 addr=0xffffffffffffffff pc=0x40e395]
goroutine 18 [running]:
runtime.throw(0x4fd587, 0x2a)
C:/Go/src/runtime/panic.go:596 +0x9c fp=0xc042083e08 sp=0xc042083de8
runtime.sigpanic()
C:/Go/src/runtime/signal_windows.go:155 +0x18b fp=0xc042083e38 sp=0xc042083e08
runtime.lock(0x24749f73771afe8f)
C:/Go/src/runtime/lock_sema.go:43 +0x65 fp=0xc042083e70 sp=0xc042083e38
runtime.chansend(0x4cf380, 0x24749f73771afe37, 0xc042083fb0, 0xc042083f01, 0x4b64fa, 0xc042083f9c)
C:/Go/src/runtime/chan.go:176 +0xba fp=0xc042083f20 sp=0xc042083e70
runtime.chansend1(0x4cf380, 0x24749f73771afe37, 0xc042083fb0)
C:/Go/src/runtime/chan.go:113 +0x4d fp=0xc042083f60 sp=0xc042083f20github.com/Microsoft/go-winio.ioCompletionProcessor(0x1c8)
C:/repos/winio-zstd-panic/src/github.com/Microsoft/go-winio/file.go:133 +0xea fp=0xc042083fd8 sp=0xc042083f60
runtime.goexit()
C:/Go/src/runtime/asm_amd64.s:2197 +0x1 fp=0xc042083fe0 sp=0xc042083fd8
created by github.com/Microsoft/go-winio.initIo
C:/repos/winio-zstd-panic/src/github.com/Microsoft/go-winio/file.go:57 +0x87
goroutine 1 [runnable]:
main.main()
C:/repos/winio-zstd-panic/src/github.com/mappu/winio-zstd-panic/src/winio-zstd-panic/main.go:112 +0xcd
goroutine 17 [syscall, locked to thread]:
runtime.goexit()
C:/Go/src/runtime/asm_amd64.s:2197 +0x1
goroutine 5 [select]:github.com/Microsoft/go-winio.(*win32PipeListener).listenerRoutine(0xc042030070)
C:/repos/winio-zstd-panic/src/github.com/Microsoft/go-winio/pipe.go:269 +0x4e9
created by github.com/Microsoft/go-winio.ListenPipe
C:/repos/winio-zstd-panic/src/github.com/Microsoft/go-winio/pipe.go:352 +0x2ec
goroutine 6 [chan receive]:github.com/Microsoft/go-winio.(*win32PipeListener).Accept(0xc042030070, 0x0, 0x0, 0x0, 0x0)
C:/repos/winio-zstd-panic/src/github.com/Microsoft/go-winio/pipe.go:373 +0x120
main.(*Terminator).worker(0xc04200c400)
C:/repos/winio-zstd-panic/src/github.com/mappu/winio-zstd-panic/src/winio-zstd-panic/main.go:39 +0x3a
created by main.NewTerminator
C:/repos/winio-zstd-panic/src/github.com/mappu/winio-zstd-panic/src/winio-zstd-panic/main.go:34 +0x141
goroutine 19 [chan receive]:github.com/Microsoft/go-winio.(*win32File).asyncIo(0xc042074050, 0xc042078060, 0x0, 0xc000000000, 0x0, 0x0, 0x5bc4a0, 0xc042088000, 0x0, 0x0, ...)
C:/repos/winio-zstd-panic/src/github.com/Microsoft/go-winio/file.go:167 +0x24dgithub.com/Microsoft/go-winio.connectPipe(0xc042074050, 0x0, 0x0)
C:/repos/winio-zstd-panic/src/github.com/Microsoft/go-winio/pipe.go:362 +0xc1github.com/Microsoft/go-winio.(*win32PipeListener).listenerRoutine.func1(0xc042072060, 0xc042076000)
C:/repos/winio-zstd-panic/src/github.com/Microsoft/go-winio/pipe.go:267 +0x35
created by github.com/Microsoft/go-winio.(*win32PipeListener).listenerRoutine
C:/repos/winio-zstd-panic/src/github.com/Microsoft/go-winio/pipe.go:268 +0x286
goroutine 20 [runnable, locked to thread]:
syscall.Syscall(0x7ffb78294620, 0x1, 0x1cc, 0x0, 0x0, 0xc04216e080, 0xc042019900, 0x2)
C:/Go/src/runtime/syscall_windows.go:163 +0x6b
syscall.GetFileType(0x1cc, 0x428ea5, 0xc000000008, 0xc04216e080)
C:/Go/src/syscall/zsyscall_windows.go:756 +0x6b
syscall.Seek(0x1cc, 0x0, 0x1, 0x1001, 0x101000000001000, 0x0)
C:/Go/src/syscall/syscall_windows.go:349 +0x57
os.(*File).pread(0xc042076008, 0xc042280000, 0x1000, 0x1000, 0x0, 0x0, 0x0, 0x0)
C:/Go/src/os/file_windows.go:298 +0xc8
os.(*File).ReadAt(0xc042076008, 0xc042280000, 0x1000, 0x1000, 0x0, 0x1000, 0xc042276c00, 0x929)
C:/Go/src/os/file.go:120 +0xba
main.start_workload_simulator.func1(0xc042072120)
C:/repos/winio-zstd-panic/src/github.com/mappu/winio-zstd-panic/src/winio-zstd-panic/main.go:78 +0x10e
created by main.start_workload_simulator
C:/repos/winio-zstd-panic/src/github.com/mappu/winio-zstd-panic/src/winio-zstd-panic/main.go:93 +0x46
This test case creates a win32 named pipe; performs some background work;
and then connects to the named pipe. But for some reason, connecting to the
named pipe causes a panic within Golang's channel / signal handling.
This test case depends on both (A) a third-party Windows library, and (B)
a third-party CGO library. I did report this issue to the vendor of A as
microsoft/go-winio#41 <microsoft/go-winio#41>
but, the more i look at the panic trace, i think the issue is with Golang's
runtime (apologies in advance if that's wrong).
—
You are receiving this because you are subscribed to this thread.
Reply to this email directly, view it on GitHub
<#19468>, or mute the thread
<https://github.com/notifications/unsubscribe-auth/AAAcAxKrrjock7p423m4Hi-ZzlzkSZJQks5rj1wbgaJpZM4MXjK3>
.
|
bradfitz
added
the
WaitingForInfo
|
I built the test application under I think i needed to make the failure more reliable, so i thought about ways to do that. I decided to set GOMAXPROCS=1. Still have not seen any race-detection warning, but, very quickly I got this different panic: |
|
I tried 1.7.5, it seems immune from this issue.
UPDATE: added crash statistics; added 1.6.4 results; noticed failure in go1.8.0 no-race 1-proc under more rigorous test script |
|
Next guess would be memory corruption from your cgo code. Certainly memory has gotten corrupted somehow. You might want to try running with |
|
When i add |
ianlancetaylor
changed the title
|
OK, but I'm still guessing memory corruption from your C code rather than a bug in the Go distribution. I tried to look at your test case but I see that it only runs on Windows and it is large. |
ianlancetaylor
added
OS-Windows
and removed
WaitingForInfo
|
The libraries involved do have high-profile authorship... but nothing is above suspicion. I have open tickets with them too. This has the same error message as #19029 , where #19078 is considered to be the cause. In that thread, it's suggested that 1.8rc3 is unaffected by this issue. But I tried Go 1.8beta1, 1.8beta2, 1.8rc1 and 1.8rc3 , and they all have the same panic behaviour as 1.8 above. So this panic - whether the underlying fault is in the C code or not - is triggered by some change inbetween 1.7.5 and 1.8beta1. I will attempt to bisect. |
|
I checked out Go src and used git bisect. I knew 1.7.5 worked and 1.8beta1 failed. The test case is quite reliable for me (40 failures in 100 runs) and it took 11 bisections to track down where the panics first appeared. The first offending commit is ca4089a by @randall77 . Always, the problem manifests in the same way:
EDIT: full bisection log https://gist.github.com/mappu/4df62a83194b6fa158dbc4b6af61f2f9 |
|
@mappu, does your crashing application use finalizers? |
|
Apparently yes it does. |
|
I think i see where you're going with this. Go1.8 may require additional calls to |
|
@mappu, yup. That's my guess. |
|
I totally removed all calls to |
|
Panic is consistent with different C toolchains.
|
|
@mappu, looking over your code, I don't understand what's supposed to be happening. In particular, here: //sys getQueuedCompletionStatus(port syscall.Handle, bytes *uint32, key *uintptr, o **ioOperation, timeout uint32) (err error) = GetQueuedCompletionStatus
// ioOperation represents an outstanding asynchronous Win32 IO
type ioOperation struct {
o syscall.Overlapped
ch chan ioResult
}
// ioCompletionProcessor processes completed async IOs forever
func ioCompletionProcessor(h syscall.Handle) {
// Set the timer resolution to 1. This fixes a performance regression in golang 1.6.
timeBeginPeriod(1)
for {
var bytes uint32
var key uintptr
var op *ioOperation
err := getQueuedCompletionStatus(h, &bytes, &key, &op, syscall.INFINITE)
if op == nil {
panic(err)
}
op.ch <- ioResult{bytes, err}
}
}I haven't read up on IO completion ports, but it looks like the |
|
Hi @aclements, that's a great discovery. It looks like a bug to me too. It should be reported to Microsoft in their upstream repository https://github.com/Microsoft/go-winio/issues . Upstream do seem to think the earlier suggestion about go1.8 finalizer changes was correct, and they have closed my corresponding issue in their own repo. But, i haven't retried my original test case against their latest code. I'll do that today and follow up this ticket. |
|
I re-ran the test case with the updated vendor code, and can confirm the issue is resolved. && In the end it wasn't Go's fault. Thanks everyone for your assistance in troubleshooting this issue, i will close the ticket. @aclements despite it being a very weird construct, it does seem to work now that the finalizer behaviours were changed in upstream, so it's (probably??) not a bug... |
whilei
added a commit
to whilei/go-ethereum
that referenced
this issue
Nov 6, 2017
…227fbf57ac8a6fee70f69a problem: fatal error: unexpected signal during runtime execution when running 'monitor' command on win 7 sp1 note: aws/aws-sam-cli#112 note: microsoft/go-winio#41 note: golang/go#19468 (comment) [not go issue] solution: update microsoft/go-winio vendor dependency Rel ethereumproject#392
whilei
added a commit
to ethereumproject/go-ethereum
that referenced
this issue
Nov 8, 2017
…227fbf57ac8a6fee70f69a problem: fatal error: unexpected signal during runtime execution when running 'monitor' command on win 7 sp1 note: aws/aws-sam-cli#112 note: microsoft/go-winio#41 note: golang/go#19468 (comment) [not go issue] solution: update microsoft/go-winio vendor dependency Rel #392 ---- manually remove vendored winio tests remove dirs from vendored go-winio Revert "remove dirs from vendored go-winio" This reverts commit 67c9236. remove subdir go _test files from manually vendored winio package
whilei
added a commit
to ethereumproject/go-ethereum
that referenced
this issue
Nov 8, 2017
…227fbf57ac8a6fee70f69a problem: fatal error: unexpected signal during runtime execution when running 'monitor' command on win 7 sp1 note: aws/aws-sam-cli#112 note: microsoft/go-winio#41 note: golang/go#19468 (comment) [not go issue] solution: update microsoft/go-winio vendor dependency Rel #392 ---- manually remove vendored winio tests ---- remove dirs from vendored go-winio ---- Revert "remove dirs from vendored go-winio" This reverts commit 67c9236. ---- remove subdir go _test files from manually vendored winio package ---- rm -rf archive/tar/testdata
Sign up for free
to subscribe to this conversation on GitHub.
Already have an account?
Sign in.
What version of Go are you using (
go version)?go version go1.8 windows/amd64x86_64-w64-mingw32-gcc (GCC) 5.4.0What operating system and processor architecture are you using (
go env)?What did you do?
Have a working Go + CGO environment on Windows (here i use mingw-w64).
Install test case:
go get github.com/mappu/winio-zstd-panic/src/winio-zstd-panicRun a few times:
$GOPATH/bin/winio-zstd-panic- the bug happens maybe 1/10 executions on my machine (Intel i5 6400).What did you expect to see?
What did you see instead?
This test case creates a win32 named pipe; performs some background work; and then connects to the named pipe. But for some reason, connecting to the named pipe causes a panic within Golang's channel / signal handling.
This test case depends on both (A) a third-party Windows library, and (B) a third-party CGO library. I did report this issue to the vendor of A as microsoft/go-winio#41 but, the more i look at the panic trace, i think the issue is with Golang's runtime (apologies in advance if that's wrong).
The text was updated successfully, but these errors were encountered: