blob: 4b4f13d2aeb712f632fbc6b368fb284c4d813196 [file] [log] [blame]
// Copyright 2014 The Go Authors. All rights reserved.
// Use of this source code is governed by a BSD-style
// license that can be found in the LICENSE file.
package trace
import (
"sort"
"strings"
)
// GDesc contains statistics and execution details of a single goroutine.
type GDesc struct {
ID uint64
Name string
PC uint64
CreationTime int64
StartTime int64
EndTime int64
// List of regions in the goroutine, sorted based on the start time.
Regions []*UserRegionDesc
// Statistics of execution time during the goroutine execution.
GExecutionStat
*gdesc // private part.
}
// UserRegionDesc represents a region and goroutine execution stats
// while the region was active.
type UserRegionDesc struct {
TaskID uint64
Name string
// Region start event. Normally EvUserRegion start event or nil,
// but can be EvGoCreate event if the region is a synthetic
// region representing task inheritance from the parent goroutine.
Start *Event
// Region end event. Normally EvUserRegion end event or nil,
// but can be EvGoStop or EvGoEnd event if the goroutine
// terminated without explicitly ending the region.
End *Event
GExecutionStat
}
// GExecutionStat contains statistics about a goroutine's execution
// during a period of time.
type GExecutionStat struct {
ExecTime int64
SchedWaitTime int64
IOTime int64
BlockTime int64
SyscallTime int64
GCTime int64
SweepTime int64
TotalTime int64
}
// sub returns the stats v-s.
func (s GExecutionStat) sub(v GExecutionStat) (r GExecutionStat) {
r = s
r.ExecTime -= v.ExecTime
r.SchedWaitTime -= v.SchedWaitTime
r.IOTime -= v.IOTime
r.BlockTime -= v.BlockTime
r.SyscallTime -= v.SyscallTime
r.GCTime -= v.GCTime
r.SweepTime -= v.SweepTime
r.TotalTime -= v.TotalTime
return r
}
// snapshotStat returns the snapshot of the goroutine execution statistics.
// This is called as we process the ordered trace event stream. lastTs and
// activeGCStartTime are used to process pending statistics if this is called
// before any goroutine end event.
func (g *GDesc) snapshotStat(lastTs, activeGCStartTime int64) (ret GExecutionStat) {
ret = g.GExecutionStat
if g.gdesc == nil {
return ret // finalized GDesc. No pending state.
}
if activeGCStartTime != 0 { // terminating while GC is active
if g.CreationTime < activeGCStartTime {
ret.GCTime += lastTs - activeGCStartTime
} else {
// The goroutine's lifetime completely overlaps
// with a GC.
ret.GCTime += lastTs - g.CreationTime
}
}
if g.TotalTime == 0 {
ret.TotalTime = lastTs - g.CreationTime
}
if g.lastStartTime != 0 {
ret.ExecTime += lastTs - g.lastStartTime
}
if g.blockNetTime != 0 {
ret.IOTime += lastTs - g.blockNetTime
}
if g.blockSyncTime != 0 {
ret.BlockTime += lastTs - g.blockSyncTime
}
if g.blockSyscallTime != 0 {
ret.SyscallTime += lastTs - g.blockSyscallTime
}
if g.blockSchedTime != 0 {
ret.SchedWaitTime += lastTs - g.blockSchedTime
}
if g.blockSweepTime != 0 {
ret.SweepTime += lastTs - g.blockSweepTime
}
return ret
}
// finalize is called when processing a goroutine end event or at
// the end of trace processing. This finalizes the execution stat
// and any active regions in the goroutine, in which case trigger is nil.
func (g *GDesc) finalize(lastTs, activeGCStartTime int64, trigger *Event) {
if trigger != nil {
g.EndTime = trigger.Ts
}
finalStat := g.snapshotStat(lastTs, activeGCStartTime)
g.GExecutionStat = finalStat
// System goroutines are never part of regions, even though they
// "inherit" a task due to creation (EvGoCreate) from within a region.
// This may happen e.g. if the first GC is triggered within a region,
// starting the GC worker goroutines.
if !IsSystemGoroutine(g.Name) {
for _, s := range g.activeRegions {
s.End = trigger
s.GExecutionStat = finalStat.sub(s.GExecutionStat)
g.Regions = append(g.Regions, s)
}
}
*(g.gdesc) = gdesc{}
}
// gdesc is a private part of GDesc that is required only during analysis.
type gdesc struct {
lastStartTime int64
blockNetTime int64
blockSyncTime int64
blockSyscallTime int64
blockSweepTime int64
blockGCTime int64
blockSchedTime int64
activeRegions []*UserRegionDesc // stack of active regions
}
// GoroutineStats generates statistics for all goroutines in the trace.
func GoroutineStats(events []*Event) map[uint64]*GDesc {
gs := make(map[uint64]*GDesc)
var lastTs int64
var gcStartTime int64 // gcStartTime == 0 indicates gc is inactive.
for _, ev := range events {
lastTs = ev.Ts
switch ev.Type {
case EvGoCreate:
g := &GDesc{ID: ev.Args[0], CreationTime: ev.Ts, gdesc: new(gdesc)}
g.blockSchedTime = ev.Ts
// When a goroutine is newly created, inherit the task
// of the active region. For ease handling of this
// case, we create a fake region description with the
// task id. This isn't strictly necessary as this
// goroutine may not be associated with the task, but
// it can be convenient to see all children created
// during a region.
if creatorG := gs[ev.G]; creatorG != nil && len(creatorG.gdesc.activeRegions) > 0 {
regions := creatorG.gdesc.activeRegions
s := regions[len(regions)-1]
if s.TaskID != 0 {
g.gdesc.activeRegions = []*UserRegionDesc{
{TaskID: s.TaskID, Start: ev},
}
}
}
gs[g.ID] = g
case EvGoStart, EvGoStartLabel:
g := gs[ev.G]
if g.PC == 0 && len(ev.Stk) > 0 {
g.PC = ev.Stk[0].PC
g.Name = ev.Stk[0].Fn
}
g.lastStartTime = ev.Ts
if g.StartTime == 0 {
g.StartTime = ev.Ts
}
if g.blockSchedTime != 0 {
g.SchedWaitTime += ev.Ts - g.blockSchedTime
g.blockSchedTime = 0
}
case EvGoEnd, EvGoStop:
g := gs[ev.G]
g.finalize(ev.Ts, gcStartTime, ev)
case EvGoBlockSend, EvGoBlockRecv, EvGoBlockSelect,
EvGoBlockSync, EvGoBlockCond:
g := gs[ev.G]
g.ExecTime += ev.Ts - g.lastStartTime
g.lastStartTime = 0
g.blockSyncTime = ev.Ts
case EvGoSched, EvGoPreempt:
g := gs[ev.G]
g.ExecTime += ev.Ts - g.lastStartTime
g.lastStartTime = 0
g.blockSchedTime = ev.Ts
case EvGoSleep, EvGoBlock:
g := gs[ev.G]
g.ExecTime += ev.Ts - g.lastStartTime
g.lastStartTime = 0
case EvGoBlockNet:
g := gs[ev.G]
g.ExecTime += ev.Ts - g.lastStartTime
g.lastStartTime = 0
g.blockNetTime = ev.Ts
case EvGoBlockGC:
g := gs[ev.G]
g.ExecTime += ev.Ts - g.lastStartTime
g.lastStartTime = 0
g.blockGCTime = ev.Ts
case EvGoUnblock:
g := gs[ev.Args[0]]
if g.blockNetTime != 0 {
g.IOTime += ev.Ts - g.blockNetTime
g.blockNetTime = 0
}
if g.blockSyncTime != 0 {
g.BlockTime += ev.Ts - g.blockSyncTime
g.blockSyncTime = 0
}
g.blockSchedTime = ev.Ts
case EvGoSysBlock:
g := gs[ev.G]
g.ExecTime += ev.Ts - g.lastStartTime
g.lastStartTime = 0
g.blockSyscallTime = ev.Ts
case EvGoSysExit:
g := gs[ev.G]
if g.blockSyscallTime != 0 {
g.SyscallTime += ev.Ts - g.blockSyscallTime
g.blockSyscallTime = 0
}
g.blockSchedTime = ev.Ts
case EvGCSweepStart:
g := gs[ev.G]
if g != nil {
// Sweep can happen during GC on system goroutine.
g.blockSweepTime = ev.Ts
}
case EvGCSweepDone:
g := gs[ev.G]
if g != nil && g.blockSweepTime != 0 {
g.SweepTime += ev.Ts - g.blockSweepTime
g.blockSweepTime = 0
}
case EvGCStart:
gcStartTime = ev.Ts
case EvGCDone:
for _, g := range gs {
if g.EndTime != 0 {
continue
}
if gcStartTime < g.CreationTime {
g.GCTime += ev.Ts - g.CreationTime
} else {
g.GCTime += ev.Ts - gcStartTime
}
}
gcStartTime = 0 // indicates gc is inactive.
case EvUserRegion:
g := gs[ev.G]
switch mode := ev.Args[1]; mode {
case 0: // region start
g.activeRegions = append(g.activeRegions, &UserRegionDesc{
Name: ev.SArgs[0],
TaskID: ev.Args[0],
Start: ev,
GExecutionStat: g.snapshotStat(lastTs, gcStartTime),
})
case 1: // region end
var sd *UserRegionDesc
if regionStk := g.activeRegions; len(regionStk) > 0 {
n := len(regionStk)
sd = regionStk[n-1]
regionStk = regionStk[:n-1] // pop
g.activeRegions = regionStk
} else {
sd = &UserRegionDesc{
Name: ev.SArgs[0],
TaskID: ev.Args[0],
}
}
sd.GExecutionStat = g.snapshotStat(lastTs, gcStartTime).sub(sd.GExecutionStat)
sd.End = ev
g.Regions = append(g.Regions, sd)
}
}
}
for _, g := range gs {
g.finalize(lastTs, gcStartTime, nil)
// sort based on region start time
sort.Slice(g.Regions, func(i, j int) bool {
x := g.Regions[i].Start
y := g.Regions[j].Start
if x == nil {
return true
}
if y == nil {
return false
}
return x.Ts < y.Ts
})
g.gdesc = nil
}
return gs
}
// RelatedGoroutines finds a set of goroutines related to goroutine goid.
func RelatedGoroutines(events []*Event, goid uint64) map[uint64]bool {
// BFS of depth 2 over "unblock" edges
// (what goroutines unblock goroutine goid?).
gmap := make(map[uint64]bool)
gmap[goid] = true
for i := 0; i < 2; i++ {
gmap1 := make(map[uint64]bool)
for g := range gmap {
gmap1[g] = true
}
for _, ev := range events {
if ev.Type == EvGoUnblock && gmap[ev.Args[0]] {
gmap1[ev.G] = true
}
}
gmap = gmap1
}
gmap[0] = true // for GC events
return gmap
}
func IsSystemGoroutine(entryFn string) bool {
// This mimics runtime.isSystemGoroutine as closely as
// possible.
// Also, locked g in extra M (with empty entryFn) is system goroutine.
return entryFn == "" || entryFn != "runtime.main" && strings.HasPrefix(entryFn, "runtime.")
}