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 ( 8 "bufio" 9 "bytes" 10 "fmt" 11 "io" 12 "os" 13 "os/exec" 14 "sort" 15 "strconv" 16 "strings" 17 ) 18 19 // Event describes one event in the trace. 20 type Event struct { 21 Off int // offset in input file (for debugging and error reporting) 22 Type byte // one of Ev* 23 Seq int64 // sequence number 24 Ts int64 // timestamp in nanoseconds 25 P int // P on which the event happened (can be one of TimerP, NetpollP, SyscallP) 26 G uint64 // G on which the event happened 27 StkID uint64 // unique stack ID 28 Stk []*Frame // stack trace (can be empty) 29 Args [3]uint64 // event-type-specific arguments 30 // linked event (can be nil), depends on event type: 31 // for GCStart: the GCStop 32 // for GCScanStart: the GCScanDone 33 // for GCSweepStart: the GCSweepDone 34 // for GoCreate: first GoStart of the created goroutine 35 // for GoStart: the associated GoEnd, GoBlock or other blocking event 36 // for GoSched/GoPreempt: the next GoStart 37 // for GoBlock and other blocking events: the unblock event 38 // for GoUnblock: the associated GoStart 39 // for blocking GoSysCall: the associated GoSysExit 40 // for GoSysExit: the next GoStart 41 Link *Event 42 } 43 44 // Frame is a frame in stack traces. 45 type Frame struct { 46 PC uint64 47 Fn string 48 File string 49 Line int 50 } 51 52 const ( 53 // Special P identifiers: 54 FakeP = 1000000 + iota 55 TimerP // depicts timer unblocks 56 NetpollP // depicts network unblocks 57 SyscallP // depicts returns from syscalls 58 ) 59 60 // Parse parses, post-processes and verifies the trace. 61 func Parse(r io.Reader) ([]*Event, error) { 62 rawEvents, err := readTrace(r) 63 if err != nil { 64 return nil, err 65 } 66 events, err := parseEvents(rawEvents) 67 if err != nil { 68 return nil, err 69 } 70 events, err = removeFutile(events) 71 if err != nil { 72 return nil, err 73 } 74 err = postProcessTrace(events) 75 if err != nil { 76 return nil, err 77 } 78 return events, nil 79 } 80 81 // rawEvent is a helper type used during parsing. 82 type rawEvent struct { 83 off int 84 typ byte 85 args []uint64 86 } 87 88 // readTrace does wire-format parsing and verification. 89 // It does not care about specific event types and argument meaning. 90 func readTrace(r io.Reader) ([]rawEvent, error) { 91 // Read and validate trace header. 92 var buf [16]byte 93 off, err := r.Read(buf[:]) 94 if off != 16 || err != nil { 95 return nil, fmt.Errorf("failed to read header: read %v, err %v", off, err) 96 } 97 if bytes.Compare(buf[:], []byte("go 1.5 trace\x00\x00\x00\x00")) != 0 { 98 return nil, fmt.Errorf("not a trace file") 99 } 100 101 // Read events. 102 var events []rawEvent 103 for { 104 // Read event type and number of arguments (1 byte). 105 off0 := off 106 n, err := r.Read(buf[:1]) 107 if err == io.EOF { 108 break 109 } 110 if err != nil || n != 1 { 111 return nil, fmt.Errorf("failed to read trace at offset 0x%x: n=%v err=%v", off0, n, err) 112 } 113 off += n 114 typ := buf[0] << 2 >> 2 115 narg := buf[0] >> 6 116 ev := rawEvent{typ: typ, off: off0} 117 if narg < 3 { 118 for i := 0; i < int(narg)+2; i++ { // sequence number and time stamp are present but not counted in narg 119 var v uint64 120 v, off, err = readVal(r, off) 121 if err != nil { 122 return nil, err 123 } 124 ev.args = append(ev.args, v) 125 } 126 } else { 127 // If narg == 3, the first value is length of the event in bytes. 128 var v uint64 129 v, off, err = readVal(r, off) 130 if err != nil { 131 return nil, err 132 } 133 evLen := v 134 off1 := off 135 for evLen > uint64(off-off1) { 136 v, off, err = readVal(r, off) 137 if err != nil { 138 return nil, err 139 } 140 ev.args = append(ev.args, v) 141 } 142 if evLen != uint64(off-off1) { 143 return nil, fmt.Errorf("event has wrong length at offset 0x%x: want %v, got %v", off0, evLen, off-off1) 144 } 145 } 146 events = append(events, ev) 147 } 148 return events, nil 149 } 150 151 // Parse events transforms raw events into events. 152 // It does analyze and verify per-event-type arguments. 153 func parseEvents(rawEvents []rawEvent) (events []*Event, err error) { 154 var ticksPerSec, lastSeq, lastTs int64 155 var lastG, timerGoid uint64 156 var lastP int 157 lastGs := make(map[int]uint64) // last goroutine running on P 158 stacks := make(map[uint64][]*Frame) 159 for _, raw := range rawEvents { 160 if raw.typ == EvNone || raw.typ >= EvCount { 161 err = fmt.Errorf("unknown event type %v at offset 0x%x", raw.typ, raw.off) 162 return 163 } 164 desc := EventDescriptions[raw.typ] 165 if desc.Name == "" { 166 err = fmt.Errorf("missing description for event type %v", raw.typ) 167 return 168 } 169 if raw.typ != EvStack { 170 narg := len(desc.Args) 171 if desc.Stack { 172 narg++ 173 } 174 if raw.typ != EvBatch && raw.typ != EvFrequency && raw.typ != EvTimerGoroutine { 175 narg++ // sequence number 176 narg++ // timestamp 177 } 178 if len(raw.args) != narg { 179 err = fmt.Errorf("%v has wrong number of arguments at offset 0x%x: want %v, got %v", 180 desc.Name, raw.off, narg, len(raw.args)) 181 return 182 } 183 } 184 switch raw.typ { 185 case EvBatch: 186 lastGs[lastP] = lastG 187 lastP = int(raw.args[0]) 188 lastG = lastGs[lastP] 189 lastSeq = int64(raw.args[1]) 190 lastTs = int64(raw.args[2]) 191 case EvFrequency: 192 ticksPerSec = int64(raw.args[0]) 193 if ticksPerSec <= 0 { 194 // The most likely cause for this is tick skew on different CPUs. 195 // For example, solaris/amd64 seems to have wildly different 196 // ticks on different CPUs. 197 err = ErrTimeOrder 198 return 199 } 200 case EvTimerGoroutine: 201 timerGoid = raw.args[0] 202 case EvStack: 203 if len(raw.args) < 2 { 204 err = fmt.Errorf("EvStack has wrong number of arguments at offset 0x%x: want at least 2, got %v", 205 raw.off, len(raw.args)) 206 return 207 } 208 size := raw.args[1] 209 if size > 1000 { 210 err = fmt.Errorf("EvStack has bad number of frames at offset 0x%x: %v", 211 raw.off, size) 212 return 213 } 214 if uint64(len(raw.args)) != size+2 { 215 err = fmt.Errorf("EvStack has wrong number of arguments at offset 0x%x: want %v, got %v", 216 raw.off, size+2, len(raw.args)) 217 return 218 } 219 id := raw.args[0] 220 if id != 0 && size > 0 { 221 stk := make([]*Frame, size) 222 for i := 0; i < int(size); i++ { 223 stk[i] = &Frame{PC: raw.args[i+2]} 224 } 225 stacks[id] = stk 226 } 227 default: 228 e := &Event{Off: raw.off, Type: raw.typ, P: lastP, G: lastG} 229 e.Seq = lastSeq + int64(raw.args[0]) 230 e.Ts = lastTs + int64(raw.args[1]) 231 lastSeq = e.Seq 232 lastTs = e.Ts 233 for i := range desc.Args { 234 e.Args[i] = raw.args[i+2] 235 } 236 if desc.Stack { 237 e.StkID = raw.args[len(desc.Args)+2] 238 } 239 switch raw.typ { 240 case EvGoStart: 241 lastG = e.Args[0] 242 e.G = lastG 243 case EvGCStart, EvGCDone, EvGCScanStart, EvGCScanDone: 244 e.G = 0 245 case EvGoEnd, EvGoStop, EvGoSched, EvGoPreempt, 246 EvGoSleep, EvGoBlock, EvGoBlockSend, EvGoBlockRecv, 247 EvGoBlockSelect, EvGoBlockSync, EvGoBlockCond, EvGoBlockNet, 248 EvGoSysBlock: 249 lastG = 0 250 case EvGoSysExit: 251 // EvGoSysExit emission is delayed until the thread has a P. 252 // Give it the real sequence number and time stamp. 253 e.Seq = int64(e.Args[1]) 254 if e.Args[2] != 0 { 255 e.Ts = int64(e.Args[2]) 256 } 257 } 258 events = append(events, e) 259 } 260 } 261 if len(events) == 0 { 262 err = fmt.Errorf("trace is empty") 263 return 264 } 265 266 // Attach stack traces. 267 for _, ev := range events { 268 if ev.StkID != 0 { 269 ev.Stk = stacks[ev.StkID] 270 } 271 } 272 273 // Sort by sequence number and translate cpu ticks to real time. 274 sort.Sort(eventList(events)) 275 if ticksPerSec == 0 { 276 err = fmt.Errorf("no EvFrequency event") 277 return 278 } 279 minTs := events[0].Ts 280 for _, ev := range events { 281 ev.Ts = (ev.Ts - minTs) * 1e9 / ticksPerSec 282 // Move timers and syscalls to separate fake Ps. 283 if timerGoid != 0 && ev.G == timerGoid && ev.Type == EvGoUnblock { 284 ev.P = TimerP 285 } 286 if ev.Type == EvGoSysExit { 287 ev.P = SyscallP 288 ev.G = ev.Args[0] 289 } 290 } 291 292 return 293 } 294 295 // removeFutile removes all constituents of futile wakeups (block, unblock, start). 296 // For example, a goroutine was unblocked on a mutex, but another goroutine got 297 // ahead and acquired the mutex before the first goroutine is scheduled, 298 // so the first goroutine has to block again. Such wakeups happen on buffered 299 // channels and sync.Mutex, but are generally not interesting for end user. 300 func removeFutile(events []*Event) ([]*Event, error) { 301 // Two non-trivial aspects: 302 // 1. A goroutine can be preempted during a futile wakeup and migrate to another P. 303 // We want to remove all of that. 304 // 2. Tracing can start in the middle of a futile wakeup. 305 // That is, we can see a futile wakeup event w/o the actual wakeup before it. 306 // postProcessTrace runs after us and ensures that we leave the trace in a consistent state. 307 308 // Phase 1: determine futile wakeup sequences. 309 type G struct { 310 futile bool 311 wakeup []*Event // wakeup sequence (subject for removal) 312 } 313 gs := make(map[uint64]G) 314 futile := make(map[*Event]bool) 315 for _, ev := range events { 316 switch ev.Type { 317 case EvGoUnblock: 318 g := gs[ev.Args[0]] 319 g.wakeup = []*Event{ev} 320 gs[ev.Args[0]] = g 321 case EvGoStart, EvGoPreempt, EvFutileWakeup: 322 g := gs[ev.G] 323 g.wakeup = append(g.wakeup, ev) 324 if ev.Type == EvFutileWakeup { 325 g.futile = true 326 } 327 gs[ev.G] = g 328 case EvGoBlock, EvGoBlockSend, EvGoBlockRecv, EvGoBlockSelect, EvGoBlockSync, EvGoBlockCond: 329 g := gs[ev.G] 330 if g.futile { 331 futile[ev] = true 332 for _, ev1 := range g.wakeup { 333 futile[ev1] = true 334 } 335 } 336 delete(gs, ev.G) 337 } 338 } 339 340 // Phase 2: remove futile wakeup sequences. 341 newEvents := events[:0] // overwrite the original slice 342 for _, ev := range events { 343 if !futile[ev] { 344 newEvents = append(newEvents, ev) 345 } 346 } 347 return newEvents, nil 348 } 349 350 // ErrTimeOrder is returned by Parse when the trace contains 351 // time stamps that do not respect actual event ordering. 352 var ErrTimeOrder = fmt.Errorf("time stamps out of order") 353 354 // postProcessTrace does inter-event verification and information restoration. 355 // The resulting trace is guaranteed to be consistent 356 // (for example, a P does not run two Gs at the same time, or a G is indeed 357 // blocked before an unblock event). 358 func postProcessTrace(events []*Event) error { 359 const ( 360 gDead = iota 361 gRunnable 362 gRunning 363 gWaiting 364 ) 365 type gdesc struct { 366 state int 367 ev *Event 368 evStart *Event 369 evCreate *Event 370 } 371 type pdesc struct { 372 running bool 373 g uint64 374 evScan *Event 375 evSweep *Event 376 } 377 378 gs := make(map[uint64]gdesc) 379 ps := make(map[int]pdesc) 380 gs[0] = gdesc{state: gRunning} 381 var evGC *Event 382 383 checkRunning := func(p pdesc, g gdesc, ev *Event, allowG0 bool) error { 384 name := EventDescriptions[ev.Type].Name 385 if g.state != gRunning { 386 return fmt.Errorf("g %v is not running while %v (offset %v, time %v)", ev.G, name, ev.Off, ev.Ts) 387 } 388 if p.g != ev.G { 389 return fmt.Errorf("p %v is not running g %v while %v (offset %v, time %v)", ev.P, ev.G, name, ev.Off, ev.Ts) 390 } 391 if !allowG0 && ev.G == 0 { 392 return fmt.Errorf("g 0 did %v (offset %v, time %v)", EventDescriptions[ev.Type].Name, ev.Off, ev.Ts) 393 } 394 return nil 395 } 396 397 for _, ev := range events { 398 g := gs[ev.G] 399 p := ps[ev.P] 400 401 switch ev.Type { 402 case EvProcStart: 403 if p.running { 404 return fmt.Errorf("p %v is running before start (offset %v, time %v)", ev.P, ev.Off, ev.Ts) 405 } 406 p.running = true 407 case EvProcStop: 408 if !p.running { 409 return fmt.Errorf("p %v is not running before stop (offset %v, time %v)", ev.P, ev.Off, ev.Ts) 410 } 411 if p.g != 0 { 412 return fmt.Errorf("p %v is running a goroutine %v during stop (offset %v, time %v)", ev.P, p.g, ev.Off, ev.Ts) 413 } 414 p.running = false 415 case EvGCStart: 416 if evGC != nil { 417 return fmt.Errorf("previous GC is not ended before a new one (offset %v, time %v)", ev.Off, ev.Ts) 418 } 419 evGC = ev 420 case EvGCDone: 421 if evGC == nil { 422 return fmt.Errorf("bogus GC end (offset %v, time %v)", ev.Off, ev.Ts) 423 } 424 evGC.Link = ev 425 evGC = nil 426 case EvGCScanStart: 427 if p.evScan != nil { 428 return fmt.Errorf("previous scanning is not ended before a new one (offset %v, time %v)", ev.Off, ev.Ts) 429 } 430 p.evScan = ev 431 case EvGCScanDone: 432 if p.evScan == nil { 433 return fmt.Errorf("bogus scanning end (offset %v, time %v)", ev.Off, ev.Ts) 434 } 435 p.evScan.Link = ev 436 p.evScan = nil 437 case EvGCSweepStart: 438 if p.evSweep != nil { 439 return fmt.Errorf("previous sweeping is not ended before a new one (offset %v, time %v)", ev.Off, ev.Ts) 440 } 441 p.evSweep = ev 442 case EvGCSweepDone: 443 if p.evSweep == nil { 444 return fmt.Errorf("bogus sweeping end (offset %v, time %v)", ev.Off, ev.Ts) 445 } 446 p.evSweep.Link = ev 447 p.evSweep = nil 448 case EvGoWaiting: 449 g1 := gs[ev.Args[0]] 450 if g1.state != gRunnable { 451 return fmt.Errorf("g %v is not runnable before EvGoWaiting (offset %v, time %v)", ev.Args[0], ev.Off, ev.Ts) 452 } 453 g1.state = gWaiting 454 gs[ev.Args[0]] = g1 455 case EvGoInSyscall: 456 g1 := gs[ev.Args[0]] 457 if g1.state != gRunnable { 458 return fmt.Errorf("g %v is not runnable before EvGoInSyscall (offset %v, time %v)", ev.Args[0], ev.Off, ev.Ts) 459 } 460 g1.state = gWaiting 461 gs[ev.Args[0]] = g1 462 case EvGoCreate: 463 if err := checkRunning(p, g, ev, true); err != nil { 464 return err 465 } 466 if _, ok := gs[ev.Args[0]]; ok { 467 return fmt.Errorf("g %v already exists (offset %v, time %v)", ev.Args[0], ev.Off, ev.Ts) 468 } 469 gs[ev.Args[0]] = gdesc{state: gRunnable, ev: ev, evCreate: ev} 470 case EvGoStart: 471 if g.state != gRunnable { 472 return fmt.Errorf("g %v is not runnable before start (offset %v, time %v)", ev.G, ev.Off, ev.Ts) 473 } 474 if p.g != 0 { 475 return fmt.Errorf("p %v is already running g %v while start g %v (offset %v, time %v)", ev.P, p.g, ev.G, ev.Off, ev.Ts) 476 } 477 g.state = gRunning 478 g.evStart = ev 479 p.g = ev.G 480 if g.evCreate != nil { 481 // +1 because symbolizer expects return pc. 482 ev.Stk = []*Frame{&Frame{PC: g.evCreate.Args[1] + 1}} 483 g.evCreate = nil 484 } 485 486 if g.ev != nil { 487 g.ev.Link = ev 488 g.ev = nil 489 } 490 case EvGoEnd, EvGoStop: 491 if err := checkRunning(p, g, ev, false); err != nil { 492 return err 493 } 494 g.evStart.Link = ev 495 g.evStart = nil 496 g.state = gDead 497 p.g = 0 498 case EvGoSched, EvGoPreempt: 499 if err := checkRunning(p, g, ev, false); err != nil { 500 return err 501 } 502 g.state = gRunnable 503 g.evStart.Link = ev 504 g.evStart = nil 505 p.g = 0 506 g.ev = ev 507 case EvGoUnblock: 508 if g.state != gRunning { 509 return fmt.Errorf("g %v is not running while unpark (offset %v, time %v)", ev.G, ev.Off, ev.Ts) 510 } 511 if ev.P != TimerP && p.g != ev.G { 512 return fmt.Errorf("p %v is not running g %v while unpark (offset %v, time %v)", ev.P, ev.G, ev.Off, ev.Ts) 513 } 514 g1 := gs[ev.Args[0]] 515 if g1.state != gWaiting { 516 return fmt.Errorf("g %v is not waiting before unpark (offset %v, time %v)", ev.Args[0], ev.Off, ev.Ts) 517 } 518 if g1.ev != nil && g1.ev.Type == EvGoBlockNet && ev.P != TimerP { 519 ev.P = NetpollP 520 } 521 if g1.ev != nil { 522 g1.ev.Link = ev 523 } 524 g1.state = gRunnable 525 g1.ev = ev 526 gs[ev.Args[0]] = g1 527 case EvGoSysCall: 528 if err := checkRunning(p, g, ev, false); err != nil { 529 return err 530 } 531 g.ev = ev 532 case EvGoSysBlock: 533 if err := checkRunning(p, g, ev, false); err != nil { 534 return err 535 } 536 g.state = gWaiting 537 g.evStart.Link = ev 538 g.evStart = nil 539 p.g = 0 540 case EvGoSysExit: 541 if g.state != gWaiting { 542 return fmt.Errorf("g %v is not waiting during syscall exit (offset %v, time %v)", ev.G, ev.Off, ev.Ts) 543 } 544 if g.ev != nil && g.ev.Type == EvGoSysCall { 545 g.ev.Link = ev 546 } 547 g.state = gRunnable 548 g.ev = ev 549 case EvGoSleep, EvGoBlock, EvGoBlockSend, EvGoBlockRecv, 550 EvGoBlockSelect, EvGoBlockSync, EvGoBlockCond, EvGoBlockNet: 551 if err := checkRunning(p, g, ev, false); err != nil { 552 return err 553 } 554 g.state = gWaiting 555 g.ev = ev 556 g.evStart.Link = ev 557 g.evStart = nil 558 p.g = 0 559 } 560 561 gs[ev.G] = g 562 ps[ev.P] = p 563 } 564 565 // TODO(dvyukov): restore stacks for EvGoStart events. 566 // TODO(dvyukov): test that all EvGoStart events has non-nil Link. 567 568 // Last, after all the other consistency checks, 569 // make sure time stamps respect sequence numbers. 570 // The tests will skip (not fail) the test case if they see this error, 571 // so check everything else that could possibly be wrong first. 572 lastTs := int64(0) 573 for _, ev := range events { 574 if ev.Ts < lastTs { 575 return ErrTimeOrder 576 } 577 lastTs = ev.Ts 578 } 579 580 return nil 581 } 582 583 // symbolizeTrace attaches func/file/line info to stack traces. 584 func Symbolize(events []*Event, bin string) error { 585 // First, collect and dedup all pcs. 586 pcs := make(map[uint64]*Frame) 587 for _, ev := range events { 588 for _, f := range ev.Stk { 589 pcs[f.PC] = nil 590 } 591 } 592 593 // Start addr2line. 594 cmd := exec.Command("go", "tool", "addr2line", bin) 595 in, err := cmd.StdinPipe() 596 if err != nil { 597 return fmt.Errorf("failed to pipe addr2line stdin: %v", err) 598 } 599 cmd.Stderr = os.Stderr 600 out, err := cmd.StdoutPipe() 601 if err != nil { 602 return fmt.Errorf("failed to pipe addr2line stdout: %v", err) 603 } 604 err = cmd.Start() 605 if err != nil { 606 return fmt.Errorf("failed to start addr2line: %v", err) 607 } 608 outb := bufio.NewReader(out) 609 610 // Write all pcs to addr2line. 611 // Need to copy pcs to an array, because map iteration order is non-deterministic. 612 var pcArray []uint64 613 for pc := range pcs { 614 pcArray = append(pcArray, pc) 615 _, err := fmt.Fprintf(in, "0x%x\n", pc-1) 616 if err != nil { 617 return fmt.Errorf("failed to write to addr2line: %v", err) 618 } 619 } 620 in.Close() 621 622 // Read in answers. 623 for _, pc := range pcArray { 624 fn, err := outb.ReadString('\n') 625 if err != nil { 626 return fmt.Errorf("failed to read from addr2line: %v", err) 627 } 628 file, err := outb.ReadString('\n') 629 if err != nil { 630 return fmt.Errorf("failed to read from addr2line: %v", err) 631 } 632 f := &Frame{PC: pc} 633 f.Fn = fn[:len(fn)-1] 634 f.File = file[:len(file)-1] 635 if colon := strings.LastIndex(f.File, ":"); colon != -1 { 636 ln, err := strconv.Atoi(f.File[colon+1:]) 637 if err == nil { 638 f.File = f.File[:colon] 639 f.Line = ln 640 } 641 } 642 pcs[pc] = f 643 } 644 cmd.Wait() 645 646 // Replace frames in events array. 647 for _, ev := range events { 648 for i, f := range ev.Stk { 649 ev.Stk[i] = pcs[f.PC] 650 } 651 } 652 653 return nil 654 } 655 656 // readVal reads unsigned base-128 value from r. 657 func readVal(r io.Reader, off0 int) (v uint64, off int, err error) { 658 off = off0 659 for i := 0; i < 10; i++ { 660 var buf [1]byte 661 var n int 662 n, err = r.Read(buf[:]) 663 if err != nil || n != 1 { 664 return 0, 0, fmt.Errorf("failed to read trace at offset %d: read %v, error %v", off0, n, err) 665 } 666 off++ 667 v |= uint64(buf[0]&0x7f) << (uint(i) * 7) 668 if buf[0]&0x80 == 0 { 669 return 670 } 671 } 672 return 0, 0, fmt.Errorf("bad value at offset 0x%x", off0) 673 } 674 675 type eventList []*Event 676 677 func (l eventList) Len() int { 678 return len(l) 679 } 680 681 func (l eventList) Less(i, j int) bool { 682 return l[i].Seq < l[j].Seq 683 } 684 685 func (l eventList) Swap(i, j int) { 686 l[i], l[j] = l[j], l[i] 687 } 688 689 // Print dumps events to stdout. For debugging. 690 func Print(events []*Event) { 691 for _, ev := range events { 692 desc := EventDescriptions[ev.Type] 693 fmt.Printf("%v %v p=%v g=%v off=%v", ev.Ts, desc.Name, ev.P, ev.G, ev.Off) 694 for i, a := range desc.Args { 695 fmt.Printf(" %v=%v", a, ev.Args[i]) 696 } 697 fmt.Printf("\n") 698 } 699 } 700 701 // Event types in the trace. 702 // Verbatim copy from src/runtime/trace.go. 703 const ( 704 EvNone = 0 // unused 705 EvBatch = 1 // start of per-P batch of events [pid, timestamp] 706 EvFrequency = 2 // contains tracer timer frequency [frequency (ticks per second)] 707 EvStack = 3 // stack [stack id, number of PCs, array of PCs] 708 EvGomaxprocs = 4 // current value of GOMAXPROCS [timestamp, GOMAXPROCS, stack id] 709 EvProcStart = 5 // start of P [timestamp, thread id] 710 EvProcStop = 6 // stop of P [timestamp] 711 EvGCStart = 7 // GC start [timestamp, stack id] 712 EvGCDone = 8 // GC done [timestamp] 713 EvGCScanStart = 9 // GC scan start [timestamp] 714 EvGCScanDone = 10 // GC scan done [timestamp] 715 EvGCSweepStart = 11 // GC sweep start [timestamp, stack id] 716 EvGCSweepDone = 12 // GC sweep done [timestamp] 717 EvGoCreate = 13 // goroutine creation [timestamp, new goroutine id, start PC, stack id] 718 EvGoStart = 14 // goroutine starts running [timestamp, goroutine id] 719 EvGoEnd = 15 // goroutine ends [timestamp] 720 EvGoStop = 16 // goroutine stops (like in select{}) [timestamp, stack] 721 EvGoSched = 17 // goroutine calls Gosched [timestamp, stack] 722 EvGoPreempt = 18 // goroutine is preempted [timestamp, stack] 723 EvGoSleep = 19 // goroutine calls Sleep [timestamp, stack] 724 EvGoBlock = 20 // goroutine blocks [timestamp, stack] 725 EvGoUnblock = 21 // goroutine is unblocked [timestamp, goroutine id, stack] 726 EvGoBlockSend = 22 // goroutine blocks on chan send [timestamp, stack] 727 EvGoBlockRecv = 23 // goroutine blocks on chan recv [timestamp, stack] 728 EvGoBlockSelect = 24 // goroutine blocks on select [timestamp, stack] 729 EvGoBlockSync = 25 // goroutine blocks on Mutex/RWMutex [timestamp, stack] 730 EvGoBlockCond = 26 // goroutine blocks on Cond [timestamp, stack] 731 EvGoBlockNet = 27 // goroutine blocks on network [timestamp, stack] 732 EvGoSysCall = 28 // syscall enter [timestamp, stack] 733 EvGoSysExit = 29 // syscall exit [timestamp, goroutine id, real timestamp] 734 EvGoSysBlock = 30 // syscall blocks [timestamp] 735 EvGoWaiting = 31 // denotes that goroutine is blocked when tracing starts [goroutine id] 736 EvGoInSyscall = 32 // denotes that goroutine is in syscall when tracing starts [goroutine id] 737 EvHeapAlloc = 33 // memstats.heap_alloc change [timestamp, heap_alloc] 738 EvNextGC = 34 // memstats.next_gc change [timestamp, next_gc] 739 EvTimerGoroutine = 35 // denotes timer goroutine [timer goroutine id] 740 EvFutileWakeup = 36 // denotes that the previous wakeup of this goroutine was futile [timestamp] 741 EvCount = 37 742 ) 743 744 var EventDescriptions = [EvCount]struct { 745 Name string 746 Stack bool 747 Args []string 748 }{ 749 EvNone: {"None", false, []string{}}, 750 EvBatch: {"Batch", false, []string{"p", "seq", "ticks"}}, 751 EvFrequency: {"Frequency", false, []string{"freq", "unused"}}, 752 EvStack: {"Stack", false, []string{"id", "siz"}}, 753 EvGomaxprocs: {"Gomaxprocs", true, []string{"procs"}}, 754 EvProcStart: {"ProcStart", false, []string{"thread"}}, 755 EvProcStop: {"ProcStop", false, []string{}}, 756 EvGCStart: {"GCStart", true, []string{}}, 757 EvGCDone: {"GCDone", false, []string{}}, 758 EvGCScanStart: {"GCScanStart", false, []string{}}, 759 EvGCScanDone: {"GCScanDone", false, []string{}}, 760 EvGCSweepStart: {"GCSweepStart", true, []string{}}, 761 EvGCSweepDone: {"GCSweepDone", false, []string{}}, 762 EvGoCreate: {"GoCreate", true, []string{"g", "pc"}}, 763 EvGoStart: {"GoStart", false, []string{"g"}}, 764 EvGoEnd: {"GoEnd", false, []string{}}, 765 EvGoStop: {"GoStop", true, []string{}}, 766 EvGoSched: {"GoSched", true, []string{}}, 767 EvGoPreempt: {"GoPreempt", true, []string{}}, 768 EvGoSleep: {"GoSleep", true, []string{}}, 769 EvGoBlock: {"GoBlock", true, []string{}}, 770 EvGoUnblock: {"GoUnblock", true, []string{"g"}}, 771 EvGoBlockSend: {"GoBlockSend", true, []string{}}, 772 EvGoBlockRecv: {"GoBlockRecv", true, []string{}}, 773 EvGoBlockSelect: {"GoBlockSelect", true, []string{}}, 774 EvGoBlockSync: {"GoBlockSync", true, []string{}}, 775 EvGoBlockCond: {"GoBlockCond", true, []string{}}, 776 EvGoBlockNet: {"GoBlockNet", true, []string{}}, 777 EvGoSysCall: {"GoSysCall", true, []string{}}, 778 EvGoSysExit: {"GoSysExit", false, []string{"g", "seq", "ts"}}, 779 EvGoSysBlock: {"GoSysBlock", false, []string{}}, 780 EvGoWaiting: {"GoWaiting", false, []string{"g"}}, 781 EvGoInSyscall: {"GoInSyscall", false, []string{"g"}}, 782 EvHeapAlloc: {"HeapAlloc", false, []string{"mem"}}, 783 EvNextGC: {"NextGC", false, []string{"mem"}}, 784 EvTimerGoroutine: {"TimerGoroutine", false, []string{"g", "unused"}}, 785 EvFutileWakeup: {"FutileWakeup", false, []string{}}, 786 } 787