github.com/go-asm/go@v1.21.1-0.20240213172139-40c5ead50c48/cmd/trace/v2/gstate.go (about)

     1  // Copyright 2023 The Go Authors. All rights reserved.
     2  // Use of this source code is governed by a BSD-style
     3  // license that can be found in the LICENSE file.
     4  
     5  package trace
     6  
     7  import (
     8  	"fmt"
     9  	"strings"
    10  
    11  	"github.com/go-asm/go/trace"
    12  	"github.com/go-asm/go/trace/traceviewer"
    13  	"github.com/go-asm/go/trace/traceviewer/format"
    14  	tracev2 "github.com/go-asm/go/trace/v2"
    15  )
    16  
    17  // resource is a generic constraint interface for resource IDs.
    18  type resource interface {
    19  	tracev2.GoID | tracev2.ProcID | tracev2.ThreadID
    20  }
    21  
    22  // noResource indicates the lack of a resource.
    23  const noResource = -1
    24  
    25  // gState represents the trace viewer state of a goroutine in a trace.
    26  //
    27  // The type parameter on this type is the resource which is used to construct
    28  // a timeline of events. e.g. R=ProcID for a proc-oriented view, R=GoID for
    29  // a goroutine-oriented view, etc.
    30  type gState[R resource] struct {
    31  	baseName  string
    32  	named     bool   // Whether baseName has been set.
    33  	label     string // EventLabel extension.
    34  	isSystemG bool
    35  
    36  	executing R // The resource this goroutine is executing on. (Could be itself.)
    37  
    38  	// lastStopStack is the stack trace at the point of the last
    39  	// call to the stop method. This tends to be a more reliable way
    40  	// of picking up stack traces, since the parser doesn't provide
    41  	// a stack for every state transition event.
    42  	lastStopStack tracev2.Stack
    43  
    44  	// activeRanges is the set of all active ranges on the goroutine.
    45  	activeRanges map[string]activeRange
    46  
    47  	// completedRanges is a list of ranges that completed since before the
    48  	// goroutine stopped executing. These are flushed on every stop or block.
    49  	completedRanges []completedRange
    50  
    51  	// startRunning is the most recent event that caused a goroutine to
    52  	// transition to GoRunning.
    53  	startRunningTime tracev2.Time
    54  
    55  	// startSyscall is the most recent event that caused a goroutine to
    56  	// transition to GoSyscall.
    57  	syscall struct {
    58  		time   tracev2.Time
    59  		stack  tracev2.Stack
    60  		active bool
    61  	}
    62  
    63  	// startBlockReason is the StateTransition.Reason of the most recent
    64  	// event that caused a gorotuine to transition to GoWaiting.
    65  	startBlockReason string
    66  
    67  	// startCause is the event that allowed this goroutine to start running.
    68  	// It's used to generate flow events. This is typically something like
    69  	// an unblock event or a goroutine creation event.
    70  	//
    71  	// startCause.resource is the resource on which startCause happened, but is
    72  	// listed separately because the cause may have happened on a resource that
    73  	// isn't R (or perhaps on some abstract nebulous resource, like trace.NetpollP).
    74  	startCause struct {
    75  		time     tracev2.Time
    76  		name     string
    77  		resource uint64
    78  		stack    tracev2.Stack
    79  	}
    80  }
    81  
    82  // newGState constructs a new goroutine state for the goroutine
    83  // identified by the provided ID.
    84  func newGState[R resource](goID tracev2.GoID) *gState[R] {
    85  	return &gState[R]{
    86  		baseName:     fmt.Sprintf("G%d", goID),
    87  		executing:    R(noResource),
    88  		activeRanges: make(map[string]activeRange),
    89  	}
    90  }
    91  
    92  // augmentName attempts to use stk to augment the name of the goroutine
    93  // with stack information. This stack must be related to the goroutine
    94  // in some way, but it doesn't really matter which stack.
    95  func (gs *gState[R]) augmentName(stk tracev2.Stack) {
    96  	if gs.named {
    97  		return
    98  	}
    99  	if stk == tracev2.NoStack {
   100  		return
   101  	}
   102  	name := lastFunc(stk)
   103  	gs.baseName += fmt.Sprintf(" %s", name)
   104  	gs.named = true
   105  	gs.isSystemG = trace.IsSystemGoroutine(name)
   106  }
   107  
   108  // setLabel adds an additional label to the goroutine's name.
   109  func (gs *gState[R]) setLabel(label string) {
   110  	gs.label = label
   111  }
   112  
   113  // name returns a name for the goroutine.
   114  func (gs *gState[R]) name() string {
   115  	name := gs.baseName
   116  	if gs.label != "" {
   117  		name += " (" + gs.label + ")"
   118  	}
   119  	return name
   120  }
   121  
   122  // setStartCause sets the reason a goroutine will be allowed to start soon.
   123  // For example, via unblocking or exiting a blocked syscall.
   124  func (gs *gState[R]) setStartCause(ts tracev2.Time, name string, resource uint64, stack tracev2.Stack) {
   125  	gs.startCause.time = ts
   126  	gs.startCause.name = name
   127  	gs.startCause.resource = resource
   128  	gs.startCause.stack = stack
   129  }
   130  
   131  // created indicates that this goroutine was just created by the provided creator.
   132  func (gs *gState[R]) created(ts tracev2.Time, creator R, stack tracev2.Stack) {
   133  	if creator == R(noResource) {
   134  		return
   135  	}
   136  	gs.setStartCause(ts, "go", uint64(creator), stack)
   137  }
   138  
   139  // start indicates that a goroutine has started running on a proc.
   140  func (gs *gState[R]) start(ts tracev2.Time, resource R, ctx *traceContext) {
   141  	// Set the time for all the active ranges.
   142  	for name := range gs.activeRanges {
   143  		gs.activeRanges[name] = activeRange{ts, tracev2.NoStack}
   144  	}
   145  
   146  	if gs.startCause.name != "" {
   147  		// It has a start cause. Emit a flow event.
   148  		ctx.Arrow(traceviewer.ArrowEvent{
   149  			Name:         gs.startCause.name,
   150  			Start:        ctx.elapsed(gs.startCause.time),
   151  			End:          ctx.elapsed(ts),
   152  			FromResource: uint64(gs.startCause.resource),
   153  			ToResource:   uint64(resource),
   154  			FromStack:    ctx.Stack(viewerFrames(gs.startCause.stack)),
   155  		})
   156  		gs.startCause.time = 0
   157  		gs.startCause.name = ""
   158  		gs.startCause.resource = 0
   159  		gs.startCause.stack = tracev2.NoStack
   160  	}
   161  	gs.executing = resource
   162  	gs.startRunningTime = ts
   163  }
   164  
   165  // syscallBegin indicates that the goroutine entered a syscall on a proc.
   166  func (gs *gState[R]) syscallBegin(ts tracev2.Time, resource R, stack tracev2.Stack) {
   167  	gs.syscall.time = ts
   168  	gs.syscall.stack = stack
   169  	gs.syscall.active = true
   170  	if gs.executing == R(noResource) {
   171  		gs.executing = resource
   172  		gs.startRunningTime = ts
   173  	}
   174  }
   175  
   176  // syscallEnd ends the syscall slice, wherever the syscall is at. This is orthogonal
   177  // to blockedSyscallEnd -- both must be called when a syscall ends and that syscall
   178  // blocked. They're kept separate because syscallEnd indicates the point at which the
   179  // goroutine is no longer executing on the resource (e.g. a proc) whereas blockedSyscallEnd
   180  // is the point at which the goroutine actually exited the syscall regardless of which
   181  // resource that happened on.
   182  func (gs *gState[R]) syscallEnd(ts tracev2.Time, blocked bool, ctx *traceContext) {
   183  	if !gs.syscall.active {
   184  		return
   185  	}
   186  	blockString := "no"
   187  	if blocked {
   188  		blockString = "yes"
   189  	}
   190  	gs.completedRanges = append(gs.completedRanges, completedRange{
   191  		name:       "syscall",
   192  		startTime:  gs.syscall.time,
   193  		endTime:    ts,
   194  		startStack: gs.syscall.stack,
   195  		arg:        format.BlockedArg{Blocked: blockString},
   196  	})
   197  	gs.syscall.active = false
   198  	gs.syscall.time = 0
   199  	gs.syscall.stack = tracev2.NoStack
   200  }
   201  
   202  // blockedSyscallEnd indicates the point at which the blocked syscall ended. This is distinct
   203  // and orthogonal to syscallEnd; both must be called if the syscall blocked. This sets up an instant
   204  // to emit a flow event from, indicating explicitly that this goroutine was unblocked by the system.
   205  func (gs *gState[R]) blockedSyscallEnd(ts tracev2.Time, stack tracev2.Stack, ctx *traceContext) {
   206  	name := "exit blocked syscall"
   207  	gs.setStartCause(ts, name, trace.SyscallP, stack)
   208  
   209  	// Emit an syscall exit instant event for the "Syscall" lane.
   210  	ctx.Instant(traceviewer.InstantEvent{
   211  		Name:     name,
   212  		Ts:       ctx.elapsed(ts),
   213  		Resource: trace.SyscallP,
   214  		Stack:    ctx.Stack(viewerFrames(stack)),
   215  	})
   216  }
   217  
   218  // unblock indicates that the goroutine gs represents has been unblocked.
   219  func (gs *gState[R]) unblock(ts tracev2.Time, stack tracev2.Stack, resource R, ctx *traceContext) {
   220  	name := "unblock"
   221  	viewerResource := uint64(resource)
   222  	if gs.startBlockReason != "" {
   223  		name = fmt.Sprintf("%s (%s)", name, gs.startBlockReason)
   224  	}
   225  	if strings.Contains(gs.startBlockReason, "network") {
   226  		// Attribute the network instant to the nebulous "NetpollP" if
   227  		// resource isn't a thread, because there's a good chance that
   228  		// resource isn't going to be valid in this case.
   229  		//
   230  		// TODO(mknyszek): Handle this invalidness in a more general way.
   231  		if _, ok := any(resource).(tracev2.ThreadID); !ok {
   232  			// Emit an unblock instant event for the "Network" lane.
   233  			viewerResource = trace.NetpollP
   234  		}
   235  		ctx.Instant(traceviewer.InstantEvent{
   236  			Name:     name,
   237  			Ts:       ctx.elapsed(ts),
   238  			Resource: viewerResource,
   239  			Stack:    ctx.Stack(viewerFrames(stack)),
   240  		})
   241  	}
   242  	gs.startBlockReason = ""
   243  	if viewerResource != 0 {
   244  		gs.setStartCause(ts, name, viewerResource, stack)
   245  	}
   246  }
   247  
   248  // block indicates that the goroutine has stopped executing on a proc -- specifically,
   249  // it blocked for some reason.
   250  func (gs *gState[R]) block(ts tracev2.Time, stack tracev2.Stack, reason string, ctx *traceContext) {
   251  	gs.startBlockReason = reason
   252  	gs.stop(ts, stack, ctx)
   253  }
   254  
   255  // stop indicates that the goroutine has stopped executing on a proc.
   256  func (gs *gState[R]) stop(ts tracev2.Time, stack tracev2.Stack, ctx *traceContext) {
   257  	// Emit the execution time slice.
   258  	var stk int
   259  	if gs.lastStopStack != tracev2.NoStack {
   260  		stk = ctx.Stack(viewerFrames(gs.lastStopStack))
   261  	}
   262  	// Check invariants.
   263  	if gs.startRunningTime == 0 {
   264  		panic("silently broken trace or generator invariant (startRunningTime != 0) not held")
   265  	}
   266  	if gs.executing == R(noResource) {
   267  		panic("non-executing goroutine stopped")
   268  	}
   269  	ctx.Slice(traceviewer.SliceEvent{
   270  		Name:     gs.name(),
   271  		Ts:       ctx.elapsed(gs.startRunningTime),
   272  		Dur:      ts.Sub(gs.startRunningTime),
   273  		Resource: uint64(gs.executing),
   274  		Stack:    stk,
   275  	})
   276  
   277  	// Flush completed ranges.
   278  	for _, cr := range gs.completedRanges {
   279  		ctx.Slice(traceviewer.SliceEvent{
   280  			Name:     cr.name,
   281  			Ts:       ctx.elapsed(cr.startTime),
   282  			Dur:      cr.endTime.Sub(cr.startTime),
   283  			Resource: uint64(gs.executing),
   284  			Stack:    ctx.Stack(viewerFrames(cr.startStack)),
   285  			EndStack: ctx.Stack(viewerFrames(cr.endStack)),
   286  			Arg:      cr.arg,
   287  		})
   288  	}
   289  	gs.completedRanges = gs.completedRanges[:0]
   290  
   291  	// Continue in-progress ranges.
   292  	for name, r := range gs.activeRanges {
   293  		// Check invariant.
   294  		if r.time == 0 {
   295  			panic("silently broken trace or generator invariant (activeRanges time != 0) not held")
   296  		}
   297  		ctx.Slice(traceviewer.SliceEvent{
   298  			Name:     name,
   299  			Ts:       ctx.elapsed(r.time),
   300  			Dur:      ts.Sub(r.time),
   301  			Resource: uint64(gs.executing),
   302  			Stack:    ctx.Stack(viewerFrames(r.stack)),
   303  		})
   304  	}
   305  
   306  	// Clear the range info.
   307  	for name := range gs.activeRanges {
   308  		gs.activeRanges[name] = activeRange{0, tracev2.NoStack}
   309  	}
   310  
   311  	gs.startRunningTime = 0
   312  	gs.lastStopStack = stack
   313  	gs.executing = R(noResource)
   314  }
   315  
   316  // finalize writes out any in-progress slices as if the goroutine stopped.
   317  // This must only be used once the trace has been fully processed and no
   318  // further events will be processed. This method may leave the gState in
   319  // an inconsistent state.
   320  func (gs *gState[R]) finish(ctx *traceContext) {
   321  	if gs.executing != R(noResource) {
   322  		gs.syscallEnd(ctx.endTime, false, ctx)
   323  		gs.stop(ctx.endTime, tracev2.NoStack, ctx)
   324  	}
   325  }
   326  
   327  // rangeBegin indicates the start of a special range of time.
   328  func (gs *gState[R]) rangeBegin(ts tracev2.Time, name string, stack tracev2.Stack) {
   329  	if gs.executing != R(noResource) {
   330  		// If we're executing, start the slice from here.
   331  		gs.activeRanges[name] = activeRange{ts, stack}
   332  	} else {
   333  		// If the goroutine isn't executing, there's no place for
   334  		// us to create a slice from. Wait until it starts executing.
   335  		gs.activeRanges[name] = activeRange{0, stack}
   336  	}
   337  }
   338  
   339  // rangeActive indicates that a special range of time has been in progress.
   340  func (gs *gState[R]) rangeActive(name string) {
   341  	if gs.executing != R(noResource) {
   342  		// If we're executing, and the range is active, then start
   343  		// from wherever the goroutine started running from.
   344  		gs.activeRanges[name] = activeRange{gs.startRunningTime, tracev2.NoStack}
   345  	} else {
   346  		// If the goroutine isn't executing, there's no place for
   347  		// us to create a slice from. Wait until it starts executing.
   348  		gs.activeRanges[name] = activeRange{0, tracev2.NoStack}
   349  	}
   350  }
   351  
   352  // rangeEnd indicates the end of a special range of time.
   353  func (gs *gState[R]) rangeEnd(ts tracev2.Time, name string, stack tracev2.Stack, ctx *traceContext) {
   354  	if gs.executing != R(noResource) {
   355  		r := gs.activeRanges[name]
   356  		gs.completedRanges = append(gs.completedRanges, completedRange{
   357  			name:       name,
   358  			startTime:  r.time,
   359  			endTime:    ts,
   360  			startStack: r.stack,
   361  			endStack:   stack,
   362  		})
   363  	}
   364  	delete(gs.activeRanges, name)
   365  }
   366  
   367  func lastFunc(s tracev2.Stack) string {
   368  	var last tracev2.StackFrame
   369  	s.Frames(func(f tracev2.StackFrame) bool {
   370  		last = f
   371  		return true
   372  	})
   373  	return last.Func
   374  }