gen.go

Documentation: cmd/trace/v2

     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  	"internal/trace"
    10  	"internal/trace/traceviewer"
    11  	tracev2 "internal/trace/v2"
    12  	"strings"
    13  )
    14  
    15  // generator is an interface for generating a JSON trace for the trace viewer
    16  // from a trace. Each method in this interface is a handler for a kind of event
    17  // that is interesting to render in the UI via the JSON trace.
    18  type generator interface {
    19  	// Global parts.
    20  	Sync() // Notifies the generator of an EventSync event.
    21  	StackSample(ctx *traceContext, ev *tracev2.Event)
    22  	GlobalRange(ctx *traceContext, ev *tracev2.Event)
    23  	GlobalMetric(ctx *traceContext, ev *tracev2.Event)
    24  
    25  	// Goroutine parts.
    26  	GoroutineLabel(ctx *traceContext, ev *tracev2.Event)
    27  	GoroutineRange(ctx *traceContext, ev *tracev2.Event)
    28  	GoroutineTransition(ctx *traceContext, ev *tracev2.Event)
    29  
    30  	// Proc parts.
    31  	ProcRange(ctx *traceContext, ev *tracev2.Event)
    32  	ProcTransition(ctx *traceContext, ev *tracev2.Event)
    33  
    34  	// User annotations.
    35  	Log(ctx *traceContext, ev *tracev2.Event)
    36  
    37  	// Finish indicates the end of the trace and finalizes generation.
    38  	Finish(ctx *traceContext)
    39  }
    40  
    41  // runGenerator produces a trace into ctx by running the generator over the parsed trace.
    42  func runGenerator(ctx *traceContext, g generator, parsed *parsedTrace, opts *genOpts) {
    43  	for i := range parsed.events {
    44  		ev := &parsed.events[i]
    45  
    46  		switch ev.Kind() {
    47  		case tracev2.EventSync:
    48  			g.Sync()
    49  		case tracev2.EventStackSample:
    50  			g.StackSample(ctx, ev)
    51  		case tracev2.EventRangeBegin, tracev2.EventRangeActive, tracev2.EventRangeEnd:
    52  			r := ev.Range()
    53  			switch r.Scope.Kind {
    54  			case tracev2.ResourceGoroutine:
    55  				g.GoroutineRange(ctx, ev)
    56  			case tracev2.ResourceProc:
    57  				g.ProcRange(ctx, ev)
    58  			case tracev2.ResourceNone:
    59  				g.GlobalRange(ctx, ev)
    60  			}
    61  		case tracev2.EventMetric:
    62  			g.GlobalMetric(ctx, ev)
    63  		case tracev2.EventLabel:
    64  			l := ev.Label()
    65  			if l.Resource.Kind == tracev2.ResourceGoroutine {
    66  				g.GoroutineLabel(ctx, ev)
    67  			}
    68  		case tracev2.EventStateTransition:
    69  			switch ev.StateTransition().Resource.Kind {
    70  			case tracev2.ResourceProc:
    71  				g.ProcTransition(ctx, ev)
    72  			case tracev2.ResourceGoroutine:
    73  				g.GoroutineTransition(ctx, ev)
    74  			}
    75  		case tracev2.EventLog:
    76  			g.Log(ctx, ev)
    77  		}
    78  	}
    79  	for i, task := range opts.tasks {
    80  		emitTask(ctx, task, i)
    81  		if opts.mode&traceviewer.ModeGoroutineOriented != 0 {
    82  			for _, region := range task.Regions {
    83  				emitRegion(ctx, region)
    84  			}
    85  		}
    86  	}
    87  	g.Finish(ctx)
    88  }
    89  
    90  // emitTask emits information about a task into the trace viewer's event stream.
    91  //
    92  // sortIndex sets the order in which this task will appear related to other tasks,
    93  // lowest first.
    94  func emitTask(ctx *traceContext, task *trace.UserTaskSummary, sortIndex int) {
    95  	// Collect information about the task.
    96  	var startStack, endStack tracev2.Stack
    97  	var startG, endG tracev2.GoID
    98  	startTime, endTime := ctx.startTime, ctx.endTime
    99  	if task.Start != nil {
   100  		startStack = task.Start.Stack()
   101  		startG = task.Start.Goroutine()
   102  		startTime = task.Start.Time()
   103  	}
   104  	if task.End != nil {
   105  		endStack = task.End.Stack()
   106  		endG = task.End.Goroutine()
   107  		endTime = task.End.Time()
   108  	}
   109  	arg := struct {
   110  		ID     uint64 `json:"id"`
   111  		StartG uint64 `json:"start_g,omitempty"`
   112  		EndG   uint64 `json:"end_g,omitempty"`
   113  	}{
   114  		ID:     uint64(task.ID),
   115  		StartG: uint64(startG),
   116  		EndG:   uint64(endG),
   117  	}
   118  
   119  	// Emit the task slice and notify the emitter of the task.
   120  	ctx.Task(uint64(task.ID), fmt.Sprintf("T%d %s", task.ID, task.Name), sortIndex)
   121  	ctx.TaskSlice(traceviewer.SliceEvent{
   122  		Name:     task.Name,
   123  		Ts:       ctx.elapsed(startTime),
   124  		Dur:      endTime.Sub(startTime),
   125  		Resource: uint64(task.ID),
   126  		Stack:    ctx.Stack(viewerFrames(startStack)),
   127  		EndStack: ctx.Stack(viewerFrames(endStack)),
   128  		Arg:      arg,
   129  	})
   130  	// Emit an arrow from the parent to the child.
   131  	if task.Parent != nil && task.Start != nil && task.Start.Kind() == tracev2.EventTaskBegin {
   132  		ctx.TaskArrow(traceviewer.ArrowEvent{
   133  			Name:         "newTask",
   134  			Start:        ctx.elapsed(task.Start.Time()),
   135  			End:          ctx.elapsed(task.Start.Time()),
   136  			FromResource: uint64(task.Parent.ID),
   137  			ToResource:   uint64(task.ID),
   138  			FromStack:    ctx.Stack(viewerFrames(task.Start.Stack())),
   139  		})
   140  	}
   141  }
   142  
   143  // emitRegion emits goroutine-based slice events to the UI. The caller
   144  // must be emitting for a goroutine-oriented trace.
   145  //
   146  // TODO(mknyszek): Make regions part of the regular generator loop and
   147  // treat them like ranges so that we can emit regions in traces oriented
   148  // by proc or thread.
   149  func emitRegion(ctx *traceContext, region *trace.UserRegionSummary) {
   150  	if region.Name == "" {
   151  		return
   152  	}
   153  	// Collect information about the region.
   154  	var startStack, endStack tracev2.Stack
   155  	goroutine := tracev2.NoGoroutine
   156  	startTime, endTime := ctx.startTime, ctx.endTime
   157  	if region.Start != nil {
   158  		startStack = region.Start.Stack()
   159  		startTime = region.Start.Time()
   160  		goroutine = region.Start.Goroutine()
   161  	}
   162  	if region.End != nil {
   163  		endStack = region.End.Stack()
   164  		endTime = region.End.Time()
   165  		goroutine = region.End.Goroutine()
   166  	}
   167  	if goroutine == tracev2.NoGoroutine {
   168  		return
   169  	}
   170  	arg := struct {
   171  		TaskID uint64 `json:"taskid"`
   172  	}{
   173  		TaskID: uint64(region.TaskID),
   174  	}
   175  	ctx.AsyncSlice(traceviewer.AsyncSliceEvent{
   176  		SliceEvent: traceviewer.SliceEvent{
   177  			Name:     region.Name,
   178  			Ts:       ctx.elapsed(startTime),
   179  			Dur:      endTime.Sub(startTime),
   180  			Resource: uint64(goroutine),
   181  			Stack:    ctx.Stack(viewerFrames(startStack)),
   182  			EndStack: ctx.Stack(viewerFrames(endStack)),
   183  			Arg:      arg,
   184  		},
   185  		Category:       "Region",
   186  		Scope:          fmt.Sprintf("%x", region.TaskID),
   187  		TaskColorIndex: uint64(region.TaskID),
   188  	})
   189  }
   190  
   191  // Building blocks for generators.
   192  
   193  // stackSampleGenerator implements a generic handler for stack sample events.
   194  // The provided resource is the resource the stack sample should count against.
   195  type stackSampleGenerator[R resource] struct {
   196  	// getResource is a function to extract a resource ID from a stack sample event.
   197  	getResource func(*tracev2.Event) R
   198  }
   199  
   200  // StackSample implements a stack sample event handler. It expects ev to be one such event.
   201  func (g *stackSampleGenerator[R]) StackSample(ctx *traceContext, ev *tracev2.Event) {
   202  	id := g.getResource(ev)
   203  	if id == R(noResource) {
   204  		// We have nowhere to put this in the UI.
   205  		return
   206  	}
   207  	ctx.Instant(traceviewer.InstantEvent{
   208  		Name:     "CPU profile sample",
   209  		Ts:       ctx.elapsed(ev.Time()),
   210  		Resource: uint64(id),
   211  		Stack:    ctx.Stack(viewerFrames(ev.Stack())),
   212  	})
   213  }
   214  
   215  // globalRangeGenerator implements a generic handler for EventRange* events that pertain
   216  // to tracev2.ResourceNone (the global scope).
   217  type globalRangeGenerator struct {
   218  	ranges   map[string]activeRange
   219  	seenSync bool
   220  }
   221  
   222  // Sync notifies the generator of an EventSync event.
   223  func (g *globalRangeGenerator) Sync() {
   224  	g.seenSync = true
   225  }
   226  
   227  // GlobalRange implements a handler for EventRange* events whose Scope.Kind is ResourceNone.
   228  // It expects ev to be one such event.
   229  func (g *globalRangeGenerator) GlobalRange(ctx *traceContext, ev *tracev2.Event) {
   230  	if g.ranges == nil {
   231  		g.ranges = make(map[string]activeRange)
   232  	}
   233  	r := ev.Range()
   234  	switch ev.Kind() {
   235  	case tracev2.EventRangeBegin:
   236  		g.ranges[r.Name] = activeRange{ev.Time(), ev.Stack()}
   237  	case tracev2.EventRangeActive:
   238  		// If we've seen a Sync event, then Active events are always redundant.
   239  		if !g.seenSync {
   240  			// Otherwise, they extend back to the start of the trace.
   241  			g.ranges[r.Name] = activeRange{ctx.startTime, ev.Stack()}
   242  		}
   243  	case tracev2.EventRangeEnd:
   244  		// Only emit GC events, because we have nowhere to
   245  		// put other events.
   246  		ar := g.ranges[r.Name]
   247  		if strings.Contains(r.Name, "GC") {
   248  			ctx.Slice(traceviewer.SliceEvent{
   249  				Name:     r.Name,
   250  				Ts:       ctx.elapsed(ar.time),
   251  				Dur:      ev.Time().Sub(ar.time),
   252  				Resource: trace.GCP,
   253  				Stack:    ctx.Stack(viewerFrames(ar.stack)),
   254  				EndStack: ctx.Stack(viewerFrames(ev.Stack())),
   255  			})
   256  		}
   257  		delete(g.ranges, r.Name)
   258  	}
   259  }
   260  
   261  // Finish flushes any outstanding ranges at the end of the trace.
   262  func (g *globalRangeGenerator) Finish(ctx *traceContext) {
   263  	for name, ar := range g.ranges {
   264  		if !strings.Contains(name, "GC") {
   265  			continue
   266  		}
   267  		ctx.Slice(traceviewer.SliceEvent{
   268  			Name:     name,
   269  			Ts:       ctx.elapsed(ar.time),
   270  			Dur:      ctx.endTime.Sub(ar.time),
   271  			Resource: trace.GCP,
   272  			Stack:    ctx.Stack(viewerFrames(ar.stack)),
   273  		})
   274  	}
   275  }
   276  
   277  // globalMetricGenerator implements a generic handler for Metric events.
   278  type globalMetricGenerator struct {
   279  }
   280  
   281  // GlobalMetric implements an event handler for EventMetric events. ev must be one such event.
   282  func (g *globalMetricGenerator) GlobalMetric(ctx *traceContext, ev *tracev2.Event) {
   283  	m := ev.Metric()
   284  	switch m.Name {
   285  	case "/memory/classes/heap/objects:bytes":
   286  		ctx.HeapAlloc(ctx.elapsed(ev.Time()), m.Value.Uint64())
   287  	case "/gc/heap/goal:bytes":
   288  		ctx.HeapGoal(ctx.elapsed(ev.Time()), m.Value.Uint64())
   289  	case "/sched/gomaxprocs:threads":
   290  		ctx.Gomaxprocs(m.Value.Uint64())
   291  	}
   292  }
   293  
   294  // procRangeGenerator implements a generic handler for EventRange* events whose Scope.Kind is
   295  // ResourceProc.
   296  type procRangeGenerator struct {
   297  	ranges   map[tracev2.Range]activeRange
   298  	seenSync bool
   299  }
   300  
   301  // Sync notifies the generator of an EventSync event.
   302  func (g *procRangeGenerator) Sync() {
   303  	g.seenSync = true
   304  }
   305  
   306  // ProcRange implements a handler for EventRange* events whose Scope.Kind is ResourceProc.
   307  // It expects ev to be one such event.
   308  func (g *procRangeGenerator) ProcRange(ctx *traceContext, ev *tracev2.Event) {
   309  	if g.ranges == nil {
   310  		g.ranges = make(map[tracev2.Range]activeRange)
   311  	}
   312  	r := ev.Range()
   313  	switch ev.Kind() {
   314  	case tracev2.EventRangeBegin:
   315  		g.ranges[r] = activeRange{ev.Time(), ev.Stack()}
   316  	case tracev2.EventRangeActive:
   317  		// If we've seen a Sync event, then Active events are always redundant.
   318  		if !g.seenSync {
   319  			// Otherwise, they extend back to the start of the trace.
   320  			g.ranges[r] = activeRange{ctx.startTime, ev.Stack()}
   321  		}
   322  	case tracev2.EventRangeEnd:
   323  		// Emit proc-based ranges.
   324  		ar := g.ranges[r]
   325  		ctx.Slice(traceviewer.SliceEvent{
   326  			Name:     r.Name,
   327  			Ts:       ctx.elapsed(ar.time),
   328  			Dur:      ev.Time().Sub(ar.time),
   329  			Resource: uint64(r.Scope.Proc()),
   330  			Stack:    ctx.Stack(viewerFrames(ar.stack)),
   331  			EndStack: ctx.Stack(viewerFrames(ev.Stack())),
   332  		})
   333  		delete(g.ranges, r)
   334  	}
   335  }
   336  
   337  // Finish flushes any outstanding ranges at the end of the trace.
   338  func (g *procRangeGenerator) Finish(ctx *traceContext) {
   339  	for r, ar := range g.ranges {
   340  		ctx.Slice(traceviewer.SliceEvent{
   341  			Name:     r.Name,
   342  			Ts:       ctx.elapsed(ar.time),
   343  			Dur:      ctx.endTime.Sub(ar.time),
   344  			Resource: uint64(r.Scope.Proc()),
   345  			Stack:    ctx.Stack(viewerFrames(ar.stack)),
   346  		})
   347  	}
   348  }
   349  
   350  // activeRange represents an active EventRange* range.
   351  type activeRange struct {
   352  	time  tracev2.Time
   353  	stack tracev2.Stack
   354  }
   355  
   356  // completedRange represents a completed EventRange* range.
   357  type completedRange struct {
   358  	name       string
   359  	startTime  tracev2.Time
   360  	endTime    tracev2.Time
   361  	startStack tracev2.Stack
   362  	endStack   tracev2.Stack
   363  	arg        any
   364  }
   365  
   366  type logEventGenerator[R resource] struct {
   367  	// getResource is a function to extract a resource ID from a Log event.
   368  	getResource func(*tracev2.Event) R
   369  }
   370  
   371  // Log implements a log event handler. It expects ev to be one such event.
   372  func (g *logEventGenerator[R]) Log(ctx *traceContext, ev *tracev2.Event) {
   373  	id := g.getResource(ev)
   374  	if id == R(noResource) {
   375  		// We have nowhere to put this in the UI.
   376  		return
   377  	}
   378  
   379  	// Construct the name to present.
   380  	log := ev.Log()
   381  	name := log.Message
   382  	if log.Category != "" {
   383  		name = "[" + log.Category + "] " + name
   384  	}
   385  
   386  	// Emit an instant event.
   387  	ctx.Instant(traceviewer.InstantEvent{
   388  		Name:     name,
   389  		Ts:       ctx.elapsed(ev.Time()),
   390  		Category: "user event",
   391  		Resource: uint64(id),
   392  		Stack:    ctx.Stack(viewerFrames(ev.Stack())),
   393  	})
   394  }
   395
View as plain text