golang.org/x/exp@v0.0.0-20240506185415-9bf2ced13842/trace/oldtrace.go (about) 1 // Copyright 2024 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 // Code generated by "gen.bash" from internal/trace/v2; DO NOT EDIT. 6 7 //go:build go1.21 8 9 // This file implements conversion from old (Go 1.11–Go 1.21) traces to the Go 10 // 1.22 format. 11 // 12 // Most events have direct equivalents in 1.22, at worst requiring arguments to 13 // be reordered. Some events, such as GoWaiting need to look ahead for follow-up 14 // events to determine the correct translation. GoSyscall, which is an 15 // instantaneous event, gets turned into a 1 ns long pair of 16 // GoSyscallStart+GoSyscallEnd, unless we observe a GoSysBlock, in which case we 17 // emit a GoSyscallStart+GoSyscallEndBlocked pair with the correct duration 18 // (i.e. starting at the original GoSyscall). 19 // 20 // The resulting trace treats the old trace as a single, large generation, 21 // sharing a single evTable for all events. 22 // 23 // We use a new (compared to what was used for 'go tool trace' in earlier 24 // versions of Go) parser for old traces that is optimized for speed, low memory 25 // usage, and minimal GC pressure. It allocates events in batches so that even 26 // though we have to load the entire trace into memory, the conversion process 27 // shouldn't result in a doubling of memory usage, even if all converted events 28 // are kept alive, as we free batches once we're done with them. 29 // 30 // The conversion process is lossless. 31 32 package trace 33 34 import ( 35 "errors" 36 "fmt" 37 "golang.org/x/exp/trace/internal/event" 38 "golang.org/x/exp/trace/internal/event/go122" 39 "golang.org/x/exp/trace/internal/oldtrace" 40 "io" 41 ) 42 43 type oldTraceConverter struct { 44 trace oldtrace.Trace 45 evt *evTable 46 preInit bool 47 createdPreInit map[GoID]struct{} 48 events oldtrace.Events 49 extra []Event 50 extraArr [3]Event 51 tasks map[TaskID]taskState 52 seenProcs map[ProcID]struct{} 53 lastTs Time 54 procMs map[ProcID]ThreadID 55 lastStwReason uint64 56 57 inlineToStringID []uint64 58 builtinToStringID []uint64 59 } 60 61 const ( 62 // Block reasons 63 sForever = iota 64 sPreempted 65 sGosched 66 sSleep 67 sChanSend 68 sChanRecv 69 sNetwork 70 sSync 71 sSyncCond 72 sSelect 73 sEmpty 74 sMarkAssistWait 75 76 // STW kinds 77 sSTWUnknown 78 sSTWGCMarkTermination 79 sSTWGCSweepTermination 80 sSTWWriteHeapDump 81 sSTWGoroutineProfile 82 sSTWGoroutineProfileCleanup 83 sSTWAllGoroutinesStackTrace 84 sSTWReadMemStats 85 sSTWAllThreadsSyscall 86 sSTWGOMAXPROCS 87 sSTWStartTrace 88 sSTWStopTrace 89 sSTWCountPagesInUse 90 sSTWReadMetricsSlow 91 sSTWReadMemStatsSlow 92 sSTWPageCachePagesLeaked 93 sSTWResetDebugLog 94 95 sLast 96 ) 97 98 func (it *oldTraceConverter) init(pr oldtrace.Trace) error { 99 it.trace = pr 100 it.preInit = true 101 it.createdPreInit = make(map[GoID]struct{}) 102 it.evt = &evTable{pcs: make(map[uint64]frame)} 103 it.events = pr.Events 104 it.extra = it.extraArr[:0] 105 it.tasks = make(map[TaskID]taskState) 106 it.seenProcs = make(map[ProcID]struct{}) 107 it.procMs = make(map[ProcID]ThreadID) 108 it.lastTs = -1 109 110 evt := it.evt 111 112 // Convert from oldtracer's Strings map to our dataTable. 113 var max uint64 114 for id, s := range pr.Strings { 115 evt.strings.insert(stringID(id), s) 116 if id > max { 117 max = id 118 } 119 } 120 pr.Strings = nil 121 122 // Add all strings used for UserLog. In the old trace format, these were 123 // stored inline and didn't have IDs. We generate IDs for them. 124 if max+uint64(len(pr.InlineStrings)) < max { 125 return errors.New("trace contains too many strings") 126 } 127 var addErr error 128 add := func(id stringID, s string) { 129 if err := evt.strings.insert(id, s); err != nil && addErr == nil { 130 addErr = err 131 } 132 } 133 for id, s := range pr.InlineStrings { 134 nid := max + 1 + uint64(id) 135 it.inlineToStringID = append(it.inlineToStringID, nid) 136 add(stringID(nid), s) 137 } 138 max += uint64(len(pr.InlineStrings)) 139 pr.InlineStrings = nil 140 141 // Add strings that the converter emits explicitly. 142 if max+uint64(sLast) < max { 143 return errors.New("trace contains too many strings") 144 } 145 it.builtinToStringID = make([]uint64, sLast) 146 addBuiltin := func(c int, s string) { 147 nid := max + 1 + uint64(c) 148 it.builtinToStringID[c] = nid 149 add(stringID(nid), s) 150 } 151 addBuiltin(sForever, "forever") 152 addBuiltin(sPreempted, "preempted") 153 addBuiltin(sGosched, "runtime.Gosched") 154 addBuiltin(sSleep, "sleep") 155 addBuiltin(sChanSend, "chan send") 156 addBuiltin(sChanRecv, "chan receive") 157 addBuiltin(sNetwork, "network") 158 addBuiltin(sSync, "sync") 159 addBuiltin(sSyncCond, "sync.(*Cond).Wait") 160 addBuiltin(sSelect, "select") 161 addBuiltin(sEmpty, "") 162 addBuiltin(sMarkAssistWait, "GC mark assist wait for work") 163 addBuiltin(sSTWUnknown, "") 164 addBuiltin(sSTWGCMarkTermination, "GC mark termination") 165 addBuiltin(sSTWGCSweepTermination, "GC sweep termination") 166 addBuiltin(sSTWWriteHeapDump, "write heap dump") 167 addBuiltin(sSTWGoroutineProfile, "goroutine profile") 168 addBuiltin(sSTWGoroutineProfileCleanup, "goroutine profile cleanup") 169 addBuiltin(sSTWAllGoroutinesStackTrace, "all goroutine stack trace") 170 addBuiltin(sSTWReadMemStats, "read mem stats") 171 addBuiltin(sSTWAllThreadsSyscall, "AllThreadsSyscall") 172 addBuiltin(sSTWGOMAXPROCS, "GOMAXPROCS") 173 addBuiltin(sSTWStartTrace, "start trace") 174 addBuiltin(sSTWStopTrace, "stop trace") 175 addBuiltin(sSTWCountPagesInUse, "CountPagesInUse (test)") 176 addBuiltin(sSTWReadMetricsSlow, "ReadMetricsSlow (test)") 177 addBuiltin(sSTWReadMemStatsSlow, "ReadMemStatsSlow (test)") 178 addBuiltin(sSTWPageCachePagesLeaked, "PageCachePagesLeaked (test)") 179 addBuiltin(sSTWResetDebugLog, "ResetDebugLog (test)") 180 181 if addErr != nil { 182 // This should be impossible but let's be safe. 183 return fmt.Errorf("couldn't add strings: %w", addErr) 184 } 185 186 it.evt.strings.compactify() 187 188 // Convert stacks. 189 for id, stk := range pr.Stacks { 190 evt.stacks.insert(stackID(id), stack{pcs: stk}) 191 } 192 193 // OPT(dh): if we could share the frame type between this package and 194 // oldtrace we wouldn't have to copy the map. 195 for pc, f := range pr.PCs { 196 evt.pcs[pc] = frame{ 197 pc: pc, 198 funcID: stringID(f.Fn), 199 fileID: stringID(f.File), 200 line: uint64(f.Line), 201 } 202 } 203 pr.Stacks = nil 204 pr.PCs = nil 205 evt.stacks.compactify() 206 return nil 207 } 208 209 // next returns the next event, io.EOF if there are no more events, or a 210 // descriptive error for invalid events. 211 func (it *oldTraceConverter) next() (Event, error) { 212 if len(it.extra) > 0 { 213 ev := it.extra[0] 214 it.extra = it.extra[1:] 215 216 if len(it.extra) == 0 { 217 it.extra = it.extraArr[:0] 218 } 219 // Two events aren't allowed to fall on the same timestamp in the new API, 220 // but this may happen when we produce EvGoStatus events 221 if ev.base.time <= it.lastTs { 222 ev.base.time = it.lastTs + 1 223 } 224 it.lastTs = ev.base.time 225 return ev, nil 226 } 227 228 oev, ok := it.events.Pop() 229 if !ok { 230 return Event{}, io.EOF 231 } 232 233 ev, err := it.convertEvent(oev) 234 235 if err == errSkip { 236 return it.next() 237 } else if err != nil { 238 return Event{}, err 239 } 240 241 // Two events aren't allowed to fall on the same timestamp in the new API, 242 // but this may happen when we produce EvGoStatus events 243 if ev.base.time <= it.lastTs { 244 ev.base.time = it.lastTs + 1 245 } 246 it.lastTs = ev.base.time 247 return ev, nil 248 } 249 250 var errSkip = errors.New("skip event") 251 252 // convertEvent converts an event from the old trace format to zero or more 253 // events in the new format. Most events translate 1 to 1. Some events don't 254 // result in an event right away, in which case convertEvent returns errSkip. 255 // Some events result in more than one new event; in this case, convertEvent 256 // returns the first event and stores additional events in it.extra. When 257 // encountering events that oldtrace shouldn't be able to emit, ocnvertEvent 258 // returns a descriptive error. 259 func (it *oldTraceConverter) convertEvent(ev *oldtrace.Event) (OUT Event, ERR error) { 260 var mappedType event.Type 261 var mappedArgs timedEventArgs 262 copy(mappedArgs[:], ev.Args[:]) 263 264 switch ev.Type { 265 case oldtrace.EvGomaxprocs: 266 mappedType = go122.EvProcsChange 267 if it.preInit { 268 // The first EvGomaxprocs signals the end of trace initialization. At this point we've seen 269 // all goroutines that already existed at trace begin. 270 it.preInit = false 271 for gid := range it.createdPreInit { 272 // These are goroutines that already existed when tracing started but for which we 273 // received neither GoWaiting, GoInSyscall, or GoStart. These are goroutines that are in 274 // the states _Gidle or _Grunnable. 275 it.extra = append(it.extra, Event{ 276 ctx: schedCtx{ 277 // G: GoID(gid), 278 G: NoGoroutine, 279 P: NoProc, 280 M: NoThread, 281 }, 282 table: it.evt, 283 base: baseEvent{ 284 typ: go122.EvGoStatus, 285 time: Time(ev.Ts), 286 args: timedEventArgs{uint64(gid), ^uint64(0), uint64(go122.GoRunnable)}, 287 }, 288 }) 289 } 290 it.createdPreInit = nil 291 return Event{}, errSkip 292 } 293 case oldtrace.EvProcStart: 294 it.procMs[ProcID(ev.P)] = ThreadID(ev.Args[0]) 295 if _, ok := it.seenProcs[ProcID(ev.P)]; ok { 296 mappedType = go122.EvProcStart 297 mappedArgs = timedEventArgs{uint64(ev.P)} 298 } else { 299 it.seenProcs[ProcID(ev.P)] = struct{}{} 300 mappedType = go122.EvProcStatus 301 mappedArgs = timedEventArgs{uint64(ev.P), uint64(go122.ProcRunning)} 302 } 303 case oldtrace.EvProcStop: 304 if _, ok := it.seenProcs[ProcID(ev.P)]; ok { 305 mappedType = go122.EvProcStop 306 mappedArgs = timedEventArgs{uint64(ev.P)} 307 } else { 308 it.seenProcs[ProcID(ev.P)] = struct{}{} 309 mappedType = go122.EvProcStatus 310 mappedArgs = timedEventArgs{uint64(ev.P), uint64(go122.ProcIdle)} 311 } 312 case oldtrace.EvGCStart: 313 mappedType = go122.EvGCBegin 314 case oldtrace.EvGCDone: 315 mappedType = go122.EvGCEnd 316 case oldtrace.EvSTWStart: 317 sid := it.builtinToStringID[sSTWUnknown+it.trace.STWReason(ev.Args[0])] 318 it.lastStwReason = sid 319 mappedType = go122.EvSTWBegin 320 mappedArgs = timedEventArgs{uint64(sid)} 321 case oldtrace.EvSTWDone: 322 mappedType = go122.EvSTWEnd 323 mappedArgs = timedEventArgs{it.lastStwReason} 324 case oldtrace.EvGCSweepStart: 325 mappedType = go122.EvGCSweepBegin 326 case oldtrace.EvGCSweepDone: 327 mappedType = go122.EvGCSweepEnd 328 case oldtrace.EvGoCreate: 329 if it.preInit { 330 it.createdPreInit[GoID(ev.Args[0])] = struct{}{} 331 return Event{}, errSkip 332 } 333 mappedType = go122.EvGoCreate 334 case oldtrace.EvGoStart: 335 if it.preInit { 336 mappedType = go122.EvGoStatus 337 mappedArgs = timedEventArgs{ev.Args[0], ^uint64(0), uint64(go122.GoRunning)} 338 delete(it.createdPreInit, GoID(ev.Args[0])) 339 } else { 340 mappedType = go122.EvGoStart 341 } 342 case oldtrace.EvGoStartLabel: 343 it.extra = []Event{{ 344 ctx: schedCtx{ 345 G: GoID(ev.G), 346 P: ProcID(ev.P), 347 M: it.procMs[ProcID(ev.P)], 348 }, 349 table: it.evt, 350 base: baseEvent{ 351 typ: go122.EvGoLabel, 352 time: Time(ev.Ts), 353 args: timedEventArgs{ev.Args[2]}, 354 }, 355 }} 356 return Event{ 357 ctx: schedCtx{ 358 G: GoID(ev.G), 359 P: ProcID(ev.P), 360 M: it.procMs[ProcID(ev.P)], 361 }, 362 table: it.evt, 363 base: baseEvent{ 364 typ: go122.EvGoStart, 365 time: Time(ev.Ts), 366 args: mappedArgs, 367 }, 368 }, nil 369 case oldtrace.EvGoEnd: 370 mappedType = go122.EvGoDestroy 371 case oldtrace.EvGoStop: 372 mappedType = go122.EvGoBlock 373 mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sForever]), uint64(ev.StkID)} 374 case oldtrace.EvGoSched: 375 mappedType = go122.EvGoStop 376 mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sGosched]), uint64(ev.StkID)} 377 case oldtrace.EvGoPreempt: 378 mappedType = go122.EvGoStop 379 mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sPreempted]), uint64(ev.StkID)} 380 case oldtrace.EvGoSleep: 381 mappedType = go122.EvGoBlock 382 mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sSleep]), uint64(ev.StkID)} 383 case oldtrace.EvGoBlock: 384 mappedType = go122.EvGoBlock 385 mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sEmpty]), uint64(ev.StkID)} 386 case oldtrace.EvGoUnblock: 387 mappedType = go122.EvGoUnblock 388 case oldtrace.EvGoBlockSend: 389 mappedType = go122.EvGoBlock 390 mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sChanSend]), uint64(ev.StkID)} 391 case oldtrace.EvGoBlockRecv: 392 mappedType = go122.EvGoBlock 393 mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sChanRecv]), uint64(ev.StkID)} 394 case oldtrace.EvGoBlockSelect: 395 mappedType = go122.EvGoBlock 396 mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sSelect]), uint64(ev.StkID)} 397 case oldtrace.EvGoBlockSync: 398 mappedType = go122.EvGoBlock 399 mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sSync]), uint64(ev.StkID)} 400 case oldtrace.EvGoBlockCond: 401 mappedType = go122.EvGoBlock 402 mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sSyncCond]), uint64(ev.StkID)} 403 case oldtrace.EvGoBlockNet: 404 mappedType = go122.EvGoBlock 405 mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sNetwork]), uint64(ev.StkID)} 406 case oldtrace.EvGoBlockGC: 407 mappedType = go122.EvGoBlock 408 mappedArgs = timedEventArgs{uint64(it.builtinToStringID[sMarkAssistWait]), uint64(ev.StkID)} 409 case oldtrace.EvGoSysCall: 410 // Look for the next event for the same G to determine if the syscall 411 // blocked. 412 blocked := false 413 it.events.All()(func(nev *oldtrace.Event) bool { 414 if nev.G != ev.G { 415 return true 416 } 417 // After an EvGoSysCall, the next event on the same G will either be 418 // EvGoSysBlock to denote a blocking syscall, or some other event 419 // (or the end of the trace) if the syscall didn't block. 420 if nev.Type == oldtrace.EvGoSysBlock { 421 blocked = true 422 } 423 return false 424 }) 425 if blocked { 426 mappedType = go122.EvGoSyscallBegin 427 mappedArgs = timedEventArgs{1: uint64(ev.StkID)} 428 } else { 429 // Convert the old instantaneous syscall event to a pair of syscall 430 // begin and syscall end and give it the shortest possible duration, 431 // 1ns. 432 out1 := Event{ 433 ctx: schedCtx{ 434 G: GoID(ev.G), 435 P: ProcID(ev.P), 436 M: it.procMs[ProcID(ev.P)], 437 }, 438 table: it.evt, 439 base: baseEvent{ 440 typ: go122.EvGoSyscallBegin, 441 time: Time(ev.Ts), 442 args: timedEventArgs{1: uint64(ev.StkID)}, 443 }, 444 } 445 446 out2 := Event{ 447 ctx: out1.ctx, 448 table: it.evt, 449 base: baseEvent{ 450 typ: go122.EvGoSyscallEnd, 451 time: Time(ev.Ts + 1), 452 args: timedEventArgs{}, 453 }, 454 } 455 456 it.extra = append(it.extra, out2) 457 return out1, nil 458 } 459 460 case oldtrace.EvGoSysExit: 461 mappedType = go122.EvGoSyscallEndBlocked 462 case oldtrace.EvGoSysBlock: 463 return Event{}, errSkip 464 case oldtrace.EvGoWaiting: 465 mappedType = go122.EvGoStatus 466 mappedArgs = timedEventArgs{ev.Args[0], ^uint64(0), uint64(go122.GoWaiting)} 467 delete(it.createdPreInit, GoID(ev.Args[0])) 468 case oldtrace.EvGoInSyscall: 469 mappedType = go122.EvGoStatus 470 // In the new tracer, GoStatus with GoSyscall knows what thread the 471 // syscall is on. In the old tracer, EvGoInSyscall doesn't contain that 472 // information and all we can do here is specify NoThread. 473 mappedArgs = timedEventArgs{ev.Args[0], ^uint64(0), uint64(go122.GoSyscall)} 474 delete(it.createdPreInit, GoID(ev.Args[0])) 475 case oldtrace.EvHeapAlloc: 476 mappedType = go122.EvHeapAlloc 477 case oldtrace.EvHeapGoal: 478 mappedType = go122.EvHeapGoal 479 case oldtrace.EvGCMarkAssistStart: 480 mappedType = go122.EvGCMarkAssistBegin 481 case oldtrace.EvGCMarkAssistDone: 482 mappedType = go122.EvGCMarkAssistEnd 483 case oldtrace.EvUserTaskCreate: 484 mappedType = go122.EvUserTaskBegin 485 parent := ev.Args[1] 486 if parent == 0 { 487 parent = uint64(NoTask) 488 } 489 mappedArgs = timedEventArgs{ev.Args[0], parent, ev.Args[2], uint64(ev.StkID)} 490 name, _ := it.evt.strings.get(stringID(ev.Args[2])) 491 it.tasks[TaskID(ev.Args[0])] = taskState{name: name, parentID: TaskID(ev.Args[1])} 492 case oldtrace.EvUserTaskEnd: 493 mappedType = go122.EvUserTaskEnd 494 // Event.Task expects the parent and name to be smuggled in extra args 495 // and as extra strings. 496 ts, ok := it.tasks[TaskID(ev.Args[0])] 497 if ok { 498 delete(it.tasks, TaskID(ev.Args[0])) 499 mappedArgs = timedEventArgs{ 500 ev.Args[0], 501 ev.Args[1], 502 uint64(ts.parentID), 503 uint64(it.evt.addExtraString(ts.name)), 504 } 505 } else { 506 mappedArgs = timedEventArgs{ev.Args[0], ev.Args[1], uint64(NoTask), uint64(it.evt.addExtraString(""))} 507 } 508 case oldtrace.EvUserRegion: 509 switch ev.Args[1] { 510 case 0: // start 511 mappedType = go122.EvUserRegionBegin 512 case 1: // end 513 mappedType = go122.EvUserRegionEnd 514 } 515 mappedArgs = timedEventArgs{ev.Args[0], ev.Args[2], uint64(ev.StkID)} 516 case oldtrace.EvUserLog: 517 mappedType = go122.EvUserLog 518 mappedArgs = timedEventArgs{ev.Args[0], ev.Args[1], it.inlineToStringID[ev.Args[3]], uint64(ev.StkID)} 519 case oldtrace.EvCPUSample: 520 mappedType = go122.EvCPUSample 521 // When emitted by the Go 1.22 tracer, CPU samples have 5 arguments: 522 // timestamp, M, P, G, stack. However, after they get turned into Event, 523 // they have the arguments stack, M, P, G. 524 // 525 // In Go 1.21, CPU samples did not have Ms. 526 mappedArgs = timedEventArgs{uint64(ev.StkID), ^uint64(0), uint64(ev.P), ev.G} 527 default: 528 return Event{}, fmt.Errorf("unexpected event type %v", ev.Type) 529 } 530 531 if oldtrace.EventDescriptions[ev.Type].Stack { 532 if stackIDs := go122.Specs()[mappedType].StackIDs; len(stackIDs) > 0 { 533 mappedArgs[stackIDs[0]-1] = uint64(ev.StkID) 534 } 535 } 536 537 m := NoThread 538 if ev.P != -1 && ev.Type != oldtrace.EvCPUSample { 539 if t, ok := it.procMs[ProcID(ev.P)]; ok { 540 m = ThreadID(t) 541 } 542 } 543 if ev.Type == oldtrace.EvProcStop { 544 delete(it.procMs, ProcID(ev.P)) 545 } 546 g := GoID(ev.G) 547 if g == 0 { 548 g = NoGoroutine 549 } 550 out := Event{ 551 ctx: schedCtx{ 552 G: GoID(g), 553 P: ProcID(ev.P), 554 M: m, 555 }, 556 table: it.evt, 557 base: baseEvent{ 558 typ: mappedType, 559 time: Time(ev.Ts), 560 args: mappedArgs, 561 }, 562 } 563 return out, nil 564 } 565 566 // convertOldFormat takes a fully loaded trace in the old trace format and 567 // returns an iterator over events in the new format. 568 func convertOldFormat(pr oldtrace.Trace) *oldTraceConverter { 569 it := &oldTraceConverter{} 570 it.init(pr) 571 return it 572 }