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