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
5package trace
6
7import "sort"
8
9// GDesc contains statistics and execution details of a single goroutine.
10type 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.
29type 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.
48type 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.
60func (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.
77func (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.
122func (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.
138type 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.
151func 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.
319func 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