From 5879bf7e38ac49e2e0caddd11cd4ddd4a4782437 Mon Sep 17 00:00:00 2001 From: Michael Anthony Knyszek Date: Mon, 26 Feb 2024 19:51:31 +0000 Subject: [PATCH] runtime: emit trace stacks for more goroutines in each generation This change adds a new event, GoStatusStack, which is like GoStatus but also carries a stack ID. The purpose of this event is to emit stacks in more places, in particular for goroutines that may never emit a stack-bearing event in a whole generation. This CL targets one specific case: goroutines that were blocked or in a syscall the entire generation. This particular case is handled at the point that we scribble down the goroutine's status before the generation transition. That way, when we're finishing up the generation and emitting events for any goroutines we scribbled down, we have an accurate stack for those goroutines ready to go, and we emit a GoStatusStack instead of a GoStatus event. There's a small drawback with the way we scribble down the stack though: we immediately register it in the stack table instead of tracking the PCs. This means that if a goroutine does run and emit a trace event in between when we scribbled down its stack and the end of the generation, we will have recorded a stack that never actually gets referenced in the trace. This case should be rare. There are two remaining cases where we could emit stacks for goroutines but we don't. One is goroutines that get unblocked but either never run, or run and never block within a generation. We could take a stack trace at the point of unblocking the goroutine, if we're emitting a GoStatus event for it, but unfortunately we don't own the stack at that point. We could obtain ownership by grabbing its _Gscan bit, but that seems a little risky, since we could hold up the goroutine emitting the event for a while. Something to consider for the future. The other remaining case is a goroutine that was runnable when tracing started and began running, but then ran until the end of the generation without getting preempted or blocking. The main issue here is that although the goroutine will have a GoStatus event, it'll only have a GoStart event for it which doesn't emit a stack trace. This case is rare, but still certainly possible. I believe the only way to resolve it is to emit a GoStatusStack event instead of a GoStatus event for a goroutine that we're emitting GoStart for. This case is a bit easier than the last one because at the point of emitting GoStart, we have ownership of the goroutine's stack. We may consider dealing with these in the future, but for now, this CL captures a fairly large class of goroutines, so is worth it on its own. Fixes #65634. Change-Id: Ief3b6df5848b426e7ee6794e98dc7ef5f37ab2d0 Reviewed-on: https://go-review.googlesource.com/c/go/+/567076 Auto-Submit: Michael Knyszek Reviewed-by: David Chase LUCI-TryBot-Result: Go LUCI --- src/internal/trace/v2/base.go | 14 ++++- src/internal/trace/v2/event.go | 3 +- src/internal/trace/v2/event/go122/event.go | 9 +++ src/internal/trace/v2/oldtrace.go | 69 +++++++++++----------- src/internal/trace/v2/order.go | 3 + src/runtime/trace2.go | 4 +- src/runtime/trace2event.go | 7 ++- src/runtime/trace2runtime.go | 5 +- src/runtime/trace2stack.go | 46 ++++++++++----- src/runtime/trace2status.go | 8 ++- 10 files changed, 109 insertions(+), 59 deletions(-) diff --git a/src/internal/trace/v2/base.go b/src/internal/trace/v2/base.go index e2ba09362b..bcc4414936 100644 --- a/src/internal/trace/v2/base.go +++ b/src/internal/trace/v2/base.go @@ -18,15 +18,23 @@ import ( ) // maxArgs is the maximum number of arguments for "plain" events, -// i.e. anything that could reasonably be represented as a Base. -const maxArgs = 5 +// i.e. anything that could reasonably be represented as a baseEvent. +// +// TODO(mknyszek): This is only 6 instead of 5 because GoStatusStack +// has 5 arguments and needs to smuggle in a 6th. Figure out a way to +// shrink this in the future. +const maxArgs = 6 + +// timedEventArgs is an array that is able to hold the arguments for any +// timed event. +type timedEventArgs [maxArgs - 1]uint64 // baseEvent is the basic unprocessed event. This serves as a common // fundamental data structure across. type baseEvent struct { typ event.Type time Time - args [maxArgs - 1]uint64 + args timedEventArgs } // extra returns a slice representing extra available space in args diff --git a/src/internal/trace/v2/event.go b/src/internal/trace/v2/event.go index 55bc88455c..a1eb220dbd 100644 --- a/src/internal/trace/v2/event.go +++ b/src/internal/trace/v2/event.go @@ -604,7 +604,7 @@ func (e Event) StateTransition() StateTransition { case go122.EvGoSyscallEndBlocked: s = goStateTransition(e.ctx.G, GoSyscall, GoRunnable) s.Stack = e.Stack() // This event references the resource the event happened on. - case go122.EvGoStatus: + case go122.EvGoStatus, go122.EvGoStatusStack: // N.B. ordering.advance populates e.base.extra. s = goStateTransition(GoID(e.base.args[0]), GoState(e.base.extra(version.Go122)[0]), go122GoStatus2GoState[e.base.args[2]]) default: @@ -656,6 +656,7 @@ var go122Type2Kind = [...]EventKind{ go122.EvGoSwitch: EventStateTransition, go122.EvGoSwitchDestroy: EventStateTransition, go122.EvGoCreateBlocked: EventStateTransition, + go122.EvGoStatusStack: EventStateTransition, evSync: EventSync, } diff --git a/src/internal/trace/v2/event/go122/event.go b/src/internal/trace/v2/event/go122/event.go index ace11be462..5bb9bf1837 100644 --- a/src/internal/trace/v2/event/go122/event.go +++ b/src/internal/trace/v2/event/go122/event.go @@ -72,6 +72,9 @@ const ( EvGoSwitch // goroutine switch (coroswitch) [timestamp, goroutine ID, goroutine seq] EvGoSwitchDestroy // goroutine switch and destroy [timestamp, goroutine ID, goroutine seq] EvGoCreateBlocked // goroutine creation (starts blocked) [timestamp, new goroutine ID, new stack ID, stack ID] + + // GoStatus with stack. + EvGoStatusStack // goroutine status at the start of a generation, with a stack [timestamp, goroutine ID, M ID, status, stack ID] ) // EventString returns the name of a Go 1.22 event. @@ -353,6 +356,12 @@ var specs = [...]event.Spec{ IsTimedEvent: true, StackIDs: []int{3, 2}, }, + EvGoStatusStack: event.Spec{ + Name: "GoStatusStack", + Args: []string{"dt", "g", "m", "gstatus", "stack"}, + IsTimedEvent: true, + StackIDs: []int{4}, + }, } type GoStatus uint8 diff --git a/src/internal/trace/v2/oldtrace.go b/src/internal/trace/v2/oldtrace.go index b0586fe92a..29b7173a3a 100644 --- a/src/internal/trace/v2/oldtrace.go +++ b/src/internal/trace/v2/oldtrace.go @@ -254,7 +254,8 @@ var errSkip = errors.New("skip event") // returns a descriptive error. func (it *oldTraceConverter) convertEvent(ev *oldtrace.Event) (OUT Event, ERR error) { var mappedType event.Type - mappedArgs := ev.Args + var mappedArgs timedEventArgs + copy(mappedArgs[:], ev.Args[:]) switch ev.Type { case oldtrace.EvGomaxprocs: @@ -278,7 +279,7 @@ func (it *oldTraceConverter) convertEvent(ev *oldtrace.Event) (OUT Event, ERR er base: baseEvent{ typ: go122.EvGoStatus, time: Time(ev.Ts), - args: [4]uint64{uint64(gid), ^uint64(0), uint64(go122.GoRunnable)}, + args: timedEventArgs{uint64(gid), ^uint64(0), uint64(go122.GoRunnable)}, }, }) } @@ -289,20 +290,20 @@ func (it *oldTraceConverter) convertEvent(ev *oldtrace.Event) (OUT Event, ERR er it.procMs[ProcID(ev.P)] = ThreadID(ev.Args[0]) if _, ok := it.seenProcs[ProcID(ev.P)]; ok { mappedType = go122.EvProcStart - mappedArgs = [4]uint64{uint64(ev.P)} + mappedArgs = timedEventArgs{uint64(ev.P)} } else { it.seenProcs[ProcID(ev.P)] = struct{}{} mappedType = go122.EvProcStatus - mappedArgs = [4]uint64{uint64(ev.P), uint64(go122.ProcRunning)} + mappedArgs = timedEventArgs{uint64(ev.P), uint64(go122.ProcRunning)} } case oldtrace.EvProcStop: if _, ok := it.seenProcs[ProcID(ev.P)]; ok { mappedType = go122.EvProcStop - mappedArgs = [4]uint64{uint64(ev.P)} + mappedArgs = timedEventArgs{uint64(ev.P)} } else { it.seenProcs[ProcID(ev.P)] = struct{}{} mappedType = go122.EvProcStatus - mappedArgs = [4]uint64{uint64(ev.P), uint64(go122.ProcIdle)} + mappedArgs = timedEventArgs{uint64(ev.P), uint64(go122.ProcIdle)} } case oldtrace.EvGCStart: mappedType = go122.EvGCBegin @@ -312,10 +313,10 @@ func (it *oldTraceConverter) convertEvent(ev *oldtrace.Event) (OUT Event, ERR er sid := it.builtinToStringID[sSTWUnknown+it.trace.STWReason(ev.Args[0])] it.lastStwReason = sid mappedType = go122.EvSTWBegin - mappedArgs = [4]uint64{uint64(sid)} + mappedArgs = timedEventArgs{uint64(sid)} case oldtrace.EvSTWDone: mappedType = go122.EvSTWEnd - mappedArgs = [4]uint64{it.lastStwReason} + mappedArgs = timedEventArgs{it.lastStwReason} case oldtrace.EvGCSweepStart: mappedType = go122.EvGCSweepBegin case oldtrace.EvGCSweepDone: @@ -329,7 +330,7 @@ func (it *oldTraceConverter) convertEvent(ev *oldtrace.Event) (OUT Event, ERR er case oldtrace.EvGoStart: if it.preInit { mappedType = go122.EvGoStatus - mappedArgs = [4]uint64{ev.Args[0], ^uint64(0), uint64(go122.GoRunning)} + mappedArgs = timedEventArgs{ev.Args[0], ^uint64(0), uint64(go122.GoRunning)} delete(it.createdPreInit, GoID(ev.Args[0])) } else { mappedType = go122.EvGoStart @@ -345,7 +346,7 @@ func (it *oldTraceConverter) convertEvent(ev *oldtrace.Event) (OUT Event, ERR er base: baseEvent{ typ: go122.EvGoLabel, time: Time(ev.Ts), - args: [4]uint64{ev.Args[2]}, + args: timedEventArgs{ev.Args[2]}, }, }} return Event{ @@ -358,49 +359,49 @@ func (it *oldTraceConverter) convertEvent(ev *oldtrace.Event) (OUT Event, ERR er base: baseEvent{ typ: go122.EvGoStart, time: Time(ev.Ts), - args: ev.Args, + args: mappedArgs, }, }, nil case oldtrace.EvGoEnd: mappedType = go122.EvGoDestroy case oldtrace.EvGoStop: mappedType = go122.EvGoBlock - mappedArgs = [4]uint64{uint64(it.builtinToStringID[sForever]), uint64(ev.StkID)} + mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sForever]), uint64(ev.StkID)} case oldtrace.EvGoSched: mappedType = go122.EvGoStop - mappedArgs = [4]uint64{uint64(it.builtinToStringID[sGosched]), uint64(ev.StkID)} + mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sGosched]), uint64(ev.StkID)} case oldtrace.EvGoPreempt: mappedType = go122.EvGoStop - mappedArgs = [4]uint64{uint64(it.builtinToStringID[sPreempted]), uint64(ev.StkID)} + mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sPreempted]), uint64(ev.StkID)} case oldtrace.EvGoSleep: mappedType = go122.EvGoBlock - mappedArgs = [4]uint64{uint64(it.builtinToStringID[sSleep]), uint64(ev.StkID)} + mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sSleep]), uint64(ev.StkID)} case oldtrace.EvGoBlock: mappedType = go122.EvGoBlock - mappedArgs = [4]uint64{uint64(it.builtinToStringID[sEmpty]), uint64(ev.StkID)} + mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sEmpty]), uint64(ev.StkID)} case oldtrace.EvGoUnblock: mappedType = go122.EvGoUnblock case oldtrace.EvGoBlockSend: mappedType = go122.EvGoBlock - mappedArgs = [4]uint64{uint64(it.builtinToStringID[sChanSend]), uint64(ev.StkID)} + mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sChanSend]), uint64(ev.StkID)} case oldtrace.EvGoBlockRecv: mappedType = go122.EvGoBlock - mappedArgs = [4]uint64{uint64(it.builtinToStringID[sChanRecv]), uint64(ev.StkID)} + mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sChanRecv]), uint64(ev.StkID)} case oldtrace.EvGoBlockSelect: mappedType = go122.EvGoBlock - mappedArgs = [4]uint64{uint64(it.builtinToStringID[sSelect]), uint64(ev.StkID)} + mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sSelect]), uint64(ev.StkID)} case oldtrace.EvGoBlockSync: mappedType = go122.EvGoBlock - mappedArgs = [4]uint64{uint64(it.builtinToStringID[sSync]), uint64(ev.StkID)} + mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sSync]), uint64(ev.StkID)} case oldtrace.EvGoBlockCond: mappedType = go122.EvGoBlock - mappedArgs = [4]uint64{uint64(it.builtinToStringID[sSyncCond]), uint64(ev.StkID)} + mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sSyncCond]), uint64(ev.StkID)} case oldtrace.EvGoBlockNet: mappedType = go122.EvGoBlock - mappedArgs = [4]uint64{uint64(it.builtinToStringID[sNetwork]), uint64(ev.StkID)} + mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sNetwork]), uint64(ev.StkID)} case oldtrace.EvGoBlockGC: mappedType = go122.EvGoBlock - mappedArgs = [4]uint64{uint64(it.builtinToStringID[sMarkAssistWait]), uint64(ev.StkID)} + mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sMarkAssistWait]), uint64(ev.StkID)} case oldtrace.EvGoSysCall: // Look for the next event for the same G to determine if the syscall // blocked. @@ -419,7 +420,7 @@ func (it *oldTraceConverter) convertEvent(ev *oldtrace.Event) (OUT Event, ERR er }) if blocked { mappedType = go122.EvGoSyscallBegin - mappedArgs = [4]uint64{1: uint64(ev.StkID)} + mappedArgs = timedEventArgs{1: uint64(ev.StkID)} } else { // Convert the old instantaneous syscall event to a pair of syscall // begin and syscall end and give it the shortest possible duration, @@ -434,7 +435,7 @@ func (it *oldTraceConverter) convertEvent(ev *oldtrace.Event) (OUT Event, ERR er base: baseEvent{ typ: go122.EvGoSyscallBegin, time: Time(ev.Ts), - args: [4]uint64{1: uint64(ev.StkID)}, + args: timedEventArgs{1: uint64(ev.StkID)}, }, } @@ -444,7 +445,7 @@ func (it *oldTraceConverter) convertEvent(ev *oldtrace.Event) (OUT Event, ERR er base: baseEvent{ typ: go122.EvGoSyscallEnd, time: Time(ev.Ts + 1), - args: [4]uint64{}, + args: timedEventArgs{}, }, } @@ -458,14 +459,14 @@ func (it *oldTraceConverter) convertEvent(ev *oldtrace.Event) (OUT Event, ERR er return Event{}, errSkip case oldtrace.EvGoWaiting: mappedType = go122.EvGoStatus - mappedArgs = [4]uint64{ev.Args[0], ^uint64(0), uint64(go122.GoWaiting)} + mappedArgs = timedEventArgs{ev.Args[0], ^uint64(0), uint64(go122.GoWaiting)} delete(it.createdPreInit, GoID(ev.Args[0])) case oldtrace.EvGoInSyscall: mappedType = go122.EvGoStatus // In the new tracer, GoStatus with GoSyscall knows what thread the // syscall is on. In the old tracer, EvGoInSyscall doesn't contain that // information and all we can do here is specify NoThread. - mappedArgs = [4]uint64{ev.Args[0], ^uint64(0), uint64(go122.GoSyscall)} + mappedArgs = timedEventArgs{ev.Args[0], ^uint64(0), uint64(go122.GoSyscall)} delete(it.createdPreInit, GoID(ev.Args[0])) case oldtrace.EvHeapAlloc: mappedType = go122.EvHeapAlloc @@ -481,7 +482,7 @@ func (it *oldTraceConverter) convertEvent(ev *oldtrace.Event) (OUT Event, ERR er if parent == 0 { parent = uint64(NoTask) } - mappedArgs = [4]uint64{ev.Args[0], parent, ev.Args[2], uint64(ev.StkID)} + mappedArgs = timedEventArgs{ev.Args[0], parent, ev.Args[2], uint64(ev.StkID)} name, _ := it.evt.strings.get(stringID(ev.Args[2])) it.tasks[TaskID(ev.Args[0])] = taskState{name: name, parentID: TaskID(ev.Args[1])} case oldtrace.EvUserTaskEnd: @@ -491,14 +492,14 @@ func (it *oldTraceConverter) convertEvent(ev *oldtrace.Event) (OUT Event, ERR er ts, ok := it.tasks[TaskID(ev.Args[0])] if ok { delete(it.tasks, TaskID(ev.Args[0])) - mappedArgs = [4]uint64{ + mappedArgs = timedEventArgs{ ev.Args[0], ev.Args[1], uint64(ts.parentID), uint64(it.evt.addExtraString(ts.name)), } } else { - mappedArgs = [4]uint64{ev.Args[0], ev.Args[1], uint64(NoTask), uint64(it.evt.addExtraString(""))} + mappedArgs = timedEventArgs{ev.Args[0], ev.Args[1], uint64(NoTask), uint64(it.evt.addExtraString(""))} } case oldtrace.EvUserRegion: switch ev.Args[1] { @@ -507,10 +508,10 @@ func (it *oldTraceConverter) convertEvent(ev *oldtrace.Event) (OUT Event, ERR er case 1: // end mappedType = go122.EvUserRegionEnd } - mappedArgs = [4]uint64{ev.Args[0], ev.Args[2], uint64(ev.StkID)} + mappedArgs = timedEventArgs{ev.Args[0], ev.Args[2], uint64(ev.StkID)} case oldtrace.EvUserLog: mappedType = go122.EvUserLog - mappedArgs = [4]uint64{ev.Args[0], ev.Args[1], it.inlineToStringID[ev.Args[3]], uint64(ev.StkID)} + mappedArgs = timedEventArgs{ev.Args[0], ev.Args[1], it.inlineToStringID[ev.Args[3]], uint64(ev.StkID)} case oldtrace.EvCPUSample: mappedType = go122.EvCPUSample // When emitted by the Go 1.22 tracer, CPU samples have 5 arguments: @@ -518,7 +519,7 @@ func (it *oldTraceConverter) convertEvent(ev *oldtrace.Event) (OUT Event, ERR er // they have the arguments stack, M, P, G. // // In Go 1.21, CPU samples did not have Ms. - mappedArgs = [4]uint64{uint64(ev.StkID), ^uint64(0), uint64(ev.P), ev.G} + mappedArgs = timedEventArgs{uint64(ev.StkID), ^uint64(0), uint64(ev.P), ev.G} default: return Event{}, fmt.Errorf("unexpected event type %v", ev.Type) } diff --git a/src/internal/trace/v2/order.go b/src/internal/trace/v2/order.go index e5fcd20a61..b2aa551455 100644 --- a/src/internal/trace/v2/order.go +++ b/src/internal/trace/v2/order.go @@ -140,6 +140,9 @@ var orderingDispatch = [256]orderingHandleFunc{ go122.EvGoSwitch: (*ordering).advanceGoSwitch, go122.EvGoSwitchDestroy: (*ordering).advanceGoSwitch, go122.EvGoCreateBlocked: (*ordering).advanceGoCreate, + + // GoStatus event with a stack. Added in Go 1.23. + go122.EvGoStatusStack: (*ordering).advanceGoStatus, } func (o *ordering) advanceProcStatus(ev *baseEvent, evt *evTable, m ThreadID, gen uint64, curCtx schedCtx) (schedCtx, bool, error) { diff --git a/src/runtime/trace2.go b/src/runtime/trace2.go index a5ea9b4aa1..12647ca43b 100644 --- a/src/runtime/trace2.go +++ b/src/runtime/trace2.go @@ -323,6 +323,7 @@ func traceAdvance(stopTrace bool) { gp *g goid uint64 mid int64 + stackID uint64 status uint32 waitreason waitReason inMarkAssist bool @@ -366,6 +367,7 @@ func traceAdvance(stopTrace bool) { ug.status = readgstatus(s.g) &^ _Gscan ug.waitreason = s.g.waitreason ug.inMarkAssist = s.g.inMarkAssist + ug.stackID = traceStack(0, gp, gen) } resumeG(s) casgstatus(me, _Gwaiting, _Grunning) @@ -542,7 +544,7 @@ func traceAdvance(stopTrace bool) { // traced in gen between when we recorded it and now. If that's true, the goid // and status we recorded then is exactly what we want right now. status := goStatusToTraceGoStatus(ug.status, ug.waitreason) - statusWriter = statusWriter.writeGoStatus(ug.goid, ug.mid, status, ug.inMarkAssist) + statusWriter = statusWriter.writeGoStatus(ug.goid, ug.mid, status, ug.inMarkAssist, ug.stackID) } statusWriter.flush().end() diff --git a/src/runtime/trace2event.go b/src/runtime/trace2event.go index c568874821..26bb52f768 100644 --- a/src/runtime/trace2event.go +++ b/src/runtime/trace2event.go @@ -86,6 +86,9 @@ const ( traceEvGoSwitch // goroutine switch (coroswitch) [timestamp, goroutine ID, goroutine seq] traceEvGoSwitchDestroy // goroutine switch and destroy [timestamp, goroutine ID, goroutine seq] traceEvGoCreateBlocked // goroutine creation (starts blocked) [timestamp, new goroutine ID, new stack ID, stack ID] + + // GoStatus with stack. + traceEvGoStatusStack // goroutine status at the start of a generation, with a stack [timestamp, goroutine ID, M ID, status, stack ID] ) // traceArg is a simple wrapper type to help ensure that arguments passed @@ -119,7 +122,7 @@ func (tl traceLocker) eventWriter(goStatus traceGoStatus, procStatus traceProcSt w = w.writeProcStatus(uint64(pp.id), procStatus, pp.trace.inSweep) } if gp := tl.mp.curg; gp != nil && !gp.trace.statusWasTraced(tl.gen) && gp.trace.acquireStatus(tl.gen) { - w = w.writeGoStatus(uint64(gp.goid), int64(tl.mp.procid), goStatus, gp.inMarkAssist) + w = w.writeGoStatus(uint64(gp.goid), int64(tl.mp.procid), goStatus, gp.inMarkAssist, 0 /* no stack */) } return traceEventWriter{w} } @@ -168,7 +171,7 @@ func (w traceWriter) event(ev traceEv, args ...traceArg) traceWriter { // It then returns a traceArg representing that stack which may be // passed to write. func (tl traceLocker) stack(skip int) traceArg { - return traceArg(traceStack(skip, tl.mp, tl.gen)) + return traceArg(traceStack(skip, nil, tl.gen)) } // startPC takes a start PC for a goroutine and produces a unique diff --git a/src/runtime/trace2runtime.go b/src/runtime/trace2runtime.go index 3e55226f28..6623879e6b 100644 --- a/src/runtime/trace2runtime.go +++ b/src/runtime/trace2runtime.go @@ -471,7 +471,10 @@ func (tl traceLocker) GoSwitch(nextg *g, destroy bool) { // unblocked to the trace writer. func emitUnblockStatus(w traceWriter, gp *g, gen uintptr) traceWriter { if !gp.trace.statusWasTraced(gen) && gp.trace.acquireStatus(gen) { - w = w.writeGoStatus(gp.goid, -1, traceGoWaiting, gp.inMarkAssist) + // TODO(go.dev/issue/65634): Although it would be nice to add a stack trace here of gp, + // we cannot safely do so. gp is in _Gwaiting and so we don't have ownership of its stack. + // We can fix this by acquiring the goroutine's scan bit. + w = w.writeGoStatus(gp.goid, -1, traceGoWaiting, gp.inMarkAssist, 0) } return w } diff --git a/src/runtime/trace2stack.go b/src/runtime/trace2stack.go index af6638fa8f..44588fa39e 100644 --- a/src/runtime/trace2stack.go +++ b/src/runtime/trace2stack.go @@ -27,8 +27,9 @@ const ( logicalStackSentinel = ^uintptr(0) ) -// traceStack captures a stack trace and registers it in the trace stack table. -// It then returns its unique ID. +// traceStack captures a stack trace from a goroutine and registers it in the trace +// stack table. It then returns its unique ID. If gp == nil, then traceStack will +// attempt to use the current execution context. // // skip controls the number of leaf frames to omit in order to hide tracer internals // from stack traces, see CL 5523. @@ -36,13 +37,22 @@ const ( // Avoid calling this function directly. gen needs to be the current generation // that this stack trace is being written out for, which needs to be synchronized with // generations moving forward. Prefer traceEventWriter.stack. -func traceStack(skip int, mp *m, gen uintptr) uint64 { +func traceStack(skip int, gp *g, gen uintptr) uint64 { var pcBuf [traceStackSize]uintptr - gp := getg() - curgp := gp.m.curg + // Figure out gp and mp for the backtrace. + var mp *m + if gp == nil { + mp = getg().m + gp = mp.curg + } + if gp != nil && mp == nil { + // We're getting the backtrace for a G that's not currently executing. + // It may still have an M, if it's locked to some M. + mp = gp.lockedm.ptr() + } nstk := 1 - if tracefpunwindoff() || mp.hasCgoOnStack() { + if tracefpunwindoff() || (mp != nil && mp.hasCgoOnStack()) { // Slow path: Unwind using default unwinder. Used when frame pointer // unwinding is unavailable or disabled (tracefpunwindoff), or might // produce incomplete results or crashes (hasCgoOnStack). Note that no @@ -50,30 +60,36 @@ func traceStack(skip int, mp *m, gen uintptr) uint64 { // motivation is to take advantage of a potentially registered cgo // symbolizer. pcBuf[0] = logicalStackSentinel - if curgp == gp { + if getg() == gp { nstk += callers(skip+1, pcBuf[1:]) - } else if curgp != nil { - nstk += gcallers(curgp, skip, pcBuf[1:]) + } else if gp != nil { + nstk += gcallers(gp, skip, pcBuf[1:]) } } else { // Fast path: Unwind using frame pointers. pcBuf[0] = uintptr(skip) - if curgp == gp { + if getg() == gp { nstk += fpTracebackPCs(unsafe.Pointer(getfp()), pcBuf[1:]) - } else if curgp != nil { - // We're called on the g0 stack through mcall(fn) or systemstack(fn). To + } else if gp != nil { + // Two cases: + // + // (1) We're called on the g0 stack through mcall(fn) or systemstack(fn). To // behave like gcallers above, we start unwinding from sched.bp, which // points to the caller frame of the leaf frame on g's stack. The return // address of the leaf frame is stored in sched.pc, which we manually // capture here. - pcBuf[1] = curgp.sched.pc - nstk += 1 + fpTracebackPCs(unsafe.Pointer(curgp.sched.bp), pcBuf[2:]) + // + // (2) We're called against a gp that we're not currently executing on, in + // which case it's currently not executing. gp.sched contains the most up-to-date + // information about where it stopped, and like case (1), we match gcallers here. + pcBuf[1] = gp.sched.pc + nstk += 1 + fpTracebackPCs(unsafe.Pointer(gp.sched.bp), pcBuf[2:]) } } if nstk > 0 { nstk-- // skip runtime.goexit } - if nstk > 0 && curgp.goid == 1 { + if nstk > 0 && gp.goid == 1 { nstk-- // skip runtime.main } id := trace.stackTab[gen%2].put(pcBuf[:nstk]) diff --git a/src/runtime/trace2status.go b/src/runtime/trace2status.go index 34f2e4c06f..48ecb363a6 100644 --- a/src/runtime/trace2status.go +++ b/src/runtime/trace2status.go @@ -48,7 +48,7 @@ const ( ) // writeGoStatus emits a GoStatus event as well as any active ranges on the goroutine. -func (w traceWriter) writeGoStatus(goid uint64, mid int64, status traceGoStatus, markAssist bool) traceWriter { +func (w traceWriter) writeGoStatus(goid uint64, mid int64, status traceGoStatus, markAssist bool, stackID uint64) traceWriter { // The status should never be bad. Some invariant must have been violated. if status == traceGoBad { print("runtime: goid=", goid, "\n") @@ -56,7 +56,11 @@ func (w traceWriter) writeGoStatus(goid uint64, mid int64, status traceGoStatus, } // Trace the status. - w = w.event(traceEvGoStatus, traceArg(goid), traceArg(uint64(mid)), traceArg(status)) + if stackID == 0 { + w = w.event(traceEvGoStatus, traceArg(goid), traceArg(uint64(mid)), traceArg(status)) + } else { + w = w.event(traceEvGoStatusStack, traceArg(goid), traceArg(uint64(mid)), traceArg(status), traceArg(stackID)) + } // Trace any special ranges that are in-progress. if markAssist { -- 2.48.1