pprof.go

Documentation: cmd/trace

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