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

runtime: go1.8.rc1 GC crash with MakeFunc #18635

Closed
JakeMont opened this issue Jan 12, 2017 · 6 comments
Closed

runtime: go1.8.rc1 GC crash with MakeFunc #18635

JakeMont opened this issue Jan 12, 2017 · 6 comments
Milestone

Comments

@JakeMont
Copy link

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

go version go1.8rc1 linux/amd64

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

# go env
GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/opt/go/"
GORACE=""
GOROOT="/usr/local/go"
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build572059213=/tmp/go-build -gno-record-gcc-switches"
CXX="g++"
CGO_ENABLED="1"
PKG_CONFIG="pkg-config"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"

What did you do?

We very much need the improvements in go1.8, and so have been building and testing with the go1.8rc1. I was seeing panics during "copystack". After considerable effort I was able to reduce the problem code to this somewhat contrived example:

package main

import (
	"log"
	"reflect"
)

func main() {
	go func() {
		sum := 0
		for {
			garbage := make([]byte, 1, 10*1024*1024)
			sum += int(garbage[0])
		}
	}()

	// Build runnable function creator
	ret := func() reflect.Value {
		newfun := func(in []reflect.Value) []reflect.Value {
			return reflect.ValueOf(Max).Call([]reflect.Value{})
		}
		outType := reflect.FuncOf([]reflect.Type{}, []reflect.Type{}, false)
		return reflect.MakeFunc(outType, newfun)
	}
	NextFn = func() interface{} { return ret().Interface() }
	// Run function recursively
	NextFn().(func())()
}

var NextFn func() interface{}
var ProgramStateDepth = 0

func Max() {
	ProgramStateDepth++
	log.Println("Depth", ProgramStateDepth)
	next := NextFn().(func())
	next()
}

This actually produces the same panic, but it happens during gc. On my machine it may take anywhere from 2 to 10000 "iterations" of Max, but it always crashes within seconds. Here is the output in a run where it crashed after 1 iteration:

2017/01/12 17:23:08 Depth 1
runtime: confused by reflect.makeFuncStub
fatal error: reflect mismatch

runtime stack:
runtime.throw(0x4d1c7b, 0x10)
        /usr/local/go/src/runtime/panic.go:596 +0x95
runtime.getArgInfo(0xc420037c00, 0x522a70, 0xc420037a01, 0x0, 0x10, 0x0)
        /usr/local/go/src/runtime/traceback.go:589 +0x177
runtime.gentraceback(0xffffffffffffffff, 0xc420a911a0, 0x0, 0xc4200001a0, 0x0, 0x0, 0x7fffffff, 0xc420037df0, 0x0, 0x0, ...)
        /usr/local/go/src/runtime/traceback.go:342 +0x117b
runtime.scanstack(0xc4200001a0, 0xc42001d228)
        /usr/local/go/src/runtime/mgcmark.go:842 +0x265
runtime.scang(0xc4200001a0, 0xc42001d228)
        /usr/local/go/src/runtime/proc.go:866 +0x209
runtime.markroot.func1()
        /usr/local/go/src/runtime/mgcmark.go:264 +0x6d
runtime.systemstack(0xc420037f28)
        /usr/local/go/src/runtime/asm_amd64.s:343 +0xab
runtime.markroot(0xc42001d228, 0x5)
        /usr/local/go/src/runtime/mgcmark.go:269 +0x1e2
runtime.gcDrain(0xc42001d228, 0x5)
        /usr/local/go/src/runtime/mgcmark.go:1051 +0xbe
runtime.gcBgMarkWorker.func2()
        /usr/local/go/src/runtime/mgc.go:1522 +0xe0
runtime.systemstack(0xc42001c000)
        /usr/local/go/src/runtime/asm_amd64.s:327 +0x79
runtime.mstart()
        /usr/local/go/src/runtime/proc.go:1132

goroutine 4 [GC worker (idle)]:
runtime.systemstack_switch()
        /usr/local/go/src/runtime/asm_amd64.s:281 fp=0xc420027750 sp=0xc420027748
runtime.gcBgMarkWorker(0xc42001c000)
        /usr/local/go/src/runtime/mgc.go:1527 +0x1fc fp=0xc4200277d8 sp=0xc420027750
runtime.goexit()
        /usr/local/go/src/runtime/asm_amd64.s:2197 +0x1 fp=0xc4200277e0 sp=0xc4200277d8
created by runtime.gcBgMarkStartWorkers
        /usr/local/go/src/runtime/mgc.go:1402 +0x98

goroutine 1 [runnable (scan)]:
fmt.(*pp).printArg(0xc42004c000, 0x4b1580, 0xc42000e128, 0xc400000076)
        /usr/local/go/src/fmt/print.go:604 +0xa37
fmt.(*pp).doPrintln(0xc42004c000, 0xc420a912e8, 0x2, 0x2)
        /usr/local/go/src/fmt/print.go:1138 +0xa1
fmt.Sprintln(0xc420a912e8, 0x2, 0x2, 0xc42000e128, 0x553398)
        /usr/local/go/src/fmt/print.go:264 +0x56
log.Println(0xc420a912e8, 0x2, 0x2)
        /usr/local/go/src/log/log.go:297 +0x3f
main.Max()
        /tmp/crash/crash.go:35 +0xe9
reflect.Value.call(0x4b0340, 0x4d7588, 0x13, 0x4d0495, 0x4, 0xc420a91740, 0x0, 0x0, 0x1c, 0x4b0340, ...)
        /usr/local/go/src/reflect/value.go:434 +0x91f
reflect.Value.Call(0x4b0340, 0x4d7588, 0x13, 0xc420a91740, 0x0, 0x0, 0xc42006e100, 0x20, 0x20)
        /usr/local/go/src/reflect/value.go:302 +0xa4
main.main.func2.1(0x553500, 0x0, 0x0, 0x553500, 0x0, 0x0)
        /tmp/crash/crash.go:20 +0x7b
reflect.callReflect(0xc42006e100, 0xc420a91908)
        /usr/local/go/src/reflect/value.go:508 +0x38f
reflect.makeFuncStub(0x4b0340, 0xc42006e100, 0x2, 0xc4200581c0, 0x4d05eb, 0x5, 0x4b1ac0, 0xc420058140, 0x4b1580, 0xc4200581c0, ...)
        /usr/local/go/src/reflect/asm_amd64.s:17 +0x40
main.Max()
        /tmp/crash/crash.go:37 +0x10f
reflect.Value.call(0x4b0340, 0x4d7588, 0x13, 0x4d0495, 0x4, 0xc42003bd90, 0x0, 0x0, 0xc42005c0f0, 0x4b0340, ...)
        /usr/local/go/src/reflect/value.go:434 +0x91f
reflect.Value.Call(0x4b0340, 0x4d7588, 0x13, 0xc42003bd90, 0x0, 0x0, 0xc42006e0e0, 0x20, 0x20)
        /usr/local/go/src/reflect/value.go:302 +0xa4
main.main.func2.1(0x553500, 0x0, 0x0, 0x553500, 0x0, 0x0)
        /tmp/crash/crash.go:20 +0x7b
reflect.callReflect(0xc42006e0e0, 0xc420a91f58)
        /usr/local/go/src/reflect/value.go:508 +0x38f
reflect.makeFuncStub(0x4b0340, 0xc42006e0e0, 0xc4200001a0, 0xc4200581a0, 0xc420a91fd0, 0x42802a, 0xc420056000, 0x0, 0xc420056000, 0x0, ...)
        /usr/local/go/src/reflect/asm_amd64.s:17 +0x40
main.main()
        /tmp/crash/crash.go:27 +0xaf

goroutine 18 [GC assist wait]:
main.main.func1()
        /tmp/crash/crash.go:12 +0x3f
created by main.main
        /tmp/crash/crash.go:15 +0x39

As with the stack crash, the key seems to be:

runtime: confused by reflect.makeFuncStub
fatal error: reflect mismatch

BTW - go1.8 performance is amazing - Thanks!

@dsnet
Copy link
Member

dsnet commented Jan 12, 2017

\cc @crawshaw

@bradfitz
Copy link
Contributor

Any help here would be great.

/cc @ianlancetaylor @randall77 @cherrymui @minux @aclements

@bradfitz bradfitz added this to the Go1.8 milestone Jan 12, 2017
@bradfitz bradfitz changed the title go1.8.rc1 GC crash with MakeFunc runtime: go1.8.rc1 GC crash with MakeFunc Jan 12, 2017
@crawshaw
Copy link
Member

I believe @aclements did some recent work here (https://golang.org/cl/31138).

@aclements
Copy link
Member

@JakeMont, thanks for the easy repro. I'm looking into this now.

@aclements
Copy link
Member

I believe what's going on is that the reflect.makeFuncImpl ctxt is getting garbage collected while the call through it is still on the stack. The memory gets reused and then when the stack scan tries to extract argument information from the ctxt, it's reading from the overwritten memory.

The ctxt can get GC'd because reflect.makeFuncStub (written in assembly) stores ctxt in its frame, but claims it has no local pointers, and then calls reflect.callReflect, which stops using the ctxt argument before the actual call, so the compiler marks it as not live.

@gopherbot
Copy link

CL https://golang.org/cl/35151 mentions this issue.

@golang golang locked and limited conversation to collaborators Jan 13, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

6 participants