Source file src/pkg/internal/trace/goroutines.go

     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	package trace
     6	
     7	import "sort"
     8	
     9	// GDesc contains statistics and execution details of a single goroutine.
    10	type GDesc struct {
    11		ID           uint64
    12		Name         string
    13		PC           uint64
    14		CreationTime int64
    15		StartTime    int64
    16		EndTime      int64
    17	
    18		// List of regions in the goroutine, sorted based on the start time.
    19		Regions []*UserRegionDesc
    20	
    21		// Statistics of execution time during the goroutine execution.
    22		GExecutionStat
    23	
    24		*gdesc // private part.
    25	}
    26	
    27	// UserRegionDesc represents a region and goroutine execution stats
    28	// while the region was active.
    29	type UserRegionDesc struct {
    30		TaskID uint64
    31		Name   string
    32	
    33		// Region start event. Normally EvUserRegion start event or nil,
    34		// but can be EvGoCreate event if the region is a synthetic
    35		// region representing task inheritance from the parent goroutine.
    36		Start *Event
    37	
    38		// Region end event. Normally EvUserRegion end event or nil,
    39		// but can be EvGoStop or EvGoEnd event if the goroutine
    40		// terminated without explicitly ending the region.
    41		End *Event
    42	
    43		GExecutionStat
    44	}
    45	
    46	// GExecutionStat contains statistics about a goroutine's execution
    47	// during a period of time.
    48	type GExecutionStat struct {
    49		ExecTime      int64
    50		SchedWaitTime int64
    51		IOTime        int64
    52		BlockTime     int64
    53		SyscallTime   int64
    54		GCTime        int64
    55		SweepTime     int64
    56		TotalTime     int64
    57	}
    58	
    59	// sub returns the stats v-s.
    60	func (s GExecutionStat) sub(v GExecutionStat) (r GExecutionStat) {
    61		r = s
    62		r.ExecTime -= v.ExecTime
    63		r.SchedWaitTime -= v.SchedWaitTime
    64		r.IOTime -= v.IOTime
    65		r.BlockTime -= v.BlockTime
    66		r.SyscallTime -= v.SyscallTime
    67		r.GCTime -= v.GCTime
    68		r.SweepTime -= v.SweepTime
    69		r.TotalTime -= v.TotalTime
    70		return r
    71	}
    72	
    73	// snapshotStat returns the snapshot of the goroutine execution statistics.
    74	// This is called as we process the ordered trace event stream. lastTs and
    75	// activeGCStartTime are used to process pending statistics if this is called
    76	// before any goroutine end event.
    77	func (g *GDesc) snapshotStat(lastTs, activeGCStartTime int64) (ret GExecutionStat) {
    78		ret = g.GExecutionStat
    79	
    80		if g.gdesc == nil {
    81			return ret // finalized GDesc. No pending state.
    82		}
    83	
    84		if activeGCStartTime != 0 { // terminating while GC is active
    85			if g.CreationTime < activeGCStartTime {
    86				ret.GCTime += lastTs - activeGCStartTime
    87			} else {
    88				// The goroutine's lifetime completely overlaps
    89				// with a GC.
    90				ret.GCTime += lastTs - g.CreationTime
    91			}
    92		}
    93	
    94		if g.TotalTime == 0 {
    95			ret.TotalTime = lastTs - g.CreationTime
    96		}
    97	
    98		if g.lastStartTime != 0 {
    99			ret.ExecTime += lastTs - g.lastStartTime
   100		}
   101		if g.blockNetTime != 0 {
   102			ret.IOTime += lastTs - g.blockNetTime
   103		}
   104		if g.blockSyncTime != 0 {
   105			ret.BlockTime += lastTs - g.blockSyncTime
   106		}
   107		if g.blockSyscallTime != 0 {
   108			ret.SyscallTime += lastTs - g.blockSyscallTime
   109		}
   110		if g.blockSchedTime != 0 {
   111			ret.SchedWaitTime += lastTs - g.blockSchedTime
   112		}
   113		if g.blockSweepTime != 0 {
   114			ret.SweepTime += lastTs - g.blockSweepTime
   115		}
   116		return ret
   117	}
   118	
   119	// finalize is called when processing a goroutine end event or at
   120	// the end of trace processing. This finalizes the execution stat
   121	// and any active regions in the goroutine, in which case trigger is nil.
   122	func (g *GDesc) finalize(lastTs, activeGCStartTime int64, trigger *Event) {
   123		if trigger != nil {
   124			g.EndTime = trigger.Ts
   125		}
   126		finalStat := g.snapshotStat(lastTs, activeGCStartTime)
   127	
   128		g.GExecutionStat = finalStat
   129		for _, s := range g.activeRegions {
   130			s.End = trigger
   131			s.GExecutionStat = finalStat.sub(s.GExecutionStat)
   132			g.Regions = append(g.Regions, s)
   133		}
   134		*(g.gdesc) = gdesc{}
   135	}
   136	
   137	// gdesc is a private part of GDesc that is required only during analysis.
   138	type gdesc struct {
   139		lastStartTime    int64
   140		blockNetTime     int64
   141		blockSyncTime    int64
   142		blockSyscallTime int64
   143		blockSweepTime   int64
   144		blockGCTime      int64
   145		blockSchedTime   int64
   146	
   147		activeRegions []*UserRegionDesc // stack of active regions
   148	}
   149	
   150	// GoroutineStats generates statistics for all goroutines in the trace.
   151	func GoroutineStats(events []*Event) map[uint64]*GDesc {
   152		gs := make(map[uint64]*GDesc)
   153		var lastTs int64
   154		var gcStartTime int64 // gcStartTime == 0 indicates gc is inactive.
   155		for _, ev := range events {
   156			lastTs = ev.Ts
   157			switch ev.Type {
   158			case EvGoCreate:
   159				g := &GDesc{ID: ev.Args[0], CreationTime: ev.Ts, gdesc: new(gdesc)}
   160				g.blockSchedTime = ev.Ts
   161				// When a goroutine is newly created, inherit the
   162				// task of the active region. For ease handling of
   163				// this case, we create a fake region description with
   164				// the task id.
   165				if creatorG := gs[ev.G]; creatorG != nil && len(creatorG.gdesc.activeRegions) > 0 {
   166					regions := creatorG.gdesc.activeRegions
   167					s := regions[len(regions)-1]
   168					if s.TaskID != 0 {
   169						g.gdesc.activeRegions = []*UserRegionDesc{
   170							{TaskID: s.TaskID, Start: ev},
   171						}
   172					}
   173				}
   174				gs[g.ID] = g
   175			case EvGoStart, EvGoStartLabel:
   176				g := gs[ev.G]
   177				if g.PC == 0 {
   178					g.PC = ev.Stk[0].PC
   179					g.Name = ev.Stk[0].Fn
   180				}
   181				g.lastStartTime = ev.Ts
   182				if g.StartTime == 0 {
   183					g.StartTime = ev.Ts
   184				}
   185				if g.blockSchedTime != 0 {
   186					g.SchedWaitTime += ev.Ts - g.blockSchedTime
   187					g.blockSchedTime = 0
   188				}
   189			case EvGoEnd, EvGoStop:
   190				g := gs[ev.G]
   191				g.finalize(ev.Ts, gcStartTime, ev)
   192			case EvGoBlockSend, EvGoBlockRecv, EvGoBlockSelect,
   193				EvGoBlockSync, EvGoBlockCond:
   194				g := gs[ev.G]
   195				g.ExecTime += ev.Ts - g.lastStartTime
   196				g.lastStartTime = 0
   197				g.blockSyncTime = ev.Ts
   198			case EvGoSched, EvGoPreempt:
   199				g := gs[ev.G]
   200				g.ExecTime += ev.Ts - g.lastStartTime
   201				g.lastStartTime = 0
   202				g.blockSchedTime = ev.Ts
   203			case EvGoSleep, EvGoBlock:
   204				g := gs[ev.G]
   205				g.ExecTime += ev.Ts - g.lastStartTime
   206				g.lastStartTime = 0
   207			case EvGoBlockNet:
   208				g := gs[ev.G]
   209				g.ExecTime += ev.Ts - g.lastStartTime
   210				g.lastStartTime = 0
   211				g.blockNetTime = ev.Ts
   212			case EvGoBlockGC:
   213				g := gs[ev.G]
   214				g.ExecTime += ev.Ts - g.lastStartTime
   215				g.lastStartTime = 0
   216				g.blockGCTime = ev.Ts
   217			case EvGoUnblock:
   218				g := gs[ev.Args[0]]
   219				if g.blockNetTime != 0 {
   220					g.IOTime += ev.Ts - g.blockNetTime
   221					g.blockNetTime = 0
   222				}
   223				if g.blockSyncTime != 0 {
   224					g.BlockTime += ev.Ts - g.blockSyncTime
   225					g.blockSyncTime = 0
   226				}
   227				g.blockSchedTime = ev.Ts
   228			case EvGoSysBlock:
   229				g := gs[ev.G]
   230				g.ExecTime += ev.Ts - g.lastStartTime
   231				g.lastStartTime = 0
   232				g.blockSyscallTime = ev.Ts
   233			case EvGoSysExit:
   234				g := gs[ev.G]
   235				if g.blockSyscallTime != 0 {
   236					g.SyscallTime += ev.Ts - g.blockSyscallTime
   237					g.blockSyscallTime = 0
   238				}
   239				g.blockSchedTime = ev.Ts
   240			case EvGCSweepStart:
   241				g := gs[ev.G]
   242				if g != nil {
   243					// Sweep can happen during GC on system goroutine.
   244					g.blockSweepTime = ev.Ts
   245				}
   246			case EvGCSweepDone:
   247				g := gs[ev.G]
   248				if g != nil && g.blockSweepTime != 0 {
   249					g.SweepTime += ev.Ts - g.blockSweepTime
   250					g.blockSweepTime = 0
   251				}
   252			case EvGCStart:
   253				gcStartTime = ev.Ts
   254			case EvGCDone:
   255				for _, g := range gs {
   256					if g.EndTime != 0 {
   257						continue
   258					}
   259					if gcStartTime < g.CreationTime {
   260						g.GCTime += ev.Ts - g.CreationTime
   261					} else {
   262						g.GCTime += ev.Ts - gcStartTime
   263					}
   264				}
   265				gcStartTime = 0 // indicates gc is inactive.
   266			case EvUserRegion:
   267				g := gs[ev.G]
   268				switch mode := ev.Args[1]; mode {
   269				case 0: // region start
   270					g.activeRegions = append(g.activeRegions, &UserRegionDesc{
   271						Name:           ev.SArgs[0],
   272						TaskID:         ev.Args[0],
   273						Start:          ev,
   274						GExecutionStat: g.snapshotStat(lastTs, gcStartTime),
   275					})
   276				case 1: // region end
   277					var sd *UserRegionDesc
   278					if regionStk := g.activeRegions; len(regionStk) > 0 {
   279						n := len(regionStk)
   280						sd = regionStk[n-1]
   281						regionStk = regionStk[:n-1] // pop
   282						g.activeRegions = regionStk
   283					} else {
   284						sd = &UserRegionDesc{
   285							Name:   ev.SArgs[0],
   286							TaskID: ev.Args[0],
   287						}
   288					}
   289					sd.GExecutionStat = g.snapshotStat(lastTs, gcStartTime).sub(sd.GExecutionStat)
   290					sd.End = ev
   291					g.Regions = append(g.Regions, sd)
   292				}
   293			}
   294		}
   295	
   296		for _, g := range gs {
   297			g.finalize(lastTs, gcStartTime, nil)
   298	
   299			// sort based on region start time
   300			sort.Slice(g.Regions, func(i, j int) bool {
   301				x := g.Regions[i].Start
   302				y := g.Regions[j].Start
   303				if x == nil {
   304					return true
   305				}
   306				if y == nil {
   307					return false
   308				}
   309				return x.Ts < y.Ts
   310			})
   311	
   312			g.gdesc = nil
   313		}
   314	
   315		return gs
   316	}
   317	
   318	// RelatedGoroutines finds a set of goroutines related to goroutine goid.
   319	func RelatedGoroutines(events []*Event, goid uint64) map[uint64]bool {
   320		// BFS of depth 2 over "unblock" edges
   321		// (what goroutines unblock goroutine goid?).
   322		gmap := make(map[uint64]bool)
   323		gmap[goid] = true
   324		for i := 0; i < 2; i++ {
   325			gmap1 := make(map[uint64]bool)
   326			for g := range gmap {
   327				gmap1[g] = true
   328			}
   329			for _, ev := range events {
   330				if ev.Type == EvGoUnblock && gmap[ev.Args[0]] {
   331					gmap1[ev.G] = true
   332				}
   333			}
   334			gmap = gmap1
   335		}
   336		gmap[0] = true // for GC events
   337		return gmap
   338	}
   339	

View as plain text