summary.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  	"cmp"
     9  	"slices"
    10  	"strings"
    11  	"time"
    12  )
    13  
    14  // Summary is the analysis result produced by the summarizer.
    15  type Summary struct {
    16  	Goroutines map[GoID]*GoroutineSummary
    17  	Tasks      map[TaskID]*UserTaskSummary
    18  }
    19  
    20  // GoroutineSummary contains statistics and execution details of a single goroutine.
    21  // (For v2 traces.)
    22  type GoroutineSummary struct {
    23  	ID           GoID
    24  	Name         string // A non-unique human-friendly identifier for the goroutine.
    25  	PC           uint64 // The first PC we saw for the entry function of the goroutine
    26  	CreationTime Time   // Timestamp of the first appearance in the trace.
    27  	StartTime    Time   // Timestamp of the first time it started running. 0 if the goroutine never ran.
    28  	EndTime      Time   // Timestamp of when the goroutine exited. 0 if the goroutine never exited.
    29  
    30  	// List of regions in the goroutine, sorted based on the start time.
    31  	Regions []*UserRegionSummary
    32  
    33  	// Statistics of execution time during the goroutine execution.
    34  	GoroutineExecStats
    35  
    36  	// goroutineSummary is state used just for computing this structure.
    37  	// It's dropped before being returned to the caller.
    38  	//
    39  	// More specifically, if it's nil, it indicates that this summary has
    40  	// already been finalized.
    41  	*goroutineSummary
    42  }
    43  
    44  // UserTaskSummary represents a task in the trace.
    45  type UserTaskSummary struct {
    46  	ID       TaskID
    47  	Name     string
    48  	Parent   *UserTaskSummary // nil if the parent is unknown.
    49  	Children []*UserTaskSummary
    50  
    51  	// Task begin event. An EventTaskBegin event or nil.
    52  	Start *Event
    53  
    54  	// End end event. Normally EventTaskEnd event or nil.
    55  	End *Event
    56  
    57  	// Logs is a list of EventLog events associated with the task.
    58  	Logs []*Event
    59  
    60  	// List of regions in the task, sorted based on the start time.
    61  	Regions []*UserRegionSummary
    62  
    63  	// Goroutines is the set of goroutines associated with this task.
    64  	Goroutines map[GoID]*GoroutineSummary
    65  }
    66  
    67  // Complete returns true if we have complete information about the task
    68  // from the trace: both a start and an end.
    69  func (s *UserTaskSummary) Complete() bool {
    70  	return s.Start != nil && s.End != nil
    71  }
    72  
    73  // Descendents returns a slice consisting of itself (always the first task returned),
    74  // and the transitive closure of all of its children.
    75  func (s *UserTaskSummary) Descendents() []*UserTaskSummary {
    76  	descendents := []*UserTaskSummary{s}
    77  	for _, child := range s.Children {
    78  		descendents = append(descendents, child.Descendents()...)
    79  	}
    80  	return descendents
    81  }
    82  
    83  // UserRegionSummary represents a region and goroutine execution stats
    84  // while the region was active. (For v2 traces.)
    85  type UserRegionSummary struct {
    86  	TaskID TaskID
    87  	Name   string
    88  
    89  	// Region start event. Normally EventRegionBegin event or nil,
    90  	// but can be a state transition event from NotExist or Undetermined
    91  	// if the region is a synthetic region representing task inheritance
    92  	// from the parent goroutine.
    93  	Start *Event
    94  
    95  	// Region end event. Normally EventRegionEnd event or nil,
    96  	// but can be a state transition event to NotExist if the goroutine
    97  	// terminated without explicitly ending the region.
    98  	End *Event
    99  
   100  	GoroutineExecStats
   101  }
   102  
   103  // GoroutineExecStats contains statistics about a goroutine's execution
   104  // during a period of time.
   105  type GoroutineExecStats struct {
   106  	// These stats are all non-overlapping.
   107  	ExecTime          time.Duration
   108  	SchedWaitTime     time.Duration
   109  	BlockTimeByReason map[string]time.Duration
   110  	SyscallTime       time.Duration
   111  	SyscallBlockTime  time.Duration
   112  
   113  	// TotalTime is the duration of the goroutine's presence in the trace.
   114  	// Necessarily overlaps with other stats.
   115  	TotalTime time.Duration
   116  
   117  	// Total time the goroutine spent in certain ranges; may overlap
   118  	// with other stats.
   119  	RangeTime map[string]time.Duration
   120  }
   121  
   122  func (s GoroutineExecStats) NonOverlappingStats() map[string]time.Duration {
   123  	stats := map[string]time.Duration{
   124  		"Execution time":         s.ExecTime,
   125  		"Sched wait time":        s.SchedWaitTime,
   126  		"Syscall execution time": s.SyscallTime,
   127  		"Block time (syscall)":   s.SyscallBlockTime,
   128  		"Unknown time":           s.UnknownTime(),
   129  	}
   130  	for reason, dt := range s.BlockTimeByReason {
   131  		stats["Block time ("+reason+")"] += dt
   132  	}
   133  	// N.B. Don't include RangeTime or TotalTime; they overlap with these other
   134  	// stats.
   135  	return stats
   136  }
   137  
   138  // UnknownTime returns whatever isn't accounted for in TotalTime.
   139  func (s GoroutineExecStats) UnknownTime() time.Duration {
   140  	sum := s.ExecTime + s.SchedWaitTime + s.SyscallTime +
   141  		s.SyscallBlockTime
   142  	for _, dt := range s.BlockTimeByReason {
   143  		sum += dt
   144  	}
   145  	// N.B. Don't include range time. Ranges overlap with
   146  	// other stats, whereas these stats are non-overlapping.
   147  	if sum < s.TotalTime {
   148  		return s.TotalTime - sum
   149  	}
   150  	return 0
   151  }
   152  
   153  // sub returns the stats v-s.
   154  func (s GoroutineExecStats) sub(v GoroutineExecStats) (r GoroutineExecStats) {
   155  	r = s.clone()
   156  	r.ExecTime -= v.ExecTime
   157  	r.SchedWaitTime -= v.SchedWaitTime
   158  	for reason := range s.BlockTimeByReason {
   159  		r.BlockTimeByReason[reason] -= v.BlockTimeByReason[reason]
   160  	}
   161  	r.SyscallTime -= v.SyscallTime
   162  	r.SyscallBlockTime -= v.SyscallBlockTime
   163  	r.TotalTime -= v.TotalTime
   164  	for name := range s.RangeTime {
   165  		r.RangeTime[name] -= v.RangeTime[name]
   166  	}
   167  	return r
   168  }
   169  
   170  func (s GoroutineExecStats) clone() (r GoroutineExecStats) {
   171  	r = s
   172  	r.BlockTimeByReason = make(map[string]time.Duration)
   173  	for reason, dt := range s.BlockTimeByReason {
   174  		r.BlockTimeByReason[reason] = dt
   175  	}
   176  	r.RangeTime = make(map[string]time.Duration)
   177  	for name, dt := range s.RangeTime {
   178  		r.RangeTime[name] = dt
   179  	}
   180  	return r
   181  }
   182  
   183  // snapshotStat returns the snapshot of the goroutine execution statistics.
   184  // This is called as we process the ordered trace event stream. lastTs is used
   185  // to process pending statistics if this is called before any goroutine end event.
   186  func (g *GoroutineSummary) snapshotStat(lastTs Time) (ret GoroutineExecStats) {
   187  	ret = g.GoroutineExecStats.clone()
   188  
   189  	if g.goroutineSummary == nil {
   190  		return ret // Already finalized; no pending state.
   191  	}
   192  
   193  	// Set the total time if necessary.
   194  	if g.TotalTime == 0 {
   195  		ret.TotalTime = lastTs.Sub(g.CreationTime)
   196  	}
   197  
   198  	// Add in time since lastTs.
   199  	if g.lastStartTime != 0 {
   200  		ret.ExecTime += lastTs.Sub(g.lastStartTime)
   201  	}
   202  	if g.lastRunnableTime != 0 {
   203  		ret.SchedWaitTime += lastTs.Sub(g.lastRunnableTime)
   204  	}
   205  	if g.lastBlockTime != 0 {
   206  		ret.BlockTimeByReason[g.lastBlockReason] += lastTs.Sub(g.lastBlockTime)
   207  	}
   208  	if g.lastSyscallTime != 0 {
   209  		ret.SyscallTime += lastTs.Sub(g.lastSyscallTime)
   210  	}
   211  	if g.lastSyscallBlockTime != 0 {
   212  		ret.SchedWaitTime += lastTs.Sub(g.lastSyscallBlockTime)
   213  	}
   214  	for name, ts := range g.lastRangeTime {
   215  		ret.RangeTime[name] += lastTs.Sub(ts)
   216  	}
   217  	return ret
   218  }
   219  
   220  // finalize is called when processing a goroutine end event or at
   221  // the end of trace processing. This finalizes the execution stat
   222  // and any active regions in the goroutine, in which case trigger is nil.
   223  func (g *GoroutineSummary) finalize(lastTs Time, trigger *Event) {
   224  	if trigger != nil {
   225  		g.EndTime = trigger.Time()
   226  	}
   227  	finalStat := g.snapshotStat(lastTs)
   228  
   229  	g.GoroutineExecStats = finalStat
   230  
   231  	// System goroutines are never part of regions, even though they
   232  	// "inherit" a task due to creation (EvGoCreate) from within a region.
   233  	// This may happen e.g. if the first GC is triggered within a region,
   234  	// starting the GC worker goroutines.
   235  	if !IsSystemGoroutine(g.Name) {
   236  		for _, s := range g.activeRegions {
   237  			s.End = trigger
   238  			s.GoroutineExecStats = finalStat.sub(s.GoroutineExecStats)
   239  			g.Regions = append(g.Regions, s)
   240  		}
   241  	}
   242  	*(g.goroutineSummary) = goroutineSummary{}
   243  }
   244  
   245  // goroutineSummary is a private part of GoroutineSummary that is required only during analysis.
   246  type goroutineSummary struct {
   247  	lastStartTime        Time
   248  	lastRunnableTime     Time
   249  	lastBlockTime        Time
   250  	lastBlockReason      string
   251  	lastSyscallTime      Time
   252  	lastSyscallBlockTime Time
   253  	lastRangeTime        map[string]Time
   254  	activeRegions        []*UserRegionSummary // stack of active regions
   255  }
   256  
   257  // Summarizer constructs per-goroutine time statistics for v2 traces.
   258  type Summarizer struct {
   259  	// gs contains the map of goroutine summaries we're building up to return to the caller.
   260  	gs map[GoID]*GoroutineSummary
   261  
   262  	// tasks contains the map of task summaries we're building up to return to the caller.
   263  	tasks map[TaskID]*UserTaskSummary
   264  
   265  	// syscallingP and syscallingG represent a binding between a P and G in a syscall.
   266  	// Used to correctly identify and clean up after syscalls (blocking or otherwise).
   267  	syscallingP map[ProcID]GoID
   268  	syscallingG map[GoID]ProcID
   269  
   270  	// rangesP is used for optimistic tracking of P-based ranges for goroutines.
   271  	//
   272  	// It's a best-effort mapping of an active range on a P to the goroutine we think
   273  	// is associated with it.
   274  	rangesP map[rangeP]GoID
   275  
   276  	lastTs Time // timestamp of the last event processed.
   277  	syncTs Time // timestamp of the last sync event processed (or the first timestamp in the trace).
   278  }
   279  
   280  // NewSummarizer creates a new struct to build goroutine stats from a trace.
   281  func NewSummarizer() *Summarizer {
   282  	return &Summarizer{
   283  		gs:          make(map[GoID]*GoroutineSummary),
   284  		tasks:       make(map[TaskID]*UserTaskSummary),
   285  		syscallingP: make(map[ProcID]GoID),
   286  		syscallingG: make(map[GoID]ProcID),
   287  		rangesP:     make(map[rangeP]GoID),
   288  	}
   289  }
   290  
   291  type rangeP struct {
   292  	id   ProcID
   293  	name string
   294  }
   295  
   296  // Event feeds a single event into the stats summarizer.
   297  func (s *Summarizer) Event(ev *Event) {
   298  	if s.syncTs == 0 {
   299  		s.syncTs = ev.Time()
   300  	}
   301  	s.lastTs = ev.Time()
   302  
   303  	switch ev.Kind() {
   304  	// Record sync time for the RangeActive events.
   305  	case EventSync:
   306  		s.syncTs = ev.Time()
   307  
   308  	// Handle state transitions.
   309  	case EventStateTransition:
   310  		st := ev.StateTransition()
   311  		switch st.Resource.Kind {
   312  		// Handle goroutine transitions, which are the meat of this computation.
   313  		case ResourceGoroutine:
   314  			id := st.Resource.Goroutine()
   315  			old, new := st.Goroutine()
   316  			if old == new {
   317  				// Skip these events; they're not telling us anything new.
   318  				break
   319  			}
   320  
   321  			// Handle transition out.
   322  			g := s.gs[id]
   323  			switch old {
   324  			case GoUndetermined:
   325  				g = &GoroutineSummary{ID: id, goroutineSummary: &goroutineSummary{}}
   326  
   327  				// The goroutine is being named for the first time.
   328  				// If we're coming out of GoUndetermined, then the creation time is the
   329  				// time of the last sync.
   330  				g.CreationTime = s.syncTs
   331  				g.lastRangeTime = make(map[string]Time)
   332  				g.BlockTimeByReason = make(map[string]time.Duration)
   333  				g.RangeTime = make(map[string]time.Duration)
   334  
   335  				// Accumulate all the time we spent in new as if it was old.
   336  				//
   337  				// Note that we still handle "new" again below because the time until
   338  				// the *next* event still needs to be accumulated (even though it's
   339  				// probably going to come immediately after this event).
   340  				stateTime := ev.Time().Sub(s.syncTs)
   341  				switch new {
   342  				case GoRunning:
   343  					g.ExecTime += stateTime
   344  				case GoWaiting:
   345  					g.BlockTimeByReason[st.Reason] += stateTime
   346  				case GoRunnable:
   347  					g.SchedWaitTime += stateTime
   348  				case GoSyscall:
   349  					// For a syscall, we're not going to be 'naming' this P from afar.
   350  					// It's "executing" somewhere. If we've got a P, then that means
   351  					// we've had that P since the start, so this is regular syscall time.
   352  					// Otherwise, this is syscall block time (no P).
   353  					if ev.Proc() == NoProc {
   354  						g.SyscallBlockTime += stateTime
   355  					} else {
   356  						g.SyscallTime += stateTime
   357  					}
   358  				}
   359  				s.gs[g.ID] = g
   360  			case GoNotExist:
   361  				g = &GoroutineSummary{ID: id, goroutineSummary: &goroutineSummary{}}
   362  
   363  				// The goroutine is being created.
   364  				g.CreationTime = ev.Time()
   365  				g.lastRangeTime = make(map[string]Time)
   366  				g.BlockTimeByReason = make(map[string]time.Duration)
   367  				g.RangeTime = make(map[string]time.Duration)
   368  
   369  				// When a goroutine is newly created, inherit the task
   370  				// of the active region. For ease handling of this
   371  				// case, we create a fake region description with the
   372  				// task id. This isn't strictly necessary as this
   373  				// goroutine may not be associated with the task, but
   374  				// it can be convenient to see all children created
   375  				// during a region.
   376  				//
   377  				// N.B. ev.Goroutine() will always be NoGoroutine for the
   378  				// Undetermined case, so this is will simply not fire.
   379  				if creatorG := s.gs[ev.Goroutine()]; creatorG != nil && len(creatorG.activeRegions) > 0 {
   380  					regions := creatorG.activeRegions
   381  					s := regions[len(regions)-1]
   382  					g.activeRegions = []*UserRegionSummary{{TaskID: s.TaskID, Start: ev}}
   383  				}
   384  				s.gs[g.ID] = g
   385  			case GoRunning:
   386  				// Record execution time as we transition out of running
   387  				g.ExecTime += ev.Time().Sub(g.lastStartTime)
   388  				g.lastStartTime = 0
   389  			case GoWaiting:
   390  				// Record block time as we transition out of waiting.
   391  				if g.lastBlockTime != 0 {
   392  					g.BlockTimeByReason[g.lastBlockReason] += ev.Time().Sub(g.lastBlockTime)
   393  					g.lastBlockTime = 0
   394  				}
   395  			case GoRunnable:
   396  				// Record sched latency time as we transition out of runnable.
   397  				if g.lastRunnableTime != 0 {
   398  					g.SchedWaitTime += ev.Time().Sub(g.lastRunnableTime)
   399  					g.lastRunnableTime = 0
   400  				}
   401  			case GoSyscall:
   402  				// Record syscall execution time and syscall block time as we transition out of syscall.
   403  				if g.lastSyscallTime != 0 {
   404  					if g.lastSyscallBlockTime != 0 {
   405  						g.SyscallBlockTime += ev.Time().Sub(g.lastSyscallBlockTime)
   406  						g.SyscallTime += g.lastSyscallBlockTime.Sub(g.lastSyscallTime)
   407  					} else {
   408  						g.SyscallTime += ev.Time().Sub(g.lastSyscallTime)
   409  					}
   410  					g.lastSyscallTime = 0
   411  					g.lastSyscallBlockTime = 0
   412  
   413  					// Clear the syscall map.
   414  					delete(s.syscallingP, s.syscallingG[id])
   415  					delete(s.syscallingG, id)
   416  				}
   417  			}
   418  
   419  			// The goroutine hasn't been identified yet. Take the transition stack
   420  			// and identify the goroutine by the root frame of that stack.
   421  			// This root frame will be identical for all transitions on this
   422  			// goroutine, because it represents its immutable start point.
   423  			if g.Name == "" {
   424  				for frame := range st.Stack.Frames() {
   425  					// NB: this PC won't actually be consistent for
   426  					// goroutines which existed at the start of the
   427  					// trace. The UI doesn't use it directly; this
   428  					// mainly serves as an indication that we
   429  					// actually saw a call stack for the goroutine
   430  					g.PC = frame.PC
   431  					g.Name = frame.Func
   432  				}
   433  			}
   434  
   435  			// Handle transition in.
   436  			switch new {
   437  			case GoRunning:
   438  				// We started running. Record it.
   439  				g.lastStartTime = ev.Time()
   440  				if g.StartTime == 0 {
   441  					g.StartTime = ev.Time()
   442  				}
   443  			case GoRunnable:
   444  				g.lastRunnableTime = ev.Time()
   445  			case GoWaiting:
   446  				if st.Reason != "forever" {
   447  					g.lastBlockTime = ev.Time()
   448  					g.lastBlockReason = st.Reason
   449  					break
   450  				}
   451  				// "Forever" is like goroutine death.
   452  				fallthrough
   453  			case GoNotExist:
   454  				g.finalize(ev.Time(), ev)
   455  			case GoSyscall:
   456  				s.syscallingP[ev.Proc()] = id
   457  				s.syscallingG[id] = ev.Proc()
   458  				g.lastSyscallTime = ev.Time()
   459  			}
   460  
   461  		// Handle procs to detect syscall blocking, which si identifiable as a
   462  		// proc going idle while the goroutine it was attached to is in a syscall.
   463  		case ResourceProc:
   464  			id := st.Resource.Proc()
   465  			old, new := st.Proc()
   466  			if old != new && new == ProcIdle {
   467  				if goid, ok := s.syscallingP[id]; ok {
   468  					g := s.gs[goid]
   469  					g.lastSyscallBlockTime = ev.Time()
   470  					delete(s.syscallingP, id)
   471  				}
   472  			}
   473  		}
   474  
   475  	// Handle ranges of all kinds.
   476  	case EventRangeBegin, EventRangeActive:
   477  		r := ev.Range()
   478  		var g *GoroutineSummary
   479  		switch r.Scope.Kind {
   480  		case ResourceGoroutine:
   481  			// Simple goroutine range. We attribute the entire range regardless of
   482  			// goroutine stats. Lots of situations are still identifiable, e.g. a
   483  			// goroutine blocked often in mark assist will have both high mark assist
   484  			// and high block times. Those interested in a deeper view can look at the
   485  			// trace viewer.
   486  			g = s.gs[r.Scope.Goroutine()]
   487  		case ResourceProc:
   488  			// N.B. These ranges are not actually bound to the goroutine, they're
   489  			// bound to the P. But if we happen to be on the P the whole time, let's
   490  			// try to attribute it to the goroutine. (e.g. GC sweeps are here.)
   491  			g = s.gs[ev.Goroutine()]
   492  			if g != nil {
   493  				s.rangesP[rangeP{id: r.Scope.Proc(), name: r.Name}] = ev.Goroutine()
   494  			}
   495  		}
   496  		if g == nil {
   497  			break
   498  		}
   499  		if ev.Kind() == EventRangeActive {
   500  			if ts := g.lastRangeTime[r.Name]; ts != 0 {
   501  				g.RangeTime[r.Name] += s.syncTs.Sub(ts)
   502  			}
   503  			g.lastRangeTime[r.Name] = s.syncTs
   504  		} else {
   505  			g.lastRangeTime[r.Name] = ev.Time()
   506  		}
   507  	case EventRangeEnd:
   508  		r := ev.Range()
   509  		var g *GoroutineSummary
   510  		switch r.Scope.Kind {
   511  		case ResourceGoroutine:
   512  			g = s.gs[r.Scope.Goroutine()]
   513  		case ResourceProc:
   514  			rp := rangeP{id: r.Scope.Proc(), name: r.Name}
   515  			if goid, ok := s.rangesP[rp]; ok {
   516  				if goid == ev.Goroutine() {
   517  					// As the comment in the RangeBegin case states, this is only OK
   518  					// if we finish on the same goroutine we started on.
   519  					g = s.gs[goid]
   520  				}
   521  				delete(s.rangesP, rp)
   522  			}
   523  		}
   524  		if g == nil {
   525  			break
   526  		}
   527  		ts := g.lastRangeTime[r.Name]
   528  		if ts == 0 {
   529  			break
   530  		}
   531  		g.RangeTime[r.Name] += ev.Time().Sub(ts)
   532  		delete(g.lastRangeTime, r.Name)
   533  
   534  	// Handle user-defined regions.
   535  	case EventRegionBegin:
   536  		g := s.gs[ev.Goroutine()]
   537  		r := ev.Region()
   538  		region := &UserRegionSummary{
   539  			Name:               r.Type,
   540  			TaskID:             r.Task,
   541  			Start:              ev,
   542  			GoroutineExecStats: g.snapshotStat(ev.Time()),
   543  		}
   544  		g.activeRegions = append(g.activeRegions, region)
   545  		// Associate the region and current goroutine to the task.
   546  		task := s.getOrAddTask(r.Task)
   547  		task.Regions = append(task.Regions, region)
   548  		task.Goroutines[g.ID] = g
   549  	case EventRegionEnd:
   550  		g := s.gs[ev.Goroutine()]
   551  		r := ev.Region()
   552  		var sd *UserRegionSummary
   553  		if regionStk := g.activeRegions; len(regionStk) > 0 {
   554  			// Pop the top region from the stack since that's what must have ended.
   555  			n := len(regionStk)
   556  			sd = regionStk[n-1]
   557  			regionStk = regionStk[:n-1]
   558  			g.activeRegions = regionStk
   559  			// N.B. No need to add the region to a task; the EventRegionBegin already handled it.
   560  		} else {
   561  			// This is an "end" without a start. Just fabricate the region now.
   562  			sd = &UserRegionSummary{Name: r.Type, TaskID: r.Task}
   563  			// Associate the region and current goroutine to the task.
   564  			task := s.getOrAddTask(r.Task)
   565  			task.Goroutines[g.ID] = g
   566  			task.Regions = append(task.Regions, sd)
   567  		}
   568  		sd.GoroutineExecStats = g.snapshotStat(ev.Time()).sub(sd.GoroutineExecStats)
   569  		sd.End = ev
   570  		g.Regions = append(g.Regions, sd)
   571  
   572  	// Handle tasks and logs.
   573  	case EventTaskBegin, EventTaskEnd:
   574  		// Initialize the task.
   575  		t := ev.Task()
   576  		task := s.getOrAddTask(t.ID)
   577  		task.Name = t.Type
   578  		task.Goroutines[ev.Goroutine()] = s.gs[ev.Goroutine()]
   579  		if ev.Kind() == EventTaskBegin {
   580  			task.Start = ev
   581  		} else {
   582  			task.End = ev
   583  		}
   584  		// Initialize the parent, if one exists and it hasn't been done yet.
   585  		// We need to avoid doing it twice, otherwise we could appear twice
   586  		// in the parent's Children list.
   587  		if t.Parent != NoTask && task.Parent == nil {
   588  			parent := s.getOrAddTask(t.Parent)
   589  			task.Parent = parent
   590  			parent.Children = append(parent.Children, task)
   591  		}
   592  	case EventLog:
   593  		log := ev.Log()
   594  		// Just add the log to the task. We'll create the task if it
   595  		// doesn't exist (it's just been mentioned now).
   596  		task := s.getOrAddTask(log.Task)
   597  		task.Goroutines[ev.Goroutine()] = s.gs[ev.Goroutine()]
   598  		task.Logs = append(task.Logs, ev)
   599  	}
   600  }
   601  
   602  func (s *Summarizer) getOrAddTask(id TaskID) *UserTaskSummary {
   603  	task := s.tasks[id]
   604  	if task == nil {
   605  		task = &UserTaskSummary{ID: id, Goroutines: make(map[GoID]*GoroutineSummary)}
   606  		s.tasks[id] = task
   607  	}
   608  	return task
   609  }
   610  
   611  // Finalize indicates to the summarizer that we're done processing the trace.
   612  // It cleans up any remaining state and returns the full summary.
   613  func (s *Summarizer) Finalize() *Summary {
   614  	for _, g := range s.gs {
   615  		g.finalize(s.lastTs, nil)
   616  
   617  		// Sort based on region start time.
   618  		slices.SortFunc(g.Regions, func(a, b *UserRegionSummary) int {
   619  			x := a.Start
   620  			y := b.Start
   621  			if x == nil {
   622  				if y == nil {
   623  					return 0
   624  				}
   625  				return -1
   626  			}
   627  			if y == nil {
   628  				return +1
   629  			}
   630  			return cmp.Compare(x.Time(), y.Time())
   631  		})
   632  		g.goroutineSummary = nil
   633  	}
   634  	return &Summary{
   635  		Goroutines: s.gs,
   636  		Tasks:      s.tasks,
   637  	}
   638  }
   639  
   640  // RelatedGoroutinesV2 finds a set of goroutines related to goroutine goid for v2 traces.
   641  // The association is based on whether they have synchronized with each other in the Go
   642  // scheduler (one has unblocked another).
   643  func RelatedGoroutinesV2(events []Event, goid GoID) map[GoID]struct{} {
   644  	// Process all the events, looking for transitions of goroutines
   645  	// out of GoWaiting. If there was an active goroutine when this
   646  	// happened, then we know that active goroutine unblocked another.
   647  	// Scribble all these down so we can process them.
   648  	type unblockEdge struct {
   649  		operator GoID
   650  		operand  GoID
   651  	}
   652  	var unblockEdges []unblockEdge
   653  	for _, ev := range events {
   654  		if ev.Goroutine() == NoGoroutine {
   655  			continue
   656  		}
   657  		if ev.Kind() != EventStateTransition {
   658  			continue
   659  		}
   660  		st := ev.StateTransition()
   661  		if st.Resource.Kind != ResourceGoroutine {
   662  			continue
   663  		}
   664  		id := st.Resource.Goroutine()
   665  		old, new := st.Goroutine()
   666  		if old == new || old != GoWaiting {
   667  			continue
   668  		}
   669  		unblockEdges = append(unblockEdges, unblockEdge{
   670  			operator: ev.Goroutine(),
   671  			operand:  id,
   672  		})
   673  	}
   674  	// Compute the transitive closure of depth 2 of goroutines that have unblocked each other
   675  	// (starting from goid).
   676  	gmap := make(map[GoID]struct{})
   677  	gmap[goid] = struct{}{}
   678  	for i := 0; i < 2; i++ {
   679  		// Copy the map.
   680  		gmap1 := make(map[GoID]struct{})
   681  		for g := range gmap {
   682  			gmap1[g] = struct{}{}
   683  		}
   684  		for _, edge := range unblockEdges {
   685  			if _, ok := gmap[edge.operand]; ok {
   686  				gmap1[edge.operator] = struct{}{}
   687  			}
   688  		}
   689  		gmap = gmap1
   690  	}
   691  	return gmap
   692  }
   693  
   694  func IsSystemGoroutine(entryFn string) bool {
   695  	// This mimics runtime.isSystemGoroutine as closely as
   696  	// possible.
   697  	// Also, locked g in extra M (with empty entryFn) is system goroutine.
   698  	return entryFn == "" || entryFn != "runtime.main" && strings.HasPrefix(entryFn, "runtime.")
   699  }
   700
View as plain text