pprof.go

Documentation: cmd/trace/v2

     1  // Copyright 2014 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  // Serving of pprof-like profiles.
     6  
     7  package trace
     8  
     9  import (
    10  	"cmp"
    11  	"fmt"
    12  	"internal/trace"
    13  	"internal/trace/traceviewer"
    14  	tracev2 "internal/trace/v2"
    15  	"net/http"
    16  	"slices"
    17  	"strings"
    18  	"time"
    19  )
    20  
    21  func pprofByGoroutine(compute computePprofFunc, t *parsedTrace) traceviewer.ProfileFunc {
    22  	return func(r *http.Request) ([]traceviewer.ProfileRecord, error) {
    23  		name := r.FormValue("name")
    24  		gToIntervals, err := pprofMatchingGoroutines(name, t)
    25  		if err != nil {
    26  			return nil, err
    27  		}
    28  		return compute(gToIntervals, t.events)
    29  	}
    30  }
    31  
    32  func pprofByRegion(compute computePprofFunc, t *parsedTrace) traceviewer.ProfileFunc {
    33  	return func(r *http.Request) ([]traceviewer.ProfileRecord, error) {
    34  		filter, err := newRegionFilter(r)
    35  		if err != nil {
    36  			return nil, err
    37  		}
    38  		gToIntervals, err := pprofMatchingRegions(filter, t)
    39  		if err != nil {
    40  			return nil, err
    41  		}
    42  		return compute(gToIntervals, t.events)
    43  	}
    44  }
    45  
    46  // pprofMatchingGoroutines returns the ids of goroutines of the matching name and its interval.
    47  // If the id string is empty, returns nil without an error.
    48  func pprofMatchingGoroutines(name string, t *parsedTrace) (map[tracev2.GoID][]interval, error) {
    49  	res := make(map[tracev2.GoID][]interval)
    50  	for _, g := range t.summary.Goroutines {
    51  		if g.Name != name {
    52  			continue
    53  		}
    54  		endTime := g.EndTime
    55  		if g.EndTime == 0 {
    56  			endTime = t.endTime() // Use the trace end time, since the goroutine is still live then.
    57  		}
    58  		res[g.ID] = []interval{{start: g.StartTime, end: endTime}}
    59  	}
    60  	if len(res) == 0 {
    61  		return nil, fmt.Errorf("failed to find matching goroutines for name: %s", name)
    62  	}
    63  	return res, nil
    64  }
    65  
    66  // pprofMatchingRegions returns the time intervals of matching regions
    67  // grouped by the goroutine id. If the filter is nil, returns nil without an error.
    68  func pprofMatchingRegions(filter *regionFilter, t *parsedTrace) (map[tracev2.GoID][]interval, error) {
    69  	if filter == nil {
    70  		return nil, nil
    71  	}
    72  
    73  	gToIntervals := make(map[tracev2.GoID][]interval)
    74  	for _, g := range t.summary.Goroutines {
    75  		for _, r := range g.Regions {
    76  			if !filter.match(t, r) {
    77  				continue
    78  			}
    79  			gToIntervals[g.ID] = append(gToIntervals[g.ID], regionInterval(t, r))
    80  		}
    81  	}
    82  
    83  	for g, intervals := range gToIntervals {
    84  		// In order to remove nested regions and
    85  		// consider only the outermost regions,
    86  		// first, we sort based on the start time
    87  		// and then scan through to select only the outermost regions.
    88  		slices.SortFunc(intervals, func(a, b interval) int {
    89  			if c := cmp.Compare(a.start, b.start); c != 0 {
    90  				return c
    91  			}
    92  			return cmp.Compare(a.end, b.end)
    93  		})
    94  		var lastTimestamp tracev2.Time
    95  		var n int
    96  		// Select only the outermost regions.
    97  		for _, i := range intervals {
    98  			if lastTimestamp <= i.start {
    99  				intervals[n] = i // new non-overlapping region starts.
   100  				lastTimestamp = i.end
   101  				n++
   102  			}
   103  			// Otherwise, skip because this region overlaps with a previous region.
   104  		}
   105  		gToIntervals[g] = intervals[:n]
   106  	}
   107  	return gToIntervals, nil
   108  }
   109  
   110  type computePprofFunc func(gToIntervals map[tracev2.GoID][]interval, events []tracev2.Event) ([]traceviewer.ProfileRecord, error)
   111  
   112  // computePprofIO returns a computePprofFunc that generates IO pprof-like profile (time spent in
   113  // IO wait, currently only network blocking event).
   114  func computePprofIO() computePprofFunc {
   115  	return makeComputePprofFunc(tracev2.GoWaiting, func(reason string) bool {
   116  		return reason == "network"
   117  	})
   118  }
   119  
   120  // computePprofBlock returns a computePprofFunc that generates blocking pprof-like profile
   121  // (time spent blocked on synchronization primitives).
   122  func computePprofBlock() computePprofFunc {
   123  	return makeComputePprofFunc(tracev2.GoWaiting, func(reason string) bool {
   124  		return strings.Contains(reason, "chan") || strings.Contains(reason, "sync") || strings.Contains(reason, "select")
   125  	})
   126  }
   127  
   128  // computePprofSyscall returns a computePprofFunc that generates a syscall pprof-like
   129  // profile (time spent in syscalls).
   130  func computePprofSyscall() computePprofFunc {
   131  	return makeComputePprofFunc(tracev2.GoSyscall, func(_ string) bool {
   132  		return true
   133  	})
   134  }
   135  
   136  // computePprofSched returns a computePprofFunc that generates a scheduler latency pprof-like profile
   137  // (time between a goroutine become runnable and actually scheduled for execution).
   138  func computePprofSched() computePprofFunc {
   139  	return makeComputePprofFunc(tracev2.GoRunnable, func(_ string) bool {
   140  		return true
   141  	})
   142  }
   143  
   144  // makeComputePprofFunc returns a computePprofFunc that generates a profile of time goroutines spend
   145  // in a particular state for the specified reasons.
   146  func makeComputePprofFunc(state tracev2.GoState, trackReason func(string) bool) computePprofFunc {
   147  	return func(gToIntervals map[tracev2.GoID][]interval, events []tracev2.Event) ([]traceviewer.ProfileRecord, error) {
   148  		stacks := newStackMap()
   149  		tracking := make(map[tracev2.GoID]*tracev2.Event)
   150  		for i := range events {
   151  			ev := &events[i]
   152  
   153  			// Filter out any non-state-transitions and events without stacks.
   154  			if ev.Kind() != tracev2.EventStateTransition {
   155  				continue
   156  			}
   157  			stack := ev.Stack()
   158  			if stack == tracev2.NoStack {
   159  				continue
   160  			}
   161  
   162  			// The state transition has to apply to a goroutine.
   163  			st := ev.StateTransition()
   164  			if st.Resource.Kind != tracev2.ResourceGoroutine {
   165  				continue
   166  			}
   167  			id := st.Resource.Goroutine()
   168  			_, new := st.Goroutine()
   169  
   170  			// Check if we're tracking this goroutine.
   171  			startEv := tracking[id]
   172  			if startEv == nil {
   173  				// We're not. Start tracking if the new state
   174  				// matches what we want and the transition is
   175  				// for one of the reasons we care about.
   176  				if new == state && trackReason(st.Reason) {
   177  					tracking[id] = ev
   178  				}
   179  				continue
   180  			}
   181  			// We're tracking this goroutine.
   182  			if new == state {
   183  				// We're tracking this goroutine, but it's just transitioning
   184  				// to the same state (this is a no-ip
   185  				continue
   186  			}
   187  			// The goroutine has transitioned out of the state we care about,
   188  			// so remove it from tracking and record the stack.
   189  			delete(tracking, id)
   190  
   191  			overlapping := pprofOverlappingDuration(gToIntervals, id, interval{startEv.Time(), ev.Time()})
   192  			if overlapping > 0 {
   193  				rec := stacks.getOrAdd(startEv.Stack())
   194  				rec.Count++
   195  				rec.Time += overlapping
   196  			}
   197  		}
   198  		return stacks.profile(), nil
   199  	}
   200  }
   201  
   202  // pprofOverlappingDuration returns the overlapping duration between
   203  // the time intervals in gToIntervals and the specified event.
   204  // If gToIntervals is nil, this simply returns the event's duration.
   205  func pprofOverlappingDuration(gToIntervals map[tracev2.GoID][]interval, id tracev2.GoID, sample interval) time.Duration {
   206  	if gToIntervals == nil { // No filtering.
   207  		return sample.duration()
   208  	}
   209  	intervals := gToIntervals[id]
   210  	if len(intervals) == 0 {
   211  		return 0
   212  	}
   213  
   214  	var overlapping time.Duration
   215  	for _, i := range intervals {
   216  		if o := i.overlap(sample); o > 0 {
   217  			overlapping += o
   218  		}
   219  	}
   220  	return overlapping
   221  }
   222  
   223  // interval represents a time interval in the trace.
   224  type interval struct {
   225  	start, end tracev2.Time
   226  }
   227  
   228  func (i interval) duration() time.Duration {
   229  	return i.end.Sub(i.start)
   230  }
   231  
   232  func (i1 interval) overlap(i2 interval) time.Duration {
   233  	// Assume start1 <= end1 and start2 <= end2
   234  	if i1.end < i2.start || i2.end < i1.start {
   235  		return 0
   236  	}
   237  	if i1.start < i2.start { // choose the later one
   238  		i1.start = i2.start
   239  	}
   240  	if i1.end > i2.end { // choose the earlier one
   241  		i1.end = i2.end
   242  	}
   243  	return i1.duration()
   244  }
   245  
   246  // pprofMaxStack is the extent of the deduplication we're willing to do.
   247  //
   248  // Because slices aren't comparable and we want to leverage maps for deduplication,
   249  // we have to choose a fixed constant upper bound on the amount of frames we want
   250  // to support. In practice this is fine because there's a maximum depth to these
   251  // stacks anyway.
   252  const pprofMaxStack = 128
   253  
   254  // stackMap is a map of tracev2.Stack to some value V.
   255  type stackMap struct {
   256  	// stacks contains the full list of stacks in the set, however
   257  	// it is insufficient for deduplication because tracev2.Stack
   258  	// equality is only optimistic. If two tracev2.Stacks are equal,
   259  	// then they are guaranteed to be equal in content. If they are
   260  	// not equal, then they might still be equal in content.
   261  	stacks map[tracev2.Stack]*traceviewer.ProfileRecord
   262  
   263  	// pcs is the source-of-truth for deduplication. It is a map of
   264  	// the actual PCs in the stack to a tracev2.Stack.
   265  	pcs map[[pprofMaxStack]uint64]tracev2.Stack
   266  }
   267  
   268  func newStackMap() *stackMap {
   269  	return &stackMap{
   270  		stacks: make(map[tracev2.Stack]*traceviewer.ProfileRecord),
   271  		pcs:    make(map[[pprofMaxStack]uint64]tracev2.Stack),
   272  	}
   273  }
   274  
   275  func (m *stackMap) getOrAdd(stack tracev2.Stack) *traceviewer.ProfileRecord {
   276  	// Fast path: check to see if this exact stack is already in the map.
   277  	if rec, ok := m.stacks[stack]; ok {
   278  		return rec
   279  	}
   280  	// Slow path: the stack may still be in the map.
   281  
   282  	// Grab the stack's PCs as the source-of-truth.
   283  	var pcs [pprofMaxStack]uint64
   284  	pcsForStack(stack, &pcs)
   285  
   286  	// Check the source-of-truth.
   287  	var rec *traceviewer.ProfileRecord
   288  	if existing, ok := m.pcs[pcs]; ok {
   289  		// In the map.
   290  		rec = m.stacks[existing]
   291  		delete(m.stacks, existing)
   292  	} else {
   293  		// Not in the map.
   294  		rec = new(traceviewer.ProfileRecord)
   295  	}
   296  	// Insert regardless of whether we have a match in m.pcs.
   297  	// Even if we have a match, we want to keep the newest version
   298  	// of that stack, since we're much more likely tos see it again
   299  	// as we iterate through the trace linearly. Simultaneously, we
   300  	// are likely to never see the old stack again.
   301  	m.pcs[pcs] = stack
   302  	m.stacks[stack] = rec
   303  	return rec
   304  }
   305  
   306  func (m *stackMap) profile() []traceviewer.ProfileRecord {
   307  	prof := make([]traceviewer.ProfileRecord, 0, len(m.stacks))
   308  	for stack, record := range m.stacks {
   309  		rec := *record
   310  		i := 0
   311  		stack.Frames(func(frame tracev2.StackFrame) bool {
   312  			rec.Stack = append(rec.Stack, &trace.Frame{
   313  				PC:   frame.PC,
   314  				Fn:   frame.Func,
   315  				File: frame.File,
   316  				Line: int(frame.Line),
   317  			})
   318  			i++
   319  			// Cut this off at pprofMaxStack because that's as far
   320  			// as our deduplication goes.
   321  			return i < pprofMaxStack
   322  		})
   323  		prof = append(prof, rec)
   324  	}
   325  	return prof
   326  }
   327  
   328  // pcsForStack extracts the first pprofMaxStack PCs from stack into pcs.
   329  func pcsForStack(stack tracev2.Stack, pcs *[pprofMaxStack]uint64) {
   330  	i := 0
   331  	stack.Frames(func(frame tracev2.StackFrame) bool {
   332  		pcs[i] = frame.PC
   333  		i++
   334  		return i < len(pcs)
   335  	})
   336  }
   337
View as plain text