github.com/sandwichdev/go-internals@v0.0.0-20210605002614-12311ac6b2c5/trace/goroutines.go (about) 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 }