diff options
| author | Michael Anthony Knyszek <mknyszek@google.com> | 2023-11-13 18:57:06 +0000 |
|---|---|---|
| committer | Michael Knyszek <mknyszek@google.com> | 2023-11-21 21:28:11 +0000 |
| commit | d1dcffdb4a40f8ea89d9e57744142f9805b64840 (patch) | |
| tree | 4bb0cfc25383b161c694a44b817a31fe477044b3 /src/internal/trace | |
| parent | b83934830fe9353ae38a08f7efe5b30f8851edd1 (diff) | |
| download | go-d1dcffdb4a40f8ea89d9e57744142f9805b64840.tar.xz | |
cmd/trace/v2: add support for pprof endpoints
This change adds support for the pprof endpoints to cmd/trace/v2.
In the process, I realized we need to pass the goroutine summaries to
more places, and previous CLs had already done the goroutine analysis
during cmd/trace startup. This change thus refactors the goroutine
analysis API once again to operate in a streaming manner, and to run
at the same time as the initial trace parsing. Now we can include it in
the parsedTrace type and pass that around as the de-facto global trace
context.
Note: for simplicity, this change redefines "syscall" profiles to
capture *all* syscalls, not just syscalls that block. IIUC, this choice
was partly the result of a limitation in the previous trace format that
syscalls don't all have complete durations and many short syscalls are
treated as instant. To this end, this change modifies the text on the
main trace webpage to reflect this change.
For #60773.
For #63960.
Change-Id: I601d9250ab0849a0bfaef233fd9b1e81aca9a22a
Reviewed-on: https://go-review.googlesource.com/c/go/+/541999
Auto-Submit: Michael Knyszek <mknyszek@google.com>
Reviewed-by: Michael Pratt <mpratt@google.com>
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
Diffstat (limited to 'src/internal/trace')
| -rw-r--r-- | src/internal/trace/goroutinesv2.go | 98 | ||||
| -rw-r--r-- | src/internal/trace/goroutinesv2_test.go | 18 | ||||
| -rw-r--r-- | src/internal/trace/traceviewer/http.go | 2 |
3 files changed, 57 insertions, 61 deletions
diff --git a/src/internal/trace/goroutinesv2.go b/src/internal/trace/goroutinesv2.go index 7ed5771cd3..c5e5fadc0b 100644 --- a/src/internal/trace/goroutinesv2.go +++ b/src/internal/trace/goroutinesv2.go @@ -209,26 +209,8 @@ type goroutineSummary struct { activeRegions []*UserRegionSummary // stack of active regions } -// SummarizeGoroutines generates statistics for all goroutines in the trace. -func SummarizeGoroutines(events []tracev2.Event) map[tracev2.GoID]*GoroutineSummary { - // Create the analysis state. - b := goroutineStatsBuilder{ - gs: make(map[tracev2.GoID]*GoroutineSummary), - syscallingP: make(map[tracev2.ProcID]tracev2.GoID), - syscallingG: make(map[tracev2.GoID]tracev2.ProcID), - rangesP: make(map[rangeP]tracev2.GoID), - } - - // Process the trace. - for i := range events { - ev := &events[i] - b.event(ev) - } - return b.finalize() -} - -// goroutineStatsBuilder constructs per-goroutine time statistics for v2 traces. -type goroutineStatsBuilder struct { +// GoroutineSummarizer constructs per-goroutine time statistics for v2 traces. +type GoroutineSummarizer struct { // gs contains the map of goroutine summaries we're building up to return to the caller. gs map[tracev2.GoID]*GoroutineSummary @@ -247,22 +229,32 @@ type goroutineStatsBuilder struct { syncTs tracev2.Time // timestamp of the last sync event processed (or the first timestamp in the trace). } +// NewGoroutineSummarizer creates a new struct to build goroutine stats from a trace. +func NewGoroutineSummarizer() *GoroutineSummarizer { + return &GoroutineSummarizer{ + gs: make(map[tracev2.GoID]*GoroutineSummary), + syscallingP: make(map[tracev2.ProcID]tracev2.GoID), + syscallingG: make(map[tracev2.GoID]tracev2.ProcID), + rangesP: make(map[rangeP]tracev2.GoID), + } +} + type rangeP struct { id tracev2.ProcID name string } -// event feeds a single event into the stats builder. -func (b *goroutineStatsBuilder) event(ev *tracev2.Event) { - if b.syncTs == 0 { - b.syncTs = ev.Time() +// Event feeds a single event into the stats summarizer. +func (s *GoroutineSummarizer) Event(ev *tracev2.Event) { + if s.syncTs == 0 { + s.syncTs = ev.Time() } - b.lastTs = ev.Time() + s.lastTs = ev.Time() switch ev.Kind() { // Record sync time for the RangeActive events. case tracev2.EventSync: - b.syncTs = ev.Time() + s.syncTs = ev.Time() // Handle state transitions. case tracev2.EventStateTransition: @@ -278,14 +270,14 @@ func (b *goroutineStatsBuilder) event(ev *tracev2.Event) { } // Handle transition out. - g := b.gs[id] + g := s.gs[id] switch old { case tracev2.GoUndetermined, tracev2.GoNotExist: g = &GoroutineSummary{ID: id, goroutineSummary: &goroutineSummary{}} // If we're coming out of GoUndetermined, then the creation time is the // time of the last sync. if old == tracev2.GoUndetermined { - g.CreationTime = b.syncTs + g.CreationTime = s.syncTs } else { g.CreationTime = ev.Time() } @@ -304,14 +296,14 @@ func (b *goroutineStatsBuilder) event(ev *tracev2.Event) { // // N.B. ev.Goroutine() will always be NoGoroutine for the // Undetermined case, so this is will simply not fire. - if creatorG := b.gs[ev.Goroutine()]; creatorG != nil && len(creatorG.activeRegions) > 0 { + if creatorG := s.gs[ev.Goroutine()]; creatorG != nil && len(creatorG.activeRegions) > 0 { regions := creatorG.activeRegions s := regions[len(regions)-1] if s.TaskID != tracev2.NoTask { g.activeRegions = []*UserRegionSummary{{TaskID: s.TaskID, Start: ev}} } } - b.gs[g.ID] = g + s.gs[g.ID] = g case tracev2.GoRunning: // Record execution time as we transition out of running g.ExecTime += ev.Time().Sub(g.lastStartTime) @@ -341,8 +333,8 @@ func (b *goroutineStatsBuilder) event(ev *tracev2.Event) { g.lastSyscallBlockTime = 0 // Clear the syscall map. - delete(b.syscallingP, b.syscallingG[id]) - delete(b.syscallingG, id) + delete(s.syscallingP, s.syscallingG[id]) + delete(s.syscallingG, id) } } @@ -388,8 +380,8 @@ func (b *goroutineStatsBuilder) event(ev *tracev2.Event) { case tracev2.GoNotExist: g.finalize(ev.Time(), ev) case tracev2.GoSyscall: - b.syscallingP[ev.Proc()] = id - b.syscallingG[id] = ev.Proc() + s.syscallingP[ev.Proc()] = id + s.syscallingG[id] = ev.Proc() g.lastSyscallTime = ev.Time() } @@ -399,10 +391,10 @@ func (b *goroutineStatsBuilder) event(ev *tracev2.Event) { id := st.Resource.Proc() old, new := st.Proc() if old != new && new == tracev2.ProcIdle { - if goid, ok := b.syscallingP[id]; ok { - g := b.gs[goid] + if goid, ok := s.syscallingP[id]; ok { + g := s.gs[goid] g.lastSyscallBlockTime = ev.Time() - delete(b.syscallingP, id) + delete(s.syscallingP, id) } } } @@ -418,14 +410,14 @@ func (b *goroutineStatsBuilder) event(ev *tracev2.Event) { // goroutine blocked often in mark assist will have both high mark assist // and high block times. Those interested in a deeper view can look at the // trace viewer. - g = b.gs[r.Scope.Goroutine()] + g = s.gs[r.Scope.Goroutine()] case tracev2.ResourceProc: // N.B. These ranges are not actually bound to the goroutine, they're // bound to the P. But if we happen to be on the P the whole time, let's // try to attribute it to the goroutine. (e.g. GC sweeps are here.) - g = b.gs[ev.Goroutine()] + g = s.gs[ev.Goroutine()] if g != nil { - b.rangesP[rangeP{id: r.Scope.Proc(), name: r.Name}] = ev.Goroutine() + s.rangesP[rangeP{id: r.Scope.Proc(), name: r.Name}] = ev.Goroutine() } } if g == nil { @@ -433,9 +425,9 @@ func (b *goroutineStatsBuilder) event(ev *tracev2.Event) { } if ev.Kind() == tracev2.EventRangeActive { if ts := g.lastRangeTime[r.Name]; ts != 0 { - g.RangeTime[r.Name] += b.syncTs.Sub(ts) + g.RangeTime[r.Name] += s.syncTs.Sub(ts) } - g.lastRangeTime[r.Name] = b.syncTs + g.lastRangeTime[r.Name] = s.syncTs } else { g.lastRangeTime[r.Name] = ev.Time() } @@ -444,16 +436,16 @@ func (b *goroutineStatsBuilder) event(ev *tracev2.Event) { var g *GoroutineSummary switch r.Scope.Kind { case tracev2.ResourceGoroutine: - g = b.gs[r.Scope.Goroutine()] + g = s.gs[r.Scope.Goroutine()] case tracev2.ResourceProc: rp := rangeP{id: r.Scope.Proc(), name: r.Name} - if goid, ok := b.rangesP[rp]; ok { + if goid, ok := s.rangesP[rp]; ok { if goid == ev.Goroutine() { // As the comment in the RangeBegin case states, this is only OK // if we finish on the same goroutine we started on. - g = b.gs[goid] + g = s.gs[goid] } - delete(b.rangesP, rp) + delete(s.rangesP, rp) } } if g == nil { @@ -468,7 +460,7 @@ func (b *goroutineStatsBuilder) event(ev *tracev2.Event) { // Handle user-defined regions. case tracev2.EventRegionBegin: - g := b.gs[ev.Goroutine()] + g := s.gs[ev.Goroutine()] r := ev.Region() g.activeRegions = append(g.activeRegions, &UserRegionSummary{ Name: r.Type, @@ -477,7 +469,7 @@ func (b *goroutineStatsBuilder) event(ev *tracev2.Event) { GoroutineExecStats: g.snapshotStat(ev.Time()), }) case tracev2.EventRegionEnd: - g := b.gs[ev.Goroutine()] + g := s.gs[ev.Goroutine()] r := ev.Region() var sd *UserRegionSummary if regionStk := g.activeRegions; len(regionStk) > 0 { @@ -496,11 +488,11 @@ func (b *goroutineStatsBuilder) event(ev *tracev2.Event) { } } -// finalize indicates to the builder that we're done processing the trace. +// Finalize indicates to the summarizer that we're done processing the trace. // It cleans up any remaining state and returns the full summary. -func (b *goroutineStatsBuilder) finalize() map[tracev2.GoID]*GoroutineSummary { - for _, g := range b.gs { - g.finalize(b.lastTs, nil) +func (s *GoroutineSummarizer) Finalize() map[tracev2.GoID]*GoroutineSummary { + for _, g := range s.gs { + g.finalize(s.lastTs, nil) // Sort based on region start time. sort.Slice(g.Regions, func(i, j int) bool { @@ -516,7 +508,7 @@ func (b *goroutineStatsBuilder) finalize() map[tracev2.GoID]*GoroutineSummary { }) g.goroutineSummary = nil } - return b.gs + return s.gs } // RelatedGoroutinesV2 finds a set of goroutines related to goroutine goid for v2 traces. diff --git a/src/internal/trace/goroutinesv2_test.go b/src/internal/trace/goroutinesv2_test.go index ecd7f2631d..ea689aca65 100644 --- a/src/internal/trace/goroutinesv2_test.go +++ b/src/internal/trace/goroutinesv2_test.go @@ -92,26 +92,30 @@ func basicSummaryChecks(t *testing.T, summary *GoroutineSummary) { } func summarizeTraceTest(t *testing.T, testPath string) map[tracev2.GoID]*GoroutineSummary { - r, _, err := testtrace.ParseFile(testPath) + trace, _, err := testtrace.ParseFile(testPath) if err != nil { t.Fatalf("malformed test %s: bad trace file: %v", testPath, err) } - var events []tracev2.Event - tr, err := tracev2.NewReader(r) + // Create the analysis state. + s := NewGoroutineSummarizer() + + // Create a reader. + r, err := tracev2.NewReader(trace) if err != nil { - t.Fatalf("failed to create trace reader %s: %v", testPath, err) + t.Fatalf("failed to create trace reader for %s: %v", testPath, err) } + // Process the trace. for { - ev, err := tr.ReadEvent() + ev, err := r.ReadEvent() if err == io.EOF { break } if err != nil { t.Fatalf("failed to process trace %s: %v", testPath, err) } - events = append(events, ev) + s.Event(&ev) } - return SummarizeGoroutines(events) + return s.Finalize() } func checkRegionEvents(t *testing.T, wantStart, wantEnd tracev2.EventKind, goid tracev2.GoID, region *UserRegionSummary) { diff --git a/src/internal/trace/traceviewer/http.go b/src/internal/trace/traceviewer/http.go index ac2803be2d..b279b62a23 100644 --- a/src/internal/trace/traceviewer/http.go +++ b/src/internal/trace/traceviewer/http.go @@ -185,7 +185,7 @@ var templMain = template.Must(template.New("").Parse(` <ul> <li><a href="/io">Network blocking profile</a> (<a href="/io?raw=1" download="io.profile">⬇</a>)</li> <li><a href="/block">Synchronization blocking profile</a> (<a href="/block?raw=1" download="block.profile">⬇</a>)</li> -<li><a href="/syscall">Syscall blocking profile</a> (<a href="/syscall?raw=1" download="syscall.profile">⬇</a>)</li> +<li><a href="/syscall">Syscall profile</a> (<a href="/syscall?raw=1" download="syscall.profile">⬇</a>)</li> <li><a href="/sched">Scheduler latency profile</a> (<a href="/sched?raw=1" download="sched.profile">⬇</a>)</li> </ul> |
