github.com/go-asm/go@v1.21.1-0.20240213172139-40c5ead50c48/cmd/trace/v2/gstate.go (about) 1 // Copyright 2023 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 ( 8 "fmt" 9 "strings" 10 11 "github.com/go-asm/go/trace" 12 "github.com/go-asm/go/trace/traceviewer" 13 "github.com/go-asm/go/trace/traceviewer/format" 14 tracev2 "github.com/go-asm/go/trace/v2" 15 ) 16 17 // resource is a generic constraint interface for resource IDs. 18 type resource interface { 19 tracev2.GoID | tracev2.ProcID | tracev2.ThreadID 20 } 21 22 // noResource indicates the lack of a resource. 23 const noResource = -1 24 25 // gState represents the trace viewer state of a goroutine in a trace. 26 // 27 // The type parameter on this type is the resource which is used to construct 28 // a timeline of events. e.g. R=ProcID for a proc-oriented view, R=GoID for 29 // a goroutine-oriented view, etc. 30 type gState[R resource] struct { 31 baseName string 32 named bool // Whether baseName has been set. 33 label string // EventLabel extension. 34 isSystemG bool 35 36 executing R // The resource this goroutine is executing on. (Could be itself.) 37 38 // lastStopStack is the stack trace at the point of the last 39 // call to the stop method. This tends to be a more reliable way 40 // of picking up stack traces, since the parser doesn't provide 41 // a stack for every state transition event. 42 lastStopStack tracev2.Stack 43 44 // activeRanges is the set of all active ranges on the goroutine. 45 activeRanges map[string]activeRange 46 47 // completedRanges is a list of ranges that completed since before the 48 // goroutine stopped executing. These are flushed on every stop or block. 49 completedRanges []completedRange 50 51 // startRunning is the most recent event that caused a goroutine to 52 // transition to GoRunning. 53 startRunningTime tracev2.Time 54 55 // startSyscall is the most recent event that caused a goroutine to 56 // transition to GoSyscall. 57 syscall struct { 58 time tracev2.Time 59 stack tracev2.Stack 60 active bool 61 } 62 63 // startBlockReason is the StateTransition.Reason of the most recent 64 // event that caused a gorotuine to transition to GoWaiting. 65 startBlockReason string 66 67 // startCause is the event that allowed this goroutine to start running. 68 // It's used to generate flow events. This is typically something like 69 // an unblock event or a goroutine creation event. 70 // 71 // startCause.resource is the resource on which startCause happened, but is 72 // listed separately because the cause may have happened on a resource that 73 // isn't R (or perhaps on some abstract nebulous resource, like trace.NetpollP). 74 startCause struct { 75 time tracev2.Time 76 name string 77 resource uint64 78 stack tracev2.Stack 79 } 80 } 81 82 // newGState constructs a new goroutine state for the goroutine 83 // identified by the provided ID. 84 func newGState[R resource](goID tracev2.GoID) *gState[R] { 85 return &gState[R]{ 86 baseName: fmt.Sprintf("G%d", goID), 87 executing: R(noResource), 88 activeRanges: make(map[string]activeRange), 89 } 90 } 91 92 // augmentName attempts to use stk to augment the name of the goroutine 93 // with stack information. This stack must be related to the goroutine 94 // in some way, but it doesn't really matter which stack. 95 func (gs *gState[R]) augmentName(stk tracev2.Stack) { 96 if gs.named { 97 return 98 } 99 if stk == tracev2.NoStack { 100 return 101 } 102 name := lastFunc(stk) 103 gs.baseName += fmt.Sprintf(" %s", name) 104 gs.named = true 105 gs.isSystemG = trace.IsSystemGoroutine(name) 106 } 107 108 // setLabel adds an additional label to the goroutine's name. 109 func (gs *gState[R]) setLabel(label string) { 110 gs.label = label 111 } 112 113 // name returns a name for the goroutine. 114 func (gs *gState[R]) name() string { 115 name := gs.baseName 116 if gs.label != "" { 117 name += " (" + gs.label + ")" 118 } 119 return name 120 } 121 122 // setStartCause sets the reason a goroutine will be allowed to start soon. 123 // For example, via unblocking or exiting a blocked syscall. 124 func (gs *gState[R]) setStartCause(ts tracev2.Time, name string, resource uint64, stack tracev2.Stack) { 125 gs.startCause.time = ts 126 gs.startCause.name = name 127 gs.startCause.resource = resource 128 gs.startCause.stack = stack 129 } 130 131 // created indicates that this goroutine was just created by the provided creator. 132 func (gs *gState[R]) created(ts tracev2.Time, creator R, stack tracev2.Stack) { 133 if creator == R(noResource) { 134 return 135 } 136 gs.setStartCause(ts, "go", uint64(creator), stack) 137 } 138 139 // start indicates that a goroutine has started running on a proc. 140 func (gs *gState[R]) start(ts tracev2.Time, resource R, ctx *traceContext) { 141 // Set the time for all the active ranges. 142 for name := range gs.activeRanges { 143 gs.activeRanges[name] = activeRange{ts, tracev2.NoStack} 144 } 145 146 if gs.startCause.name != "" { 147 // It has a start cause. Emit a flow event. 148 ctx.Arrow(traceviewer.ArrowEvent{ 149 Name: gs.startCause.name, 150 Start: ctx.elapsed(gs.startCause.time), 151 End: ctx.elapsed(ts), 152 FromResource: uint64(gs.startCause.resource), 153 ToResource: uint64(resource), 154 FromStack: ctx.Stack(viewerFrames(gs.startCause.stack)), 155 }) 156 gs.startCause.time = 0 157 gs.startCause.name = "" 158 gs.startCause.resource = 0 159 gs.startCause.stack = tracev2.NoStack 160 } 161 gs.executing = resource 162 gs.startRunningTime = ts 163 } 164 165 // syscallBegin indicates that the goroutine entered a syscall on a proc. 166 func (gs *gState[R]) syscallBegin(ts tracev2.Time, resource R, stack tracev2.Stack) { 167 gs.syscall.time = ts 168 gs.syscall.stack = stack 169 gs.syscall.active = true 170 if gs.executing == R(noResource) { 171 gs.executing = resource 172 gs.startRunningTime = ts 173 } 174 } 175 176 // syscallEnd ends the syscall slice, wherever the syscall is at. This is orthogonal 177 // to blockedSyscallEnd -- both must be called when a syscall ends and that syscall 178 // blocked. They're kept separate because syscallEnd indicates the point at which the 179 // goroutine is no longer executing on the resource (e.g. a proc) whereas blockedSyscallEnd 180 // is the point at which the goroutine actually exited the syscall regardless of which 181 // resource that happened on. 182 func (gs *gState[R]) syscallEnd(ts tracev2.Time, blocked bool, ctx *traceContext) { 183 if !gs.syscall.active { 184 return 185 } 186 blockString := "no" 187 if blocked { 188 blockString = "yes" 189 } 190 gs.completedRanges = append(gs.completedRanges, completedRange{ 191 name: "syscall", 192 startTime: gs.syscall.time, 193 endTime: ts, 194 startStack: gs.syscall.stack, 195 arg: format.BlockedArg{Blocked: blockString}, 196 }) 197 gs.syscall.active = false 198 gs.syscall.time = 0 199 gs.syscall.stack = tracev2.NoStack 200 } 201 202 // blockedSyscallEnd indicates the point at which the blocked syscall ended. This is distinct 203 // and orthogonal to syscallEnd; both must be called if the syscall blocked. This sets up an instant 204 // to emit a flow event from, indicating explicitly that this goroutine was unblocked by the system. 205 func (gs *gState[R]) blockedSyscallEnd(ts tracev2.Time, stack tracev2.Stack, ctx *traceContext) { 206 name := "exit blocked syscall" 207 gs.setStartCause(ts, name, trace.SyscallP, stack) 208 209 // Emit an syscall exit instant event for the "Syscall" lane. 210 ctx.Instant(traceviewer.InstantEvent{ 211 Name: name, 212 Ts: ctx.elapsed(ts), 213 Resource: trace.SyscallP, 214 Stack: ctx.Stack(viewerFrames(stack)), 215 }) 216 } 217 218 // unblock indicates that the goroutine gs represents has been unblocked. 219 func (gs *gState[R]) unblock(ts tracev2.Time, stack tracev2.Stack, resource R, ctx *traceContext) { 220 name := "unblock" 221 viewerResource := uint64(resource) 222 if gs.startBlockReason != "" { 223 name = fmt.Sprintf("%s (%s)", name, gs.startBlockReason) 224 } 225 if strings.Contains(gs.startBlockReason, "network") { 226 // Attribute the network instant to the nebulous "NetpollP" if 227 // resource isn't a thread, because there's a good chance that 228 // resource isn't going to be valid in this case. 229 // 230 // TODO(mknyszek): Handle this invalidness in a more general way. 231 if _, ok := any(resource).(tracev2.ThreadID); !ok { 232 // Emit an unblock instant event for the "Network" lane. 233 viewerResource = trace.NetpollP 234 } 235 ctx.Instant(traceviewer.InstantEvent{ 236 Name: name, 237 Ts: ctx.elapsed(ts), 238 Resource: viewerResource, 239 Stack: ctx.Stack(viewerFrames(stack)), 240 }) 241 } 242 gs.startBlockReason = "" 243 if viewerResource != 0 { 244 gs.setStartCause(ts, name, viewerResource, stack) 245 } 246 } 247 248 // block indicates that the goroutine has stopped executing on a proc -- specifically, 249 // it blocked for some reason. 250 func (gs *gState[R]) block(ts tracev2.Time, stack tracev2.Stack, reason string, ctx *traceContext) { 251 gs.startBlockReason = reason 252 gs.stop(ts, stack, ctx) 253 } 254 255 // stop indicates that the goroutine has stopped executing on a proc. 256 func (gs *gState[R]) stop(ts tracev2.Time, stack tracev2.Stack, ctx *traceContext) { 257 // Emit the execution time slice. 258 var stk int 259 if gs.lastStopStack != tracev2.NoStack { 260 stk = ctx.Stack(viewerFrames(gs.lastStopStack)) 261 } 262 // Check invariants. 263 if gs.startRunningTime == 0 { 264 panic("silently broken trace or generator invariant (startRunningTime != 0) not held") 265 } 266 if gs.executing == R(noResource) { 267 panic("non-executing goroutine stopped") 268 } 269 ctx.Slice(traceviewer.SliceEvent{ 270 Name: gs.name(), 271 Ts: ctx.elapsed(gs.startRunningTime), 272 Dur: ts.Sub(gs.startRunningTime), 273 Resource: uint64(gs.executing), 274 Stack: stk, 275 }) 276 277 // Flush completed ranges. 278 for _, cr := range gs.completedRanges { 279 ctx.Slice(traceviewer.SliceEvent{ 280 Name: cr.name, 281 Ts: ctx.elapsed(cr.startTime), 282 Dur: cr.endTime.Sub(cr.startTime), 283 Resource: uint64(gs.executing), 284 Stack: ctx.Stack(viewerFrames(cr.startStack)), 285 EndStack: ctx.Stack(viewerFrames(cr.endStack)), 286 Arg: cr.arg, 287 }) 288 } 289 gs.completedRanges = gs.completedRanges[:0] 290 291 // Continue in-progress ranges. 292 for name, r := range gs.activeRanges { 293 // Check invariant. 294 if r.time == 0 { 295 panic("silently broken trace or generator invariant (activeRanges time != 0) not held") 296 } 297 ctx.Slice(traceviewer.SliceEvent{ 298 Name: name, 299 Ts: ctx.elapsed(r.time), 300 Dur: ts.Sub(r.time), 301 Resource: uint64(gs.executing), 302 Stack: ctx.Stack(viewerFrames(r.stack)), 303 }) 304 } 305 306 // Clear the range info. 307 for name := range gs.activeRanges { 308 gs.activeRanges[name] = activeRange{0, tracev2.NoStack} 309 } 310 311 gs.startRunningTime = 0 312 gs.lastStopStack = stack 313 gs.executing = R(noResource) 314 } 315 316 // finalize writes out any in-progress slices as if the goroutine stopped. 317 // This must only be used once the trace has been fully processed and no 318 // further events will be processed. This method may leave the gState in 319 // an inconsistent state. 320 func (gs *gState[R]) finish(ctx *traceContext) { 321 if gs.executing != R(noResource) { 322 gs.syscallEnd(ctx.endTime, false, ctx) 323 gs.stop(ctx.endTime, tracev2.NoStack, ctx) 324 } 325 } 326 327 // rangeBegin indicates the start of a special range of time. 328 func (gs *gState[R]) rangeBegin(ts tracev2.Time, name string, stack tracev2.Stack) { 329 if gs.executing != R(noResource) { 330 // If we're executing, start the slice from here. 331 gs.activeRanges[name] = activeRange{ts, stack} 332 } else { 333 // If the goroutine isn't executing, there's no place for 334 // us to create a slice from. Wait until it starts executing. 335 gs.activeRanges[name] = activeRange{0, stack} 336 } 337 } 338 339 // rangeActive indicates that a special range of time has been in progress. 340 func (gs *gState[R]) rangeActive(name string) { 341 if gs.executing != R(noResource) { 342 // If we're executing, and the range is active, then start 343 // from wherever the goroutine started running from. 344 gs.activeRanges[name] = activeRange{gs.startRunningTime, tracev2.NoStack} 345 } else { 346 // If the goroutine isn't executing, there's no place for 347 // us to create a slice from. Wait until it starts executing. 348 gs.activeRanges[name] = activeRange{0, tracev2.NoStack} 349 } 350 } 351 352 // rangeEnd indicates the end of a special range of time. 353 func (gs *gState[R]) rangeEnd(ts tracev2.Time, name string, stack tracev2.Stack, ctx *traceContext) { 354 if gs.executing != R(noResource) { 355 r := gs.activeRanges[name] 356 gs.completedRanges = append(gs.completedRanges, completedRange{ 357 name: name, 358 startTime: r.time, 359 endTime: ts, 360 startStack: r.stack, 361 endStack: stack, 362 }) 363 } 364 delete(gs.activeRanges, name) 365 } 366 367 func lastFunc(s tracev2.Stack) string { 368 var last tracev2.StackFrame 369 s.Frames(func(f tracev2.StackFrame) bool { 370 last = f 371 return true 372 }) 373 return last.Func 374 }