Source file src/internal/trace/event.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 trace
     6  
     7  import (
     8  	"fmt"
     9  	"iter"
    10  	"math"
    11  	"strconv"
    12  	"strings"
    13  	"time"
    14  
    15  	"internal/trace/tracev2"
    16  	"internal/trace/version"
    17  )
    18  
    19  // EventKind indicates the kind of event this is.
    20  //
    21  // Use this information to obtain a more specific event that
    22  // allows access to more detailed information.
    23  type EventKind uint16
    24  
    25  const (
    26  	EventBad EventKind = iota
    27  
    28  	// EventKindSync is an event that indicates a global synchronization
    29  	// point in the trace. At the point of a sync event, the
    30  	// trace reader can be certain that all resources (e.g. threads,
    31  	// goroutines) that have existed until that point have been enumerated.
    32  	EventSync
    33  
    34  	// EventMetric is an event that represents the value of a metric at
    35  	// a particular point in time.
    36  	EventMetric
    37  
    38  	// EventLabel attaches a label to a resource.
    39  	EventLabel
    40  
    41  	// EventStackSample represents an execution sample, indicating what a
    42  	// thread/proc/goroutine was doing at a particular point in time via
    43  	// its backtrace.
    44  	//
    45  	// Note: Samples should be considered a close approximation of
    46  	// what a thread/proc/goroutine was executing at a given point in time.
    47  	// These events may slightly contradict the situation StateTransitions
    48  	// describe, so they should only be treated as a best-effort annotation.
    49  	EventStackSample
    50  
    51  	// EventRangeBegin and EventRangeEnd are a pair of generic events representing
    52  	// a special range of time. Ranges are named and scoped to some resource
    53  	// (identified via ResourceKind). A range that has begun but has not ended
    54  	// is considered active.
    55  	//
    56  	// EvRangeBegin and EvRangeEnd will share the same name, and an End will always
    57  	// follow a Begin on the same instance of the resource. The associated
    58  	// resource ID can be obtained from the Event. ResourceNone indicates the
    59  	// range is globally scoped. That is, any goroutine/proc/thread can start or
    60  	// stop, but only one such range may be active at any given time.
    61  	//
    62  	// EventRangeActive is like EventRangeBegin, but indicates that the range was
    63  	// already active. In this case, the resource referenced may not be in the current
    64  	// context.
    65  	EventRangeBegin
    66  	EventRangeActive
    67  	EventRangeEnd
    68  
    69  	// EvTaskBegin and EvTaskEnd are a pair of events representing a runtime/trace.Task.
    70  	EventTaskBegin
    71  	EventTaskEnd
    72  
    73  	// EventRegionBegin and EventRegionEnd are a pair of events represent a runtime/trace.Region.
    74  	EventRegionBegin
    75  	EventRegionEnd
    76  
    77  	// EventLog represents a runtime/trace.Log call.
    78  	EventLog
    79  
    80  	// EventStateTransition represents a state change for some resource.
    81  	EventStateTransition
    82  
    83  	// EventExperimental is an experimental event that is unvalidated and exposed in a raw form.
    84  	// Users are expected to understand the format and perform their own validation. These events
    85  	// may always be safely ignored.
    86  	EventExperimental
    87  )
    88  
    89  // String returns a string form of the EventKind.
    90  func (e EventKind) String() string {
    91  	if int(e) >= len(eventKindStrings) {
    92  		return eventKindStrings[0]
    93  	}
    94  	return eventKindStrings[e]
    95  }
    96  
    97  var eventKindStrings = [...]string{
    98  	EventBad:             "Bad",
    99  	EventSync:            "Sync",
   100  	EventMetric:          "Metric",
   101  	EventLabel:           "Label",
   102  	EventStackSample:     "StackSample",
   103  	EventRangeBegin:      "RangeBegin",
   104  	EventRangeActive:     "RangeActive",
   105  	EventRangeEnd:        "RangeEnd",
   106  	EventTaskBegin:       "TaskBegin",
   107  	EventTaskEnd:         "TaskEnd",
   108  	EventRegionBegin:     "RegionBegin",
   109  	EventRegionEnd:       "RegionEnd",
   110  	EventLog:             "Log",
   111  	EventStateTransition: "StateTransition",
   112  	EventExperimental:    "Experimental",
   113  }
   114  
   115  const maxTime = Time(math.MaxInt64)
   116  
   117  // Time is a timestamp in nanoseconds.
   118  //
   119  // It corresponds to the monotonic clock on the platform that the
   120  // trace was taken, and so is possible to correlate with timestamps
   121  // for other traces taken on the same machine using the same clock
   122  // (i.e. no reboots in between).
   123  //
   124  // The actual absolute value of the timestamp is only meaningful in
   125  // relation to other timestamps from the same clock.
   126  //
   127  // BUG: Timestamps coming from traces on Windows platforms are
   128  // only comparable with timestamps from the same trace. Timestamps
   129  // across traces cannot be compared, because the system clock is
   130  // not used as of Go 1.22.
   131  //
   132  // BUG: Traces produced by Go versions 1.21 and earlier cannot be
   133  // compared with timestamps from other traces taken on the same
   134  // machine. This is because the system clock was not used at all
   135  // to collect those timestamps.
   136  type Time int64
   137  
   138  // Sub subtracts t0 from t, returning the duration in nanoseconds.
   139  func (t Time) Sub(t0 Time) time.Duration {
   140  	return time.Duration(int64(t) - int64(t0))
   141  }
   142  
   143  // Metric provides details about a Metric event.
   144  type Metric struct {
   145  	// Name is the name of the sampled metric.
   146  	//
   147  	// Names follow the same convention as metric names in the
   148  	// runtime/metrics package, meaning they include the unit.
   149  	// Names that match with the runtime/metrics package represent
   150  	// the same quantity. Note that this corresponds to the
   151  	// runtime/metrics package for the Go version this trace was
   152  	// collected for.
   153  	Name string
   154  
   155  	// Value is the sampled value of the metric.
   156  	//
   157  	// The Value's Kind is tied to the name of the metric, and so is
   158  	// guaranteed to be the same for metric samples for the same metric.
   159  	Value Value
   160  }
   161  
   162  // Label provides details about a Label event.
   163  type Label struct {
   164  	// Label is the label applied to some resource.
   165  	Label string
   166  
   167  	// Resource is the resource to which this label should be applied.
   168  	Resource ResourceID
   169  }
   170  
   171  // Range provides details about a Range event.
   172  type Range struct {
   173  	// Name is a human-readable name for the range.
   174  	//
   175  	// This name can be used to identify the end of the range for the resource
   176  	// its scoped to, because only one of each type of range may be active on
   177  	// a particular resource. The relevant resource should be obtained from the
   178  	// Event that produced these details. The corresponding RangeEnd will have
   179  	// an identical name.
   180  	Name string
   181  
   182  	// Scope is the resource that the range is scoped to.
   183  	//
   184  	// For example, a ResourceGoroutine scope means that the same goroutine
   185  	// must have a start and end for the range, and that goroutine can only
   186  	// have one range of a particular name active at any given time. The
   187  	// ID that this range is scoped to may be obtained via Event.Goroutine.
   188  	//
   189  	// The ResourceNone scope means that the range is globally scoped. As a
   190  	// result, any goroutine/proc/thread may start or end the range, and only
   191  	// one such named range may be active globally at any given time.
   192  	//
   193  	// For RangeBegin and RangeEnd events, this will always reference some
   194  	// resource ID in the current execution context. For RangeActive events,
   195  	// this may reference a resource not in the current context. Prefer Scope
   196  	// over the current execution context.
   197  	Scope ResourceID
   198  }
   199  
   200  // RangeAttributes provides attributes about a completed Range.
   201  type RangeAttribute struct {
   202  	// Name is the human-readable name for the range.
   203  	Name string
   204  
   205  	// Value is the value of the attribute.
   206  	Value Value
   207  }
   208  
   209  // TaskID is the internal ID of a task used to disambiguate tasks (even if they
   210  // are of the same type).
   211  type TaskID uint64
   212  
   213  const (
   214  	// NoTask indicates the lack of a task.
   215  	NoTask = TaskID(^uint64(0))
   216  
   217  	// BackgroundTask is the global task that events are attached to if there was
   218  	// no other task in the context at the point the event was emitted.
   219  	BackgroundTask = TaskID(0)
   220  )
   221  
   222  // Task provides details about a Task event.
   223  type Task struct {
   224  	// ID is a unique identifier for the task.
   225  	//
   226  	// This can be used to associate the beginning of a task with its end.
   227  	ID TaskID
   228  
   229  	// ParentID is the ID of the parent task.
   230  	Parent TaskID
   231  
   232  	// Type is the taskType that was passed to runtime/trace.NewTask.
   233  	//
   234  	// May be "" if a task's TaskBegin event isn't present in the trace.
   235  	Type string
   236  }
   237  
   238  // Region provides details about a Region event.
   239  type Region struct {
   240  	// Task is the ID of the task this region is associated with.
   241  	Task TaskID
   242  
   243  	// Type is the regionType that was passed to runtime/trace.StartRegion or runtime/trace.WithRegion.
   244  	Type string
   245  }
   246  
   247  // Log provides details about a Log event.
   248  type Log struct {
   249  	// Task is the ID of the task this region is associated with.
   250  	Task TaskID
   251  
   252  	// Category is the category that was passed to runtime/trace.Log or runtime/trace.Logf.
   253  	Category string
   254  
   255  	// Message is the message that was passed to runtime/trace.Log or runtime/trace.Logf.
   256  	Message string
   257  }
   258  
   259  // Stack represents a stack. It's really a handle to a stack and it's trivially comparable.
   260  //
   261  // If two Stacks are equal then their Frames are guaranteed to be identical. If they are not
   262  // equal, however, their Frames may still be equal.
   263  type Stack struct {
   264  	table *evTable
   265  	id    stackID
   266  }
   267  
   268  // Frames is an iterator over the frames in a Stack.
   269  func (s Stack) Frames() iter.Seq[StackFrame] {
   270  	return func(yield func(StackFrame) bool) {
   271  		if s.id == 0 {
   272  			return
   273  		}
   274  		stk := s.table.stacks.mustGet(s.id)
   275  		for _, pc := range stk.pcs {
   276  			f := s.table.pcs[pc]
   277  			sf := StackFrame{
   278  				PC:   f.pc,
   279  				Func: s.table.strings.mustGet(f.funcID),
   280  				File: s.table.strings.mustGet(f.fileID),
   281  				Line: f.line,
   282  			}
   283  			if !yield(sf) {
   284  				return
   285  			}
   286  		}
   287  	}
   288  }
   289  
   290  // NoStack is a sentinel value that can be compared against any Stack value, indicating
   291  // a lack of a stack trace.
   292  var NoStack = Stack{}
   293  
   294  // StackFrame represents a single frame of a stack.
   295  type StackFrame struct {
   296  	// PC is the program counter of the function call if this
   297  	// is not a leaf frame. If it's a leaf frame, it's the point
   298  	// at which the stack trace was taken.
   299  	PC uint64
   300  
   301  	// Func is the name of the function this frame maps to.
   302  	Func string
   303  
   304  	// File is the file which contains the source code of Func.
   305  	File string
   306  
   307  	// Line is the line number within File which maps to PC.
   308  	Line uint64
   309  }
   310  
   311  // ExperimentalEvent presents a raw view of an experimental event's arguments and their names.
   312  type ExperimentalEvent struct {
   313  	// Name is the name of the event.
   314  	Name string
   315  
   316  	// Experiment is the name of the experiment this event is a part of.
   317  	Experiment string
   318  
   319  	// Args lists the names of the event's arguments in order.
   320  	Args []string
   321  
   322  	// argValues contains the raw integer arguments which are interpreted
   323  	// by ArgValue using table.
   324  	table     *evTable
   325  	argValues []uint64
   326  }
   327  
   328  // ArgValue returns a typed Value for the i'th argument in the experimental event.
   329  func (e ExperimentalEvent) ArgValue(i int) Value {
   330  	if i < 0 || i >= len(e.Args) {
   331  		panic(fmt.Sprintf("experimental event argument index %d out of bounds [0, %d)", i, len(e.Args)))
   332  	}
   333  	if strings.HasSuffix(e.Args[i], "string") {
   334  		s := e.table.strings.mustGet(stringID(e.argValues[i]))
   335  		return stringValue(s)
   336  	}
   337  	return uint64Value(e.argValues[i])
   338  }
   339  
   340  // ExperimentalBatch represents a packet of unparsed data along with metadata about that packet.
   341  type ExperimentalBatch struct {
   342  	// Thread is the ID of the thread that produced a packet of data.
   343  	Thread ThreadID
   344  
   345  	// Data is a packet of unparsed data all produced by one thread.
   346  	Data []byte
   347  }
   348  
   349  // Event represents a single event in the trace.
   350  type Event struct {
   351  	table *evTable
   352  	ctx   schedCtx
   353  	base  baseEvent
   354  }
   355  
   356  // Kind returns the kind of event that this is.
   357  func (e Event) Kind() EventKind {
   358  	return tracev2Type2Kind[e.base.typ]
   359  }
   360  
   361  // Time returns the timestamp of the event.
   362  func (e Event) Time() Time {
   363  	return e.base.time
   364  }
   365  
   366  // Goroutine returns the ID of the goroutine that was executing when
   367  // this event happened. It describes part of the execution context
   368  // for this event.
   369  //
   370  // Note that for goroutine state transitions this always refers to the
   371  // state before the transition. For example, if a goroutine is just
   372  // starting to run on this thread and/or proc, then this will return
   373  // NoGoroutine. In this case, the goroutine starting to run will be
   374  // can be found at Event.StateTransition().Resource.
   375  func (e Event) Goroutine() GoID {
   376  	return e.ctx.G
   377  }
   378  
   379  // Proc returns the ID of the proc this event event pertains to.
   380  //
   381  // Note that for proc state transitions this always refers to the
   382  // state before the transition. For example, if a proc is just
   383  // starting to run on this thread, then this will return NoProc.
   384  func (e Event) Proc() ProcID {
   385  	return e.ctx.P
   386  }
   387  
   388  // Thread returns the ID of the thread this event pertains to.
   389  //
   390  // Note that for thread state transitions this always refers to the
   391  // state before the transition. For example, if a thread is just
   392  // starting to run, then this will return NoThread.
   393  //
   394  // Note: tracking thread state is not currently supported, so this
   395  // will always return a valid thread ID. However thread state transitions
   396  // may be tracked in the future, and callers must be robust to this
   397  // possibility.
   398  func (e Event) Thread() ThreadID {
   399  	return e.ctx.M
   400  }
   401  
   402  // Stack returns a handle to a stack associated with the event.
   403  //
   404  // This represents a stack trace at the current moment in time for
   405  // the current execution context.
   406  func (e Event) Stack() Stack {
   407  	if e.base.typ == evSync {
   408  		return NoStack
   409  	}
   410  	if e.base.typ == tracev2.EvCPUSample {
   411  		return Stack{table: e.table, id: stackID(e.base.args[0])}
   412  	}
   413  	spec := tracev2.Specs()[e.base.typ]
   414  	if len(spec.StackIDs) == 0 {
   415  		return NoStack
   416  	}
   417  	// The stack for the main execution context is always the
   418  	// first stack listed in StackIDs. Subtract one from this
   419  	// because we've peeled away the timestamp argument.
   420  	id := stackID(e.base.args[spec.StackIDs[0]-1])
   421  	if id == 0 {
   422  		return NoStack
   423  	}
   424  	return Stack{table: e.table, id: id}
   425  }
   426  
   427  // Metric returns details about a Metric event.
   428  //
   429  // Panics if Kind != EventMetric.
   430  func (e Event) Metric() Metric {
   431  	if e.Kind() != EventMetric {
   432  		panic("Metric called on non-Metric event")
   433  	}
   434  	var m Metric
   435  	switch e.base.typ {
   436  	case tracev2.EvProcsChange:
   437  		m.Name = "/sched/gomaxprocs:threads"
   438  		m.Value = uint64Value(e.base.args[0])
   439  	case tracev2.EvHeapAlloc:
   440  		m.Name = "/memory/classes/heap/objects:bytes"
   441  		m.Value = uint64Value(e.base.args[0])
   442  	case tracev2.EvHeapGoal:
   443  		m.Name = "/gc/heap/goal:bytes"
   444  		m.Value = uint64Value(e.base.args[0])
   445  	default:
   446  		panic(fmt.Sprintf("internal error: unexpected wire-format event type for Metric kind: %d", e.base.typ))
   447  	}
   448  	return m
   449  }
   450  
   451  // Label returns details about a Label event.
   452  //
   453  // Panics if Kind != EventLabel.
   454  func (e Event) Label() Label {
   455  	if e.Kind() != EventLabel {
   456  		panic("Label called on non-Label event")
   457  	}
   458  	if e.base.typ != tracev2.EvGoLabel {
   459  		panic(fmt.Sprintf("internal error: unexpected wire-format event type for Label kind: %d", e.base.typ))
   460  	}
   461  	return Label{
   462  		Label:    e.table.strings.mustGet(stringID(e.base.args[0])),
   463  		Resource: ResourceID{Kind: ResourceGoroutine, id: int64(e.ctx.G)},
   464  	}
   465  }
   466  
   467  // Range returns details about an EventRangeBegin, EventRangeActive, or EventRangeEnd event.
   468  //
   469  // Panics if Kind != EventRangeBegin, Kind != EventRangeActive, and Kind != EventRangeEnd.
   470  func (e Event) Range() Range {
   471  	if kind := e.Kind(); kind != EventRangeBegin && kind != EventRangeActive && kind != EventRangeEnd {
   472  		panic("Range called on non-Range event")
   473  	}
   474  	var r Range
   475  	switch e.base.typ {
   476  	case tracev2.EvSTWBegin, tracev2.EvSTWEnd:
   477  		// N.B. ordering.advance smuggles in the STW reason as e.base.args[0]
   478  		// for tracev2.EvSTWEnd (it's already there for Begin).
   479  		r.Name = "stop-the-world (" + e.table.strings.mustGet(stringID(e.base.args[0])) + ")"
   480  		r.Scope = ResourceID{Kind: ResourceGoroutine, id: int64(e.Goroutine())}
   481  	case tracev2.EvGCBegin, tracev2.EvGCActive, tracev2.EvGCEnd:
   482  		r.Name = "GC concurrent mark phase"
   483  		r.Scope = ResourceID{Kind: ResourceNone}
   484  	case tracev2.EvGCSweepBegin, tracev2.EvGCSweepActive, tracev2.EvGCSweepEnd:
   485  		r.Name = "GC incremental sweep"
   486  		r.Scope = ResourceID{Kind: ResourceProc}
   487  		if e.base.typ == tracev2.EvGCSweepActive {
   488  			r.Scope.id = int64(e.base.args[0])
   489  		} else {
   490  			r.Scope.id = int64(e.Proc())
   491  		}
   492  	case tracev2.EvGCMarkAssistBegin, tracev2.EvGCMarkAssistActive, tracev2.EvGCMarkAssistEnd:
   493  		r.Name = "GC mark assist"
   494  		r.Scope = ResourceID{Kind: ResourceGoroutine}
   495  		if e.base.typ == tracev2.EvGCMarkAssistActive {
   496  			r.Scope.id = int64(e.base.args[0])
   497  		} else {
   498  			r.Scope.id = int64(e.Goroutine())
   499  		}
   500  	default:
   501  		panic(fmt.Sprintf("internal error: unexpected wire-event type for Range kind: %d", e.base.typ))
   502  	}
   503  	return r
   504  }
   505  
   506  // RangeAttributes returns attributes for a completed range.
   507  //
   508  // Panics if Kind != EventRangeEnd.
   509  func (e Event) RangeAttributes() []RangeAttribute {
   510  	if e.Kind() != EventRangeEnd {
   511  		panic("Range called on non-Range event")
   512  	}
   513  	if e.base.typ != tracev2.EvGCSweepEnd {
   514  		return nil
   515  	}
   516  	return []RangeAttribute{
   517  		{
   518  			Name:  "bytes swept",
   519  			Value: uint64Value(e.base.args[0]),
   520  		},
   521  		{
   522  			Name:  "bytes reclaimed",
   523  			Value: uint64Value(e.base.args[1]),
   524  		},
   525  	}
   526  }
   527  
   528  // Task returns details about a TaskBegin or TaskEnd event.
   529  //
   530  // Panics if Kind != EventTaskBegin and Kind != EventTaskEnd.
   531  func (e Event) Task() Task {
   532  	if kind := e.Kind(); kind != EventTaskBegin && kind != EventTaskEnd {
   533  		panic("Task called on non-Task event")
   534  	}
   535  	parentID := NoTask
   536  	var typ string
   537  	switch e.base.typ {
   538  	case tracev2.EvUserTaskBegin:
   539  		parentID = TaskID(e.base.args[1])
   540  		typ = e.table.strings.mustGet(stringID(e.base.args[2]))
   541  	case tracev2.EvUserTaskEnd:
   542  		parentID = TaskID(e.base.extra(version.Go122)[0])
   543  		typ = e.table.getExtraString(extraStringID(e.base.extra(version.Go122)[1]))
   544  	default:
   545  		panic(fmt.Sprintf("internal error: unexpected wire-format event type for Task kind: %d", e.base.typ))
   546  	}
   547  	return Task{
   548  		ID:     TaskID(e.base.args[0]),
   549  		Parent: parentID,
   550  		Type:   typ,
   551  	}
   552  }
   553  
   554  // Region returns details about a RegionBegin or RegionEnd event.
   555  //
   556  // Panics if Kind != EventRegionBegin and Kind != EventRegionEnd.
   557  func (e Event) Region() Region {
   558  	if kind := e.Kind(); kind != EventRegionBegin && kind != EventRegionEnd {
   559  		panic("Region called on non-Region event")
   560  	}
   561  	if e.base.typ != tracev2.EvUserRegionBegin && e.base.typ != tracev2.EvUserRegionEnd {
   562  		panic(fmt.Sprintf("internal error: unexpected wire-format event type for Region kind: %d", e.base.typ))
   563  	}
   564  	return Region{
   565  		Task: TaskID(e.base.args[0]),
   566  		Type: e.table.strings.mustGet(stringID(e.base.args[1])),
   567  	}
   568  }
   569  
   570  // Log returns details about a Log event.
   571  //
   572  // Panics if Kind != EventLog.
   573  func (e Event) Log() Log {
   574  	if e.Kind() != EventLog {
   575  		panic("Log called on non-Log event")
   576  	}
   577  	if e.base.typ != tracev2.EvUserLog {
   578  		panic(fmt.Sprintf("internal error: unexpected wire-format event type for Log kind: %d", e.base.typ))
   579  	}
   580  	return Log{
   581  		Task:     TaskID(e.base.args[0]),
   582  		Category: e.table.strings.mustGet(stringID(e.base.args[1])),
   583  		Message:  e.table.strings.mustGet(stringID(e.base.args[2])),
   584  	}
   585  }
   586  
   587  // StateTransition returns details about a StateTransition event.
   588  //
   589  // Panics if Kind != EventStateTransition.
   590  func (e Event) StateTransition() StateTransition {
   591  	if e.Kind() != EventStateTransition {
   592  		panic("StateTransition called on non-StateTransition event")
   593  	}
   594  	var s StateTransition
   595  	switch e.base.typ {
   596  	case tracev2.EvProcStart:
   597  		s = procStateTransition(ProcID(e.base.args[0]), ProcIdle, ProcRunning)
   598  	case tracev2.EvProcStop:
   599  		s = procStateTransition(e.ctx.P, ProcRunning, ProcIdle)
   600  	case tracev2.EvProcSteal:
   601  		// N.B. ordering.advance populates e.base.extra.
   602  		beforeState := ProcRunning
   603  		if tracev2.ProcStatus(e.base.extra(version.Go122)[0]) == tracev2.ProcSyscallAbandoned {
   604  			// We've lost information because this ProcSteal advanced on a
   605  			// SyscallAbandoned state. Treat the P as idle because ProcStatus
   606  			// treats SyscallAbandoned as Idle. Otherwise we'll have an invalid
   607  			// transition.
   608  			beforeState = ProcIdle
   609  		}
   610  		s = procStateTransition(ProcID(e.base.args[0]), beforeState, ProcIdle)
   611  	case tracev2.EvProcStatus:
   612  		// N.B. ordering.advance populates e.base.extra.
   613  		s = procStateTransition(ProcID(e.base.args[0]), ProcState(e.base.extra(version.Go122)[0]), tracev2ProcStatus2ProcState[e.base.args[1]])
   614  	case tracev2.EvGoCreate, tracev2.EvGoCreateBlocked:
   615  		status := GoRunnable
   616  		if e.base.typ == tracev2.EvGoCreateBlocked {
   617  			status = GoWaiting
   618  		}
   619  		s = goStateTransition(GoID(e.base.args[0]), GoNotExist, status)
   620  		s.Stack = Stack{table: e.table, id: stackID(e.base.args[1])}
   621  	case tracev2.EvGoCreateSyscall:
   622  		s = goStateTransition(GoID(e.base.args[0]), GoNotExist, GoSyscall)
   623  	case tracev2.EvGoStart:
   624  		s = goStateTransition(GoID(e.base.args[0]), GoRunnable, GoRunning)
   625  	case tracev2.EvGoDestroy:
   626  		s = goStateTransition(e.ctx.G, GoRunning, GoNotExist)
   627  	case tracev2.EvGoDestroySyscall:
   628  		s = goStateTransition(e.ctx.G, GoSyscall, GoNotExist)
   629  	case tracev2.EvGoStop:
   630  		s = goStateTransition(e.ctx.G, GoRunning, GoRunnable)
   631  		s.Reason = e.table.strings.mustGet(stringID(e.base.args[0]))
   632  		s.Stack = e.Stack() // This event references the resource the event happened on.
   633  	case tracev2.EvGoBlock:
   634  		s = goStateTransition(e.ctx.G, GoRunning, GoWaiting)
   635  		s.Reason = e.table.strings.mustGet(stringID(e.base.args[0]))
   636  		s.Stack = e.Stack() // This event references the resource the event happened on.
   637  	case tracev2.EvGoUnblock, tracev2.EvGoSwitch, tracev2.EvGoSwitchDestroy:
   638  		// N.B. GoSwitch and GoSwitchDestroy both emit additional events, but
   639  		// the first thing they both do is unblock the goroutine they name,
   640  		// identically to an unblock event (even their arguments match).
   641  		s = goStateTransition(GoID(e.base.args[0]), GoWaiting, GoRunnable)
   642  	case tracev2.EvGoSyscallBegin:
   643  		s = goStateTransition(e.ctx.G, GoRunning, GoSyscall)
   644  		s.Stack = e.Stack() // This event references the resource the event happened on.
   645  	case tracev2.EvGoSyscallEnd:
   646  		s = goStateTransition(e.ctx.G, GoSyscall, GoRunning)
   647  	case tracev2.EvGoSyscallEndBlocked:
   648  		s = goStateTransition(e.ctx.G, GoSyscall, GoRunnable)
   649  	case tracev2.EvGoStatus, tracev2.EvGoStatusStack:
   650  		packedStatus := e.base.args[2]
   651  		from, to := packedStatus>>32, packedStatus&((1<<32)-1)
   652  		s = goStateTransition(GoID(e.base.args[0]), GoState(from), tracev2GoStatus2GoState[to])
   653  	default:
   654  		panic(fmt.Sprintf("internal error: unexpected wire-format event type for StateTransition kind: %d", e.base.typ))
   655  	}
   656  	return s
   657  }
   658  
   659  // Sync returns details that are relevant for the following events, up to but excluding the
   660  // next EventSync event.
   661  func (e Event) Sync() Sync {
   662  	if e.Kind() != EventSync {
   663  		panic("Sync called on non-Sync event")
   664  	}
   665  	s := Sync{N: int(e.base.args[0])}
   666  	if e.table != nil {
   667  		expBatches := make(map[string][]ExperimentalBatch)
   668  		for exp, batches := range e.table.expBatches {
   669  			expBatches[tracev2.Experiments()[exp]] = batches
   670  		}
   671  		s.ExperimentalBatches = expBatches
   672  		if e.table.hasClockSnapshot {
   673  			s.ClockSnapshot = &ClockSnapshot{
   674  				Trace: e.table.freq.mul(e.table.snapTime),
   675  				Wall:  e.table.snapWall,
   676  				Mono:  e.table.snapMono,
   677  			}
   678  		}
   679  	}
   680  	return s
   681  }
   682  
   683  // Sync contains details potentially relevant to all the following events, up to but excluding
   684  // the next EventSync event.
   685  type Sync struct {
   686  	// N indicates that this is the Nth sync event in the trace.
   687  	N int
   688  
   689  	// ClockSnapshot represents a near-simultaneous clock reading of several
   690  	// different system clocks. The snapshot can be used as a reference to
   691  	// convert timestamps to different clocks, which is helpful for correlating
   692  	// timestamps with data captured by other tools. The value is nil for traces
   693  	// before go1.25.
   694  	ClockSnapshot *ClockSnapshot
   695  
   696  	// ExperimentalBatches contain all the unparsed batches of data for a given experiment.
   697  	ExperimentalBatches map[string][]ExperimentalBatch
   698  }
   699  
   700  // ClockSnapshot represents a near-simultaneous clock reading of several
   701  // different system clocks. The snapshot can be used as a reference to convert
   702  // timestamps to different clocks, which is helpful for correlating timestamps
   703  // with data captured by other tools.
   704  type ClockSnapshot struct {
   705  	// Trace is a snapshot of the trace clock.
   706  	Trace Time
   707  
   708  	// Wall is a snapshot of the system's wall clock.
   709  	Wall time.Time
   710  
   711  	// Mono is a snapshot of the system's monotonic clock.
   712  	Mono uint64
   713  }
   714  
   715  // Experimental returns a view of the raw event for an experimental event.
   716  //
   717  // Panics if Kind != EventExperimental.
   718  func (e Event) Experimental() ExperimentalEvent {
   719  	if e.Kind() != EventExperimental {
   720  		panic("Experimental called on non-Experimental event")
   721  	}
   722  	spec := tracev2.Specs()[e.base.typ]
   723  	argNames := spec.Args[1:] // Skip timestamp; already handled.
   724  	return ExperimentalEvent{
   725  		Name:       spec.Name,
   726  		Experiment: tracev2.Experiments()[spec.Experiment],
   727  		Args:       argNames,
   728  		table:      e.table,
   729  		argValues:  e.base.args[:len(argNames)],
   730  	}
   731  }
   732  
   733  const evSync = ^tracev2.EventType(0)
   734  
   735  var tracev2Type2Kind = [...]EventKind{
   736  	tracev2.EvCPUSample:           EventStackSample,
   737  	tracev2.EvProcsChange:         EventMetric,
   738  	tracev2.EvProcStart:           EventStateTransition,
   739  	tracev2.EvProcStop:            EventStateTransition,
   740  	tracev2.EvProcSteal:           EventStateTransition,
   741  	tracev2.EvProcStatus:          EventStateTransition,
   742  	tracev2.EvGoCreate:            EventStateTransition,
   743  	tracev2.EvGoCreateSyscall:     EventStateTransition,
   744  	tracev2.EvGoStart:             EventStateTransition,
   745  	tracev2.EvGoDestroy:           EventStateTransition,
   746  	tracev2.EvGoDestroySyscall:    EventStateTransition,
   747  	tracev2.EvGoStop:              EventStateTransition,
   748  	tracev2.EvGoBlock:             EventStateTransition,
   749  	tracev2.EvGoUnblock:           EventStateTransition,
   750  	tracev2.EvGoSyscallBegin:      EventStateTransition,
   751  	tracev2.EvGoSyscallEnd:        EventStateTransition,
   752  	tracev2.EvGoSyscallEndBlocked: EventStateTransition,
   753  	tracev2.EvGoStatus:            EventStateTransition,
   754  	tracev2.EvSTWBegin:            EventRangeBegin,
   755  	tracev2.EvSTWEnd:              EventRangeEnd,
   756  	tracev2.EvGCActive:            EventRangeActive,
   757  	tracev2.EvGCBegin:             EventRangeBegin,
   758  	tracev2.EvGCEnd:               EventRangeEnd,
   759  	tracev2.EvGCSweepActive:       EventRangeActive,
   760  	tracev2.EvGCSweepBegin:        EventRangeBegin,
   761  	tracev2.EvGCSweepEnd:          EventRangeEnd,
   762  	tracev2.EvGCMarkAssistActive:  EventRangeActive,
   763  	tracev2.EvGCMarkAssistBegin:   EventRangeBegin,
   764  	tracev2.EvGCMarkAssistEnd:     EventRangeEnd,
   765  	tracev2.EvHeapAlloc:           EventMetric,
   766  	tracev2.EvHeapGoal:            EventMetric,
   767  	tracev2.EvGoLabel:             EventLabel,
   768  	tracev2.EvUserTaskBegin:       EventTaskBegin,
   769  	tracev2.EvUserTaskEnd:         EventTaskEnd,
   770  	tracev2.EvUserRegionBegin:     EventRegionBegin,
   771  	tracev2.EvUserRegionEnd:       EventRegionEnd,
   772  	tracev2.EvUserLog:             EventLog,
   773  	tracev2.EvGoSwitch:            EventStateTransition,
   774  	tracev2.EvGoSwitchDestroy:     EventStateTransition,
   775  	tracev2.EvGoCreateBlocked:     EventStateTransition,
   776  	tracev2.EvGoStatusStack:       EventStateTransition,
   777  	tracev2.EvSpan:                EventExperimental,
   778  	tracev2.EvSpanAlloc:           EventExperimental,
   779  	tracev2.EvSpanFree:            EventExperimental,
   780  	tracev2.EvHeapObject:          EventExperimental,
   781  	tracev2.EvHeapObjectAlloc:     EventExperimental,
   782  	tracev2.EvHeapObjectFree:      EventExperimental,
   783  	tracev2.EvGoroutineStack:      EventExperimental,
   784  	tracev2.EvGoroutineStackAlloc: EventExperimental,
   785  	tracev2.EvGoroutineStackFree:  EventExperimental,
   786  	evSync:                        EventSync,
   787  }
   788  
   789  var tracev2GoStatus2GoState = [...]GoState{
   790  	tracev2.GoRunnable: GoRunnable,
   791  	tracev2.GoRunning:  GoRunning,
   792  	tracev2.GoWaiting:  GoWaiting,
   793  	tracev2.GoSyscall:  GoSyscall,
   794  }
   795  
   796  var tracev2ProcStatus2ProcState = [...]ProcState{
   797  	tracev2.ProcRunning:          ProcRunning,
   798  	tracev2.ProcIdle:             ProcIdle,
   799  	tracev2.ProcSyscall:          ProcRunning,
   800  	tracev2.ProcSyscallAbandoned: ProcIdle,
   801  }
   802  
   803  // String returns the event as a human-readable string.
   804  //
   805  // The format of the string is intended for debugging and is subject to change.
   806  func (e Event) String() string {
   807  	var sb strings.Builder
   808  	fmt.Fprintf(&sb, "M=%d P=%d G=%d", e.Thread(), e.Proc(), e.Goroutine())
   809  	fmt.Fprintf(&sb, " %s Time=%d", e.Kind(), e.Time())
   810  	// Kind-specific fields.
   811  	switch kind := e.Kind(); kind {
   812  	case EventMetric:
   813  		m := e.Metric()
   814  		v := m.Value.String()
   815  		if m.Value.Kind() == ValueString {
   816  			v = strconv.Quote(v)
   817  		}
   818  		fmt.Fprintf(&sb, " Name=%q Value=%s", m.Name, m.Value)
   819  	case EventLabel:
   820  		l := e.Label()
   821  		fmt.Fprintf(&sb, " Label=%q Resource=%s", l.Label, l.Resource)
   822  	case EventRangeBegin, EventRangeActive, EventRangeEnd:
   823  		r := e.Range()
   824  		fmt.Fprintf(&sb, " Name=%q Scope=%s", r.Name, r.Scope)
   825  		if kind == EventRangeEnd {
   826  			fmt.Fprintf(&sb, " Attributes=[")
   827  			for i, attr := range e.RangeAttributes() {
   828  				if i != 0 {
   829  					fmt.Fprintf(&sb, " ")
   830  				}
   831  				fmt.Fprintf(&sb, "%q=%s", attr.Name, attr.Value)
   832  			}
   833  			fmt.Fprintf(&sb, "]")
   834  		}
   835  	case EventTaskBegin, EventTaskEnd:
   836  		t := e.Task()
   837  		fmt.Fprintf(&sb, " ID=%d Parent=%d Type=%q", t.ID, t.Parent, t.Type)
   838  	case EventRegionBegin, EventRegionEnd:
   839  		r := e.Region()
   840  		fmt.Fprintf(&sb, " Task=%d Type=%q", r.Task, r.Type)
   841  	case EventLog:
   842  		l := e.Log()
   843  		fmt.Fprintf(&sb, " Task=%d Category=%q Message=%q", l.Task, l.Category, l.Message)
   844  	case EventStateTransition:
   845  		s := e.StateTransition()
   846  		switch s.Resource.Kind {
   847  		case ResourceGoroutine:
   848  			id := s.Resource.Goroutine()
   849  			old, new := s.Goroutine()
   850  			fmt.Fprintf(&sb, " GoID=%d %s->%s", id, old, new)
   851  		case ResourceProc:
   852  			id := s.Resource.Proc()
   853  			old, new := s.Proc()
   854  			fmt.Fprintf(&sb, " ProcID=%d %s->%s", id, old, new)
   855  		}
   856  		fmt.Fprintf(&sb, " Reason=%q", s.Reason)
   857  		if s.Stack != NoStack {
   858  			fmt.Fprintln(&sb)
   859  			fmt.Fprintln(&sb, "TransitionStack=")
   860  			for f := range s.Stack.Frames() {
   861  				fmt.Fprintf(&sb, "\t%s @ 0x%x\n", f.Func, f.PC)
   862  				fmt.Fprintf(&sb, "\t\t%s:%d\n", f.File, f.Line)
   863  			}
   864  		}
   865  	case EventExperimental:
   866  		r := e.Experimental()
   867  		fmt.Fprintf(&sb, " Name=%s Args=[", r.Name)
   868  		for i, arg := range r.Args {
   869  			if i != 0 {
   870  				fmt.Fprintf(&sb, ", ")
   871  			}
   872  			fmt.Fprintf(&sb, "%s=%s", arg, r.ArgValue(i).String())
   873  		}
   874  		fmt.Fprintf(&sb, "]")
   875  	case EventSync:
   876  		s := e.Sync()
   877  		fmt.Fprintf(&sb, " N=%d", s.N)
   878  		if s.ClockSnapshot != nil {
   879  			fmt.Fprintf(&sb, " Trace=%d Mono=%d Wall=%s",
   880  				s.ClockSnapshot.Trace,
   881  				s.ClockSnapshot.Mono,
   882  				s.ClockSnapshot.Wall.Format(time.RFC3339Nano),
   883  			)
   884  		}
   885  	}
   886  	if stk := e.Stack(); stk != NoStack {
   887  		fmt.Fprintln(&sb)
   888  		fmt.Fprintln(&sb, "Stack=")
   889  		for f := range stk.Frames() {
   890  			fmt.Fprintf(&sb, "\t%s @ 0x%x\n", f.Func, f.PC)
   891  			fmt.Fprintf(&sb, "\t\t%s:%d\n", f.File, f.Line)
   892  		}
   893  	}
   894  	return sb.String()
   895  }
   896  
   897  // validateTableIDs checks to make sure lookups in e.table
   898  // will work.
   899  func (e Event) validateTableIDs() error {
   900  	if e.base.typ == evSync {
   901  		return nil
   902  	}
   903  	spec := tracev2.Specs()[e.base.typ]
   904  
   905  	// Check stacks.
   906  	for _, i := range spec.StackIDs {
   907  		id := stackID(e.base.args[i-1])
   908  		_, ok := e.table.stacks.get(id)
   909  		if !ok {
   910  			return fmt.Errorf("found invalid stack ID %d for event %s", id, spec.Name)
   911  		}
   912  	}
   913  	// N.B. Strings referenced by stack frames are validated
   914  	// early on, when reading the stacks in to begin with.
   915  
   916  	// Check strings.
   917  	for _, i := range spec.StringIDs {
   918  		id := stringID(e.base.args[i-1])
   919  		_, ok := e.table.strings.get(id)
   920  		if !ok {
   921  			return fmt.Errorf("found invalid string ID %d for event %s", id, spec.Name)
   922  		}
   923  	}
   924  	return nil
   925  }
   926  
   927  func syncEvent(table *evTable, ts Time, n int) Event {
   928  	ev := Event{
   929  		table: table,
   930  		ctx: schedCtx{
   931  			G: NoGoroutine,
   932  			P: NoProc,
   933  			M: NoThread,
   934  		},
   935  		base: baseEvent{
   936  			typ:  evSync,
   937  			time: ts,
   938  		},
   939  	}
   940  	ev.base.args[0] = uint64(n)
   941  	return ev
   942  }
   943  

View as plain text