]> Cypherpunks repositories - gostls13.git/commitdiff
runtime: emit trace stacks for more goroutines in each generation
authorMichael Anthony Knyszek <mknyszek@google.com>
Mon, 26 Feb 2024 19:51:31 +0000 (19:51 +0000)
committerGopher Robot <gobot@golang.org>
Fri, 5 Apr 2024 20:42:48 +0000 (20:42 +0000)
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 <mknyszek@google.com>
Reviewed-by: David Chase <drchase@google.com>
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>

src/internal/trace/v2/base.go
src/internal/trace/v2/event.go
src/internal/trace/v2/event/go122/event.go
src/internal/trace/v2/oldtrace.go
src/internal/trace/v2/order.go
src/runtime/trace2.go
src/runtime/trace2event.go
src/runtime/trace2runtime.go
src/runtime/trace2stack.go
src/runtime/trace2status.go

index e2ba09362b95d1f29c5fe4e646981757e3c2a658..bcc441493616be220415b448c3aaa982730b7a90 100644 (file)
@@ -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
index 55bc88455c9f7f37a579676917db36751ff9b708..a1eb220dbd8bc47cefc7fa51e2c592ca758bb4fd 100644 (file)
@@ -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,
 }
 
index ace11be462cc6a068ff30a207e06d7dbe9a18da6..5bb9bf1837b87d51d15aff79e68787148474cee2 100644 (file)
@@ -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
index b0586fe92ad47023c90f5640d1940c338d7ee713..29b7173a3a588a967fb30f223bf0f97cd9d0d78e 100644 (file)
@@ -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)
        }
index e5fcd20a611ccdaf9133a25604885ae1ed41b340..b2aa551455f87e9ac815bfca957dbada380ccc80 100644 (file)
@@ -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) {
index a5ea9b4aa1c58ebdbe4123ecfdd88508c4462cd5..12647ca43bd2b8aa87e911d492c1e6fd73b43792 100644 (file)
@@ -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()
 
index c56887482177c0d87d27ed3915e2e39f1134ade4..26bb52f768d03612fabc3abc7c7568ce6f695842 100644 (file)
@@ -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
index 3e55226f28d648330e3b9a141b7c3fd9493f004b..6623879e6b45fb0eb464d54a59b5eebd4525e640 100644 (file)
@@ -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
 }
index af6638fa8f088593e627aa631bdc7d2a24d136dc..44588fa39e44c8b0ae2a92a59389832cf9dd091a 100644 (file)
@@ -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])
index 34f2e4c06f85bd8d275ba76502a29e0c0373c36e..48ecb363a6a1b4c4f7585cebc90c29e86703ebe6 100644 (file)
@@ -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 {