gen.go

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