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