From a51713103b5769a792b691e313254b7806855fa6 Mon Sep 17 00:00:00 2001 From: Nick Ripley Date: Wed, 7 Feb 2024 11:43:05 -0500 Subject: [PATCH] cmd/trace/v2,internal/trace: use correct frame for identifying goroutines To determine the identity of a goroutine for displaying in the trace UI, we should use the root frame from a call stack. This will be the starting function for the goroutine and is the same for each call stack from a given goroutine. The new tracer no longer includes starting PCs for goroutines which existed at the start of tracing, so we can't use a PC for grouping together goroutines any more. Instead, we just use the name of the entry function for grouping. Fixes #65574 Change-Id: I5324653316f1acf0ab90c30680f181060ea45dd7 Reviewed-on: https://go-review.googlesource.com/c/go/+/562455 Reviewed-by: Michael Knyszek LUCI-TryBot-Result: Go LUCI Reviewed-by: David Chase --- src/cmd/trace/v2/goroutines.go | 43 ++++++++++-------------------- src/cmd/trace/v2/pprof.go | 23 +++++----------- src/internal/trace/summary.go | 15 +++++++---- src/internal/trace/summary_test.go | 13 +++++++++ 4 files changed, 44 insertions(+), 50 deletions(-) diff --git a/src/cmd/trace/v2/goroutines.go b/src/cmd/trace/v2/goroutines.go index 44febeba88e2a..3cf366635af17 100644 --- a/src/cmd/trace/v2/goroutines.go +++ b/src/cmd/trace/v2/goroutines.go @@ -17,7 +17,6 @@ import ( "net/http" "slices" "sort" - "strconv" "strings" "time" ) @@ -25,31 +24,23 @@ import ( // GoroutinesHandlerFunc returns a HandlerFunc that serves list of goroutine groups. func GoroutinesHandlerFunc(summaries map[tracev2.GoID]*trace.GoroutineSummary) http.HandlerFunc { return func(w http.ResponseWriter, r *http.Request) { - // goroutineGroup describes a group of goroutines grouped by start PC. + // goroutineGroup describes a group of goroutines grouped by name. type goroutineGroup struct { - ID uint64 // Unique identifier (PC). Name string // Start function. N int // Total number of goroutines in this group. ExecTime time.Duration // Total execution time of all goroutines in this group. } - // Accumulate groups by PC. - groupsByPC := make(map[uint64]goroutineGroup) + // Accumulate groups by Name. + groupsByName := make(map[string]goroutineGroup) for _, summary := range summaries { - group := groupsByPC[summary.PC] - group.ID = summary.PC + group := groupsByName[summary.Name] group.Name = summary.Name group.N++ group.ExecTime += summary.ExecTime - groupsByPC[summary.PC] = group + groupsByName[summary.Name] = group } var groups []goroutineGroup - for pc, group := range groupsByPC { - group.ID = pc - // If goroutine didn't run during the trace (no sampled PC), - // the v.ID and v.Name will be zero value. - if group.ID == 0 && group.Name == "" { - group.Name = "(Inactive, no stack trace sampled)" - } + for _, group := range groupsByName { groups = append(groups, group) } slices.SortFunc(groups, func(a, b goroutineGroup) int { @@ -92,7 +83,7 @@ Click a start location to view more details about that group.
{{range $}} - {{.Name}} + {{or .Name "(Inactive, no stack trace sampled)"}} {{.N}} {{.ExecTime}} @@ -106,11 +97,7 @@ Click a start location to view more details about that group.
// goroutines in a particular group. func GoroutineHandler(summaries map[tracev2.GoID]*trace.GoroutineSummary) http.HandlerFunc { return func(w http.ResponseWriter, r *http.Request) { - pc, err := strconv.ParseUint(r.FormValue("id"), 10, 64) - if err != nil { - http.Error(w, fmt.Sprintf("failed to parse id parameter '%v': %v", r.FormValue("id"), err), http.StatusInternalServerError) - return - } + goroutineName := r.FormValue("name") type goroutine struct { *trace.GoroutineSummary @@ -130,7 +117,7 @@ func GoroutineHandler(summaries map[tracev2.GoID]*trace.GoroutineSummary) http.H for _, summary := range summaries { totalExecTime += summary.ExecTime - if summary.PC != pc { + if summary.Name != goroutineName { continue } nonOverlappingStats := summary.NonOverlappingStats() @@ -198,9 +185,8 @@ func GoroutineHandler(summaries map[tracev2.GoID]*trace.GoroutineSummary) http.H } sort.Strings(allRangeStats) - err = templGoroutine.Execute(w, struct { + err := templGoroutine.Execute(w, struct { Name string - PC uint64 N int ExecTimePercent string MaxTotal time.Duration @@ -209,7 +195,6 @@ func GoroutineHandler(summaries map[tracev2.GoID]*trace.GoroutineSummary) http.H RangeStats []string }{ Name: name, - PC: pc, N: len(goroutines), ExecTimePercent: execTimePercent, MaxTotal: maxTotalTime, @@ -339,19 +324,19 @@ Table of contents Network wait profile: - graph (download) + graph (download) Sync block profile: - graph (download) + graph (download) Syscall profile: - graph (download) + graph (download) Scheduler wait profile: - graph (download) + graph (download) diff --git a/src/cmd/trace/v2/pprof.go b/src/cmd/trace/v2/pprof.go index 4ec7b3a59835a..05895eda3dee8 100644 --- a/src/cmd/trace/v2/pprof.go +++ b/src/cmd/trace/v2/pprof.go @@ -14,15 +14,14 @@ import ( tracev2 "internal/trace/v2" "net/http" "slices" - "strconv" "strings" "time" ) func pprofByGoroutine(compute computePprofFunc, t *parsedTrace) traceviewer.ProfileFunc { return func(r *http.Request) ([]traceviewer.ProfileRecord, error) { - id := r.FormValue("id") - gToIntervals, err := pprofMatchingGoroutines(id, t) + name := r.FormValue("name") + gToIntervals, err := pprofMatchingGoroutines(name, t) if err != nil { return nil, err } @@ -44,20 +43,12 @@ func pprofByRegion(compute computePprofFunc, t *parsedTrace) traceviewer.Profile } } -// pprofMatchingGoroutines parses the goroutine type id string (i.e. pc) -// and returns the ids of goroutines of the matching type and its interval. +// pprofMatchingGoroutines returns the ids of goroutines of the matching name and its interval. // If the id string is empty, returns nil without an error. -func pprofMatchingGoroutines(id string, t *parsedTrace) (map[tracev2.GoID][]interval, error) { - if id == "" { - return nil, nil - } - pc, err := strconv.ParseUint(id, 10, 64) // id is string - if err != nil { - return nil, fmt.Errorf("invalid goroutine type: %v", id) - } +func pprofMatchingGoroutines(name string, t *parsedTrace) (map[tracev2.GoID][]interval, error) { res := make(map[tracev2.GoID][]interval) for _, g := range t.summary.Goroutines { - if g.PC != pc { + if g.Name != name { continue } endTime := g.EndTime @@ -66,8 +57,8 @@ func pprofMatchingGoroutines(id string, t *parsedTrace) (map[tracev2.GoID][]inte } res[g.ID] = []interval{{start: g.StartTime, end: endTime}} } - if len(res) == 0 && id != "" { - return nil, fmt.Errorf("failed to find matching goroutines for ID: %s", id) + if len(res) == 0 { + return nil, fmt.Errorf("failed to find matching goroutines for name: %s", name) } return res, nil } diff --git a/src/internal/trace/summary.go b/src/internal/trace/summary.go index 9003385fc7f00..b714e01f4aa78 100644 --- a/src/internal/trace/summary.go +++ b/src/internal/trace/summary.go @@ -21,7 +21,7 @@ type Summary struct { type GoroutineSummary struct { ID tracev2.GoID Name string // A non-unique human-friendly identifier for the goroutine. - PC uint64 // The start PC of the goroutine. + PC uint64 // The first PC we saw for the entry function of the goroutine CreationTime tracev2.Time // Timestamp of the first appearance in the trace. StartTime tracev2.Time // Timestamp of the first time it started running. 0 if the goroutine never ran. EndTime tracev2.Time // Timestamp of when the goroutine exited. 0 if the goroutine never exited. @@ -385,10 +385,10 @@ func (s *Summarizer) Event(ev *tracev2.Event) { } // The goroutine hasn't been identified yet. Take the transition stack - // and identify the goroutine by the bottom-most frame of that stack. - // This bottom-most frame will be identical for all transitions on this + // and identify the goroutine by the root frame of that stack. + // This root frame will be identical for all transitions on this // goroutine, because it represents its immutable start point. - if g.PC == 0 { + if g.Name == "" { stk := st.Stack if stk != tracev2.NoStack { var frame tracev2.StackFrame @@ -396,9 +396,14 @@ func (s *Summarizer) Event(ev *tracev2.Event) { stk.Frames(func(f tracev2.StackFrame) bool { frame = f ok = true - return false + return true }) if ok { + // NB: this PC won't actually be consistent for + // goroutines which existed at the start of the + // trace. The UI doesn't use it directly; this + // mainly serves as an indication that we + // actually saw a call stack for the goroutine g.PC = frame.PC g.Name = frame.Func } diff --git a/src/internal/trace/summary_test.go b/src/internal/trace/summary_test.go index 862218bf10c63..9978b57d9834b 100644 --- a/src/internal/trace/summary_test.go +++ b/src/internal/trace/summary_test.go @@ -18,6 +18,10 @@ func TestSummarizeGoroutinesTrace(t *testing.T) { hasSyncBlockTime bool hasGCMarkAssistTime bool ) + + assertContainsGoroutine(t, summaries, "runtime.gcBgMarkWorker") + assertContainsGoroutine(t, summaries, "main.main.func1") + for _, summary := range summaries { basicGoroutineSummaryChecks(t, summary) hasSchedWaitTime = hasSchedWaitTime || summary.SchedWaitTime > 0 @@ -232,6 +236,15 @@ func TestSummarizeTasksTrace(t *testing.T) { } } +func assertContainsGoroutine(t *testing.T, summaries map[tracev2.GoID]*GoroutineSummary, name string) { + for _, summary := range summaries { + if summary.Name == name { + return + } + } + t.Errorf("missing goroutine %s", name) +} + func basicGoroutineSummaryChecks(t *testing.T, summary *GoroutineSummary) { if summary.ID == tracev2.NoGoroutine { t.Error("summary found for no goroutine")