runtime/trace: using cgo introduces goroutine with empty stack

[dominikh]

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

$ go version
go version devel go1.21-a031f4ef83 Sat Jun 24 05:24:25 2023 +0000 linux/amd64

Does this issue reproduce with the latest release?

Yes

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

go env Output

$ go env
GO111MODULE=''
GOARCH='amd64'
GOBIN=''
GOCACHE='/home/dominikh/.cache/go-build'
GOENV='/home/dominikh/.config/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='amd64'
GOHOSTOS='linux'
GOINSECURE=''
GOMODCACHE='/home/dominikh/prj/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='linux'
GOPATH='/home/dominikh/prj'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/home/dominikh/prj/go'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/home/dominikh/prj/go/pkg/tool/linux_amd64'
GOVCS=''
GOVERSION='devel go1.21-a031f4ef83 Sat Jun 24 05:24:25 2023 +0000'
GCCGO='gccgo'
GOAMD64='v1'
AR='ar'
CC='gcc'
CXX='g++'
CGO_ENABLED='1'
GOMOD='/home/dominikh/prj/src/example.com/go.mod'
GOWORK=''
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
PKG_CONFIG='pkg-config'
GOGCCFLAGS='-fPIC -m64 -pthread -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=/tmp/go-build1830765016=/tmp/go-build -gno-record-gcc-switches'

What did you do?

package main

import "C"

import (
	"os"
	"runtime/trace"
)

func main() {
	trace.Start(os.Stdout)
	trace.Stop()
}

What did you see?

The produced trace contains the following two events:

420 GoCreate p=0 g=0 off=30 g=17 stack=3
456 GoInSyscall p=0 g=17 off=36 g=17

The EvStack for stack 3 contains a single frame, with all values set to zero.

The goroutine seems to be so special that its stack doesn't get printed when sending SIGQUIT to the process.

I've only observed this when using cgo.

/cc @mknyszek

[nsrip-dd]

I have noticed this as well. From my investigation, this appears to be an extra goroutine created for cgo programs in anticipation of C-to-Go calls. It's created here in oneNewExtraM with no starting PC. The goroutine will get used in programs where C-created threads call Go code. The creation and InSyscall events get emitted here at the beginning of tracing with a stack with just PC 0 (added in CL 429858) and we see more events for that goroutine if a C-created thread calls back into Go. The goroutine is missing when printing all stacks because its status starts out as _Gdead, so it gets skipped.

[cagedmantis]

/cc @golang/runtime

[prattmic]

I believe that @nsrip-dd is correct, this is the G from oneNewExtraM, which will be used when executing cgo callbacks that come from a non-Go thread.

This is perhaps an unfortunate internal detail to expose, but I'm not sure we can/should change the trace output? In theory I suppose it would make more sense to delay the GoCreate until a cgo callback actually occurs, but should we do that on every callback that reuses the same G or only the first call?

[mknyszek]

@nsrip-dd is exactly right. I think it needs to operate this way because of the existing requirements around goroutine states. The first thing such a goroutine ever does is, IIRC, emit a GoSysExit event, so the trace parser's state needs to be ready for this event which would otherwise come out of nowhere.

It is a little bit weird that this is treated as "the goroutine has been in a syscall the whole time." That aligns with how the runtime views the goroutine for sure, but not necessarily with how these goroutines behave from a user's perspective. We could, for instance, just pretend the goroutine is created and destroyed on each C->Go call (and return). The GoCreate event could then have the PC of the Go entrypoint for the C->Go call as its starting stack.

I imagine the reason this wasn't modeled this way originally is because it's a bit more complex. The GoSysExit event already has a special case for being emitted upon exiting the scheduler, and this becomes yet-another special case. Not saying this is sufficient reason to not model it this way, though.

[mknyszek]

I believe this might be fixed in the new tracer. The tracer now models this extra M goroutine as being created and destroyed, and I don't immediately see how a dead goroutine would ever end up in the trace now. (We try to 'suspend' every goroutine but it might just be dead, in which case we'll do nothing.) Closing optimistically.