[dev.garbage] Merge remote-tracking branch 'origin/master' into HEAD

Change-Id: I282fd9ce9db435dfd35e882a9502ab1abc185297

7 files changed, 702 insertions, 176 deletions

diff --git a/src/internal/trace/order.go b/src/internal/trace/order.go
new file mode 100644
index 0000000000..8ca2da52aa
--- /dev/null
+++ b/src/internal/trace/order.go
@@ -0,0 +1,278 @@
+// Copyright 2016 The Go Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style
+// license that can be found in the LICENSE file.
+
+package trace
+
+import (
+	"fmt"
+	"sort"
+)
+
+type eventBatch struct {
+	events   []*Event
+	selected bool
+}
+
+type orderEvent struct {
+	ev    *Event
+	batch int
+	g     uint64
+	init  gState
+	next  gState
+}
+
+type gStatus int
+
+type gState struct {
+	seq    uint64
+	status gStatus
+}
+
+const (
+	gDead gStatus = iota
+	gRunnable
+	gRunning
+	gWaiting
+
+	unordered = ^uint64(0)
+	garbage   = ^uint64(0) - 1
+	noseq     = ^uint64(0)
+	seqinc    = ^uint64(0) - 1
+)
+
+// order1007 merges a set of per-P event batches into a single, consistent stream.
+// The high level idea is as follows. Events within an individual batch are in
+// correct order, because they are emitted by a single P. So we need to produce
+// a correct interleaving of the batches. To do this we take first unmerged event
+// from each batch (frontier). Then choose subset that is "ready" to be merged,
+// that is, events for which all dependencies are already merged. Then we choose
+// event with the lowest timestamp from the subset, merge it and repeat.
+// This approach ensures that we form a consistent stream even if timestamps are
+// incorrect (condition observed on some machines).
+func order1007(m map[int][]*Event) (events []*Event, err error) {
+	pending := 0
+	var batches []*eventBatch
+	for _, v := range m {
+		pending += len(v)
+		batches = append(batches, &eventBatch{v, false})
+	}
+	gs := make(map[uint64]gState)
+	var frontier []orderEvent
+	for ; pending != 0; pending-- {
+		for i, b := range batches {
+			if b.selected || len(b.events) == 0 {
+				continue
+			}
+			ev := b.events[0]
+			g, init, next := stateTransition(ev)
+			if !transitionReady(g, gs[g], init) {
+				continue
+			}
+			frontier = append(frontier, orderEvent{ev, i, g, init, next})
+			b.events = b.events[1:]
+			b.selected = true
+			// Get rid of "Local" events, they are intended merely for ordering.
+			switch ev.Type {
+			case EvGoStartLocal:
+				ev.Type = EvGoStart
+			case EvGoUnblockLocal:
+				ev.Type = EvGoUnblock
+			case EvGoSysExitLocal:
+				ev.Type = EvGoSysExit
+			}
+		}
+		if len(frontier) == 0 {
+			return nil, fmt.Errorf("no consistent ordering of events possible")
+		}
+		sort.Sort(orderEventList(frontier))
+		f := frontier[0]
+		frontier[0] = frontier[len(frontier)-1]
+		frontier = frontier[:len(frontier)-1]
+		events = append(events, f.ev)
+		transition(gs, f.g, f.init, f.next)
+		if !batches[f.batch].selected {
+			panic("frontier batch is not selected")
+		}
+		batches[f.batch].selected = false
+	}
+
+	// At this point we have a consistent stream of events.
+	// Make sure time stamps respect the ordering.
+	// The tests will skip (not fail) the test case if they see this error.
+	if !sort.IsSorted(eventList(events)) {
+		return nil, ErrTimeOrder
+	}
+
+	// The last part is giving correct timestamps to EvGoSysExit events.
+	// The problem with EvGoSysExit is that actual syscall exit timestamp (ev.Args[2])
+	// is potentially acquired long before event emission. So far we've used
+	// timestamp of event emission (ev.Ts).
+	// We could not set ev.Ts = ev.Args[2] earlier, because it would produce
+	// seemingly broken timestamps (misplaced event).
+	// We also can't simply update the timestamp and resort events, because
+	// if timestamps are broken we will misplace the event and later report
+	// logically broken trace (instead of reporting broken timestamps).
+	lastSysBlock := make(map[uint64]int64)
+	for _, ev := range events {
+		switch ev.Type {
+		case EvGoSysBlock, EvGoInSyscall:
+			lastSysBlock[ev.G] = ev.Ts
+		case EvGoSysExit:
+			ts := int64(ev.Args[2])
+			if ts == 0 {
+				continue
+			}
+			block := lastSysBlock[ev.G]
+			if block == 0 {
+				return nil, fmt.Errorf("stray syscall exit")
+			}
+			if ts < block {
+				return nil, ErrTimeOrder
+			}
+			ev.Ts = ts
+		}
+	}
+	sort.Stable(eventList(events))
+
+	return
+}
+
+// stateTransition returns goroutine state (sequence and status) when the event
+// becomes ready for merging (init) and the goroutine state after the event (next).
+func stateTransition(ev *Event) (g uint64, init, next gState) {
+	switch ev.Type {
+	case EvGoCreate:
+		g = ev.Args[0]
+		init = gState{0, gDead}
+		next = gState{1, gRunnable}
+	case EvGoWaiting, EvGoInSyscall:
+		g = ev.G
+		init = gState{1, gRunnable}
+		next = gState{2, gWaiting}
+	case EvGoStart:
+		g = ev.G
+		init = gState{ev.Args[1], gRunnable}
+		next = gState{ev.Args[1] + 1, gRunning}
+	case EvGoStartLocal:
+		// noseq means that this event is ready for merging as soon as
+		// frontier reaches it (EvGoStartLocal is emitted on the same P
+		// as the corresponding EvGoCreate/EvGoUnblock, and thus the latter
+		// is already merged).
+		// seqinc is a stub for cases when event increments g sequence,
+		// but since we don't know current seq we also don't know next seq.
+		g = ev.G
+		init = gState{noseq, gRunnable}
+		next = gState{seqinc, gRunning}
+	case EvGoBlock, EvGoBlockSend, EvGoBlockRecv, EvGoBlockSelect,
+		EvGoBlockSync, EvGoBlockCond, EvGoBlockNet, EvGoSleep, EvGoSysBlock:
+		g = ev.G
+		init = gState{noseq, gRunning}
+		next = gState{noseq, gWaiting}
+	case EvGoSched, EvGoPreempt:
+		g = ev.G
+		init = gState{noseq, gRunning}
+		next = gState{noseq, gRunnable}
+	case EvGoUnblock, EvGoSysExit:
+		g = ev.Args[0]
+		init = gState{ev.Args[1], gWaiting}
+		next = gState{ev.Args[1] + 1, gRunnable}
+	case EvGoUnblockLocal, EvGoSysExitLocal:
+		g = ev.Args[0]
+		init = gState{noseq, gWaiting}
+		next = gState{seqinc, gRunnable}
+	case EvGCStart:
+		g = garbage
+		init = gState{ev.Args[0], gDead}
+		next = gState{ev.Args[0] + 1, gDead}
+	default:
+		// no ordering requirements
+		g = unordered
+	}
+	return
+}
+
+func transitionReady(g uint64, curr, init gState) bool {
+	return g == unordered || (init.seq == noseq || init.seq == curr.seq) && init.status == curr.status
+}
+
+func transition(gs map[uint64]gState, g uint64, init, next gState) {
+	if g == unordered {
+		return
+	}
+	curr := gs[g]
+	if !transitionReady(g, curr, init) {
+		panic("event sequences are broken")
+	}
+	switch next.seq {
+	case noseq:
+		next.seq = curr.seq
+	case seqinc:
+		next.seq = curr.seq + 1
+	}
+	gs[g] = next
+}
+
+// order1005 merges a set of per-P event batches into a single, consistent stream.
+func order1005(m map[int][]*Event) (events []*Event, err error) {
+	for _, batch := range m {
+		events = append(events, batch...)
+	}
+	for _, ev := range events {
+		if ev.Type == EvGoSysExit {
+			// EvGoSysExit emission is delayed until the thread has a P.
+			// Give it the real sequence number and time stamp.
+			ev.seq = int64(ev.Args[1])
+			if ev.Args[2] != 0 {
+				ev.Ts = int64(ev.Args[2])
+			}
+		}
+	}
+	sort.Sort(eventSeqList(events))
+	if !sort.IsSorted(eventList(events)) {
+		return nil, ErrTimeOrder
+	}
+	return
+}
+
+type orderEventList []orderEvent
+
+func (l orderEventList) Len() int {
+	return len(l)
+}
+
+func (l orderEventList) Less(i, j int) bool {
+	return l[i].ev.Ts < l[j].ev.Ts
+}
+
+func (l orderEventList) Swap(i, j int) {
+	l[i], l[j] = l[j], l[i]
+}
+
+type eventList []*Event
+
+func (l eventList) Len() int {
+	return len(l)
+}
+
+func (l eventList) Less(i, j int) bool {
+	return l[i].Ts < l[j].Ts
+}
+
+func (l eventList) Swap(i, j int) {
+	l[i], l[j] = l[j], l[i]
+}
+
+type eventSeqList []*Event
+
+func (l eventSeqList) Len() int {
+	return len(l)
+}
+
+func (l eventSeqList) Less(i, j int) bool {
+	return l[i].seq < l[j].seq
+}
+
+func (l eventSeqList) Swap(i, j int) {
+	l[i], l[j] = l[j], l[i]
+}
diff --git a/src/internal/trace/parser.go b/src/internal/trace/parser.go
index e325678733..843d0eaf63 100644
--- a/src/internal/trace/parser.go
+++ b/src/internal/trace/parser.go
@@ -9,18 +9,19 @@ import (
 	"bytes"
 	"fmt"
 	"io"
+	"math/rand"
 	"os"
 	"os/exec"
-	"sort"
 	"strconv"
 	"strings"
+	_ "unsafe"
 )
 
 // Event describes one event in the trace.
 type Event struct {
 	Off   int       // offset in input file (for debugging and error reporting)
 	Type  byte      // one of Ev*
-	Seq   int64     // sequence number
+	seq   int64     // sequence number
 	Ts    int64     // timestamp in nanoseconds
 	P     int       // P on which the event happened (can be one of TimerP, NetpollP, SyscallP)
 	G     uint64    // G on which the event happened
@@ -58,12 +59,12 @@ const (
 )
 
 // Parse parses, post-processes and verifies the trace.
-func Parse(r io.Reader) ([]*Event, error) {
-	rawEvents, err := readTrace(r)
+func Parse(r io.Reader, bin string) ([]*Event, error) {
+	ver, rawEvents, strings, err := readTrace(r)
 	if err != nil {
 		return nil, err
 	}
-	events, err := parseEvents(rawEvents)
+	events, stacks, err := parseEvents(ver, rawEvents, strings)
 	if err != nil {
 		return nil, err
 	}
@@ -71,10 +72,21 @@ func Parse(r io.Reader) ([]*Event, error) {
 	if err != nil {
 		return nil, err
 	}
-	err = postProcessTrace(events)
+	err = postProcessTrace(ver, events)
 	if err != nil {
 		return nil, err
 	}
+	// Attach stack traces.
+	for _, ev := range events {
+		if ev.StkID != 0 {
+			ev.Stk = stacks[ev.StkID]
+		}
+	}
+	if ver < 1007 && bin != "" {
+		if err := symbolize(events, bin); err != nil {
+			return nil, err
+		}
+	}
 	return events, nil
 }
 
@@ -87,107 +99,187 @@ type rawEvent struct {
 
 // readTrace does wire-format parsing and verification.
 // It does not care about specific event types and argument meaning.
-func readTrace(r io.Reader) ([]rawEvent, error) {
+func readTrace(r io.Reader) (ver int, events []rawEvent, strings map[uint64]string, err error) {
 	// Read and validate trace header.
 	var buf [16]byte
-	off, err := r.Read(buf[:])
-	if off != 16 || err != nil {
-		return nil, fmt.Errorf("failed to read header: read %v, err %v", off, err)
+	off, err := io.ReadFull(r, buf[:])
+	if err != nil {
+		err = fmt.Errorf("failed to read header: read %v, err %v", off, err)
+		return
 	}
-	if !bytes.Equal(buf[:], []byte("go 1.5 trace\x00\x00\x00\x00")) {
-		return nil, fmt.Errorf("not a trace file")
+	ver, err = parseHeader(buf[:])
+	if err != nil {
+		return
+	}
+	switch ver {
+	case 1005, 1007:
+		break
+	default:
+		err = fmt.Errorf("unsupported trace file version %v.%v (update Go toolchain) %v", ver/1000, ver%1000, ver)
+		return
 	}
 
 	// Read events.
-	var events []rawEvent
+	strings = make(map[uint64]string)
 	for {
 		// Read event type and number of arguments (1 byte).
 		off0 := off
-		n, err := r.Read(buf[:1])
+		var n int
+		n, err = r.Read(buf[:1])
 		if err == io.EOF {
+			err = nil
 			break
 		}
 		if err != nil || n != 1 {
-			return nil, fmt.Errorf("failed to read trace at offset 0x%x: n=%v err=%v", off0, n, err)
+			err = fmt.Errorf("failed to read trace at offset 0x%x: n=%v err=%v", off0, n, err)
+			return
 		}
 		off += n
 		typ := buf[0] << 2 >> 2
-		narg := buf[0] >> 6
+		narg := buf[0]>>6 + 1
+		inlineArgs := byte(4)
+		if ver < 1007 {
+			narg++
+			inlineArgs++
+		}
+		if typ == EvNone || typ >= EvCount || EventDescriptions[typ].minVersion > ver {
+			err = fmt.Errorf("unknown event type %v at offset 0x%x", typ, off0)
+			return
+		}
+		if typ == EvString {
+			// String dictionary entry [ID, length, string].
+			var id uint64
+			id, off, err = readVal(r, off)
+			if err != nil {
+				return
+			}
+			if id == 0 {
+				err = fmt.Errorf("string at offset %d has invalid id 0", off)
+				return
+			}
+			if strings[id] != "" {
+				err = fmt.Errorf("string at offset %d has duplicate id %v", off, id)
+				return
+			}
+			var ln uint64
+			ln, off, err = readVal(r, off)
+			if err != nil {
+				return
+			}
+			if ln == 0 {
+				err = fmt.Errorf("string at offset %d has invalid length 0", off)
+				return
+			}
+			if ln > 1e6 {
+				err = fmt.Errorf("string at offset %d has too large length %v", off, ln)
+				return
+			}
+			buf := make([]byte, ln)
+			var n int
+			n, err = io.ReadFull(r, buf)
+			if err != nil {
+				err = fmt.Errorf("failed to read trace at offset %d: read %v, want %v, error %v", off, n, ln, err)
+				return
+			}
+			off += n
+			strings[id] = string(buf)
+			continue
+		}
 		ev := rawEvent{typ: typ, off: off0}
-		if narg < 3 {
-			for i := 0; i < int(narg)+2; i++ { // sequence number and time stamp are present but not counted in narg
+		if narg < inlineArgs {
+			for i := 0; i < int(narg); i++ {
 				var v uint64
 				v, off, err = readVal(r, off)
 				if err != nil {
-					return nil, err
+					err = fmt.Errorf("failed to read event %v argument at offset %v (%v)", typ, off, err)
+					return
 				}
 				ev.args = append(ev.args, v)
 			}
 		} else {
-			// If narg == 3, the first value is length of the event in bytes.
+			// More than inlineArgs args, the first value is length of the event in bytes.
 			var v uint64
 			v, off, err = readVal(r, off)
 			if err != nil {
-				return nil, err
+				err = fmt.Errorf("failed to read event %v argument at offset %v (%v)", typ, off, err)
+				return
 			}
 			evLen := v
 			off1 := off
 			for evLen > uint64(off-off1) {
 				v, off, err = readVal(r, off)
 				if err != nil {
-					return nil, err
+					err = fmt.Errorf("failed to read event %v argument at offset %v (%v)", typ, off, err)
+					return
 				}
 				ev.args = append(ev.args, v)
 			}
 			if evLen != uint64(off-off1) {
-				return nil, fmt.Errorf("event has wrong length at offset 0x%x: want %v, got %v", off0, evLen, off-off1)
+				err = fmt.Errorf("event has wrong length at offset 0x%x: want %v, got %v", off0, evLen, off-off1)
+				return
 			}
 		}
 		events = append(events, ev)
 	}
-	return events, nil
+	return
+}
+
+// parseHeader parses trace header of the form "go 1.7 trace\x00\x00\x00\x00"
+// and returns parsed version as 1007.
+func parseHeader(buf []byte) (int, error) {
+	if len(buf) != 16 {
+		return 0, fmt.Errorf("bad header length")
+	}
+	if buf[0] != 'g' || buf[1] != 'o' || buf[2] != ' ' ||
+		buf[3] < '1' || buf[3] > '9' ||
+		buf[4] != '.' ||
+		buf[5] < '1' || buf[5] > '9' {
+		return 0, fmt.Errorf("not a trace file")
+	}
+	ver := int(buf[5] - '0')
+	i := 0
+	for ; buf[6+i] >= '0' && buf[6+i] <= '9' && i < 2; i++ {
+		ver = ver*10 + int(buf[6+i]-'0')
+	}
+	ver += int(buf[3]-'0') * 1000
+	if !bytes.Equal(buf[6+i:], []byte(" trace\x00\x00\x00\x00")[:10-i]) {
+		return 0, fmt.Errorf("not a trace file")
+	}
+	return ver, nil
 }
 
 // Parse events transforms raw events into events.
 // It does analyze and verify per-event-type arguments.
-func parseEvents(rawEvents []rawEvent) (events []*Event, err error) {
+func parseEvents(ver int, rawEvents []rawEvent, strings map[uint64]string) (events []*Event, stacks map[uint64][]*Frame, err error) {
 	var ticksPerSec, lastSeq, lastTs int64
 	var lastG, timerGoid uint64
 	var lastP int
 	lastGs := make(map[int]uint64) // last goroutine running on P
-	stacks := make(map[uint64][]*Frame)
+	stacks = make(map[uint64][]*Frame)
+	batches := make(map[int][]*Event) // events by P
 	for _, raw := range rawEvents {
-		if raw.typ == EvNone || raw.typ >= EvCount {
-			err = fmt.Errorf("unknown event type %v at offset 0x%x", raw.typ, raw.off)
-			return
-		}
 		desc := EventDescriptions[raw.typ]
 		if desc.Name == "" {
 			err = fmt.Errorf("missing description for event type %v", raw.typ)
 			return
 		}
-		if raw.typ != EvStack {
-			narg := len(desc.Args)
-			if desc.Stack {
-				narg++
-			}
-			if raw.typ != EvBatch && raw.typ != EvFrequency && raw.typ != EvTimerGoroutine {
-				narg++ // sequence number
-				narg++ // timestamp
-			}
-			if len(raw.args) != narg {
-				err = fmt.Errorf("%v has wrong number of arguments at offset 0x%x: want %v, got %v",
-					desc.Name, raw.off, narg, len(raw.args))
-				return
-			}
+		narg := argNum(raw, ver)
+		if len(raw.args) != narg {
+			err = fmt.Errorf("%v has wrong number of arguments at offset 0x%x: want %v, got %v",
+				desc.Name, raw.off, narg, len(raw.args))
+			return
 		}
 		switch raw.typ {
 		case EvBatch:
 			lastGs[lastP] = lastG
 			lastP = int(raw.args[0])
 			lastG = lastGs[lastP]
-			lastSeq = int64(raw.args[1])
-			lastTs = int64(raw.args[2])
+			if ver < 1007 {
+				lastSeq = int64(raw.args[1])
+				lastTs = int64(raw.args[2])
+			} else {
+				lastTs = int64(raw.args[1])
+			}
 		case EvFrequency:
 			ticksPerSec = int64(raw.args[0])
 			if ticksPerSec <= 0 {
@@ -211,33 +303,53 @@ func parseEvents(rawEvents []rawEvent) (events []*Event, err error) {
 					raw.off, size)
 				return
 			}
-			if uint64(len(raw.args)) != size+2 {
+			want := 2 + 4*size
+			if ver < 1007 {
+				want = 2 + size
+			}
+			if uint64(len(raw.args)) != want {
 				err = fmt.Errorf("EvStack has wrong number of arguments at offset 0x%x: want %v, got %v",
-					raw.off, size+2, len(raw.args))
+					raw.off, want, len(raw.args))
 				return
 			}
 			id := raw.args[0]
 			if id != 0 && size > 0 {
 				stk := make([]*Frame, size)
 				for i := 0; i < int(size); i++ {
-					stk[i] = &Frame{PC: raw.args[i+2]}
+					if ver < 1007 {
+						stk[i] = &Frame{PC: raw.args[2+i]}
+					} else {
+						pc := raw.args[2+i*4+0]
+						fn := raw.args[2+i*4+1]
+						file := raw.args[2+i*4+2]
+						line := raw.args[2+i*4+3]
+						stk[i] = &Frame{PC: pc, Fn: strings[fn], File: strings[file], Line: int(line)}
+					}
 				}
 				stacks[id] = stk
 			}
 		default:
 			e := &Event{Off: raw.off, Type: raw.typ, P: lastP, G: lastG}
-			e.Seq = lastSeq + int64(raw.args[0])
-			e.Ts = lastTs + int64(raw.args[1])
-			lastSeq = e.Seq
-			lastTs = e.Ts
-			for i := range desc.Args {
-				e.Args[i] = raw.args[i+2]
+			var argOffset int
+			if ver < 1007 {
+				e.seq = lastSeq + int64(raw.args[0])
+				e.Ts = lastTs + int64(raw.args[1])
+				lastSeq = e.seq
+				argOffset = 2
+			} else {
+				e.Ts = lastTs + int64(raw.args[0])
+				argOffset = 1
 			}
-			if desc.Stack {
-				e.StkID = raw.args[len(desc.Args)+2]
+			lastTs = e.Ts
+			for i := argOffset; i < narg; i++ {
+				if i == narg-1 && desc.Stack {
+					e.StkID = raw.args[i]
+				} else {
+					e.Args[i-argOffset] = raw.args[i]
+				}
 			}
 			switch raw.typ {
-			case EvGoStart:
+			case EvGoStart, EvGoStartLocal:
 				lastG = e.Args[0]
 				e.G = lastG
 			case EvGCStart, EvGCDone, EvGCScanStart, EvGCScanDone:
@@ -247,45 +359,51 @@ func parseEvents(rawEvents []rawEvent) (events []*Event, err error) {
 				EvGoBlockSelect, EvGoBlockSync, EvGoBlockCond, EvGoBlockNet,
 				EvGoSysBlock:
 				lastG = 0
-			case EvGoSysExit:
-				// EvGoSysExit emission is delayed until the thread has a P.
-				// Give it the real sequence number and time stamp.
-				e.Seq = int64(e.Args[1])
-				if e.Args[2] != 0 {
-					e.Ts = int64(e.Args[2])
-				}
+			case EvGoSysExit, EvGoWaiting, EvGoInSyscall:
+				e.G = e.Args[0]
 			}
-			events = append(events, e)
+			batches[lastP] = append(batches[lastP], e)
 		}
 	}
-	if len(events) == 0 {
+	if len(batches) == 0 {
 		err = fmt.Errorf("trace is empty")
 		return
 	}
-
-	// Attach stack traces.
-	for _, ev := range events {
-		if ev.StkID != 0 {
-			ev.Stk = stacks[ev.StkID]
-		}
-	}
-
-	// Sort by sequence number and translate cpu ticks to real time.
-	sort.Sort(eventList(events))
 	if ticksPerSec == 0 {
 		err = fmt.Errorf("no EvFrequency event")
 		return
 	}
+	if BreakTimestampsForTesting {
+		var batchArr [][]*Event
+		for _, batch := range batches {
+			batchArr = append(batchArr, batch)
+		}
+		for i := 0; i < 5; i++ {
+			batch := batchArr[rand.Intn(len(batchArr))]
+			batch[rand.Intn(len(batch))].Ts += int64(rand.Intn(2000) - 1000)
+		}
+	}
+	if ver < 1007 {
+		events, err = order1005(batches)
+	} else {
+		events, err = order1007(batches)
+	}
+	if err != nil {
+		return
+	}
+
+	// Translate cpu ticks to real time.
 	minTs := events[0].Ts
+	// Use floating point to avoid integer overflows.
+	freq := 1e9 / float64(ticksPerSec)
 	for _, ev := range events {
-		ev.Ts = (ev.Ts - minTs) * 1e9 / ticksPerSec
+		ev.Ts = int64(float64(ev.Ts-minTs) * freq)
 		// Move timers and syscalls to separate fake Ps.
 		if timerGoid != 0 && ev.G == timerGoid && ev.Type == EvGoUnblock {
 			ev.P = TimerP
 		}
 		if ev.Type == EvGoSysExit {
 			ev.P = SyscallP
-			ev.G = ev.Args[0]
 		}
 	}
 
@@ -355,7 +473,7 @@ var ErrTimeOrder = fmt.Errorf("time stamps out of order")
 // The resulting trace is guaranteed to be consistent
 // (for example, a P does not run two Gs at the same time, or a G is indeed
 // blocked before an unblock event).
-func postProcessTrace(events []*Event) error {
+func postProcessTrace(ver int, events []*Event) error {
 	const (
 		gDead = iota
 		gRunnable
@@ -446,19 +564,15 @@ func postProcessTrace(events []*Event) error {
 			p.evSweep.Link = ev
 			p.evSweep = nil
 		case EvGoWaiting:
-			g1 := gs[ev.Args[0]]
-			if g1.state != gRunnable {
-				return fmt.Errorf("g %v is not runnable before EvGoWaiting (offset %v, time %v)", ev.Args[0], ev.Off, ev.Ts)
+			if g.state != gRunnable {
+				return fmt.Errorf("g %v is not runnable before EvGoWaiting (offset %v, time %v)", ev.G, ev.Off, ev.Ts)
 			}
-			g1.state = gWaiting
-			gs[ev.Args[0]] = g1
+			g.state = gWaiting
 		case EvGoInSyscall:
-			g1 := gs[ev.Args[0]]
-			if g1.state != gRunnable {
-				return fmt.Errorf("g %v is not runnable before EvGoInSyscall (offset %v, time %v)", ev.Args[0], ev.Off, ev.Ts)
+			if g.state != gRunnable {
+				return fmt.Errorf("g %v is not runnable before EvGoInSyscall (offset %v, time %v)", ev.G, ev.Off, ev.Ts)
 			}
-			g1.state = gWaiting
-			gs[ev.Args[0]] = g1
+			g.state = gWaiting
 		case EvGoCreate:
 			if err := checkRunning(p, g, ev, true); err != nil {
 				return err
@@ -478,8 +592,12 @@ func postProcessTrace(events []*Event) error {
 			g.evStart = ev
 			p.g = ev.G
 			if g.evCreate != nil {
-				// +1 because symbolizer expects return pc.
-				ev.Stk = []*Frame{{PC: g.evCreate.Args[1] + 1}}
+				if ver < 1007 {
+					// +1 because symbolizer expects return pc.
+					ev.Stk = []*Frame{{PC: g.evCreate.Args[1] + 1}}
+				} else {
+					ev.StkID = g.evCreate.Args[1]
+				}
 				g.evCreate = nil
 			}
 
@@ -565,23 +683,11 @@ func postProcessTrace(events []*Event) error {
 	// TODO(dvyukov): restore stacks for EvGoStart events.
 	// TODO(dvyukov): test that all EvGoStart events has non-nil Link.
 
-	// Last, after all the other consistency checks,
-	// make sure time stamps respect sequence numbers.
-	// The tests will skip (not fail) the test case if they see this error,
-	// so check everything else that could possibly be wrong first.
-	lastTs := int64(0)
-	for _, ev := range events {
-		if ev.Ts < lastTs {
-			return ErrTimeOrder
-		}
-		lastTs = ev.Ts
-	}
-
 	return nil
 }
 
-// symbolizeTrace attaches func/file/line info to stack traces.
-func Symbolize(events []*Event, bin string) error {
+// symbolize attaches func/file/line info to stack traces.
+func symbolize(events []*Event, bin string) error {
 	// First, collect and dedup all pcs.
 	pcs := make(map[uint64]*Frame)
 	for _, ev := range events {
@@ -672,57 +778,81 @@ func readVal(r io.Reader, off0 int) (v uint64, off int, err error) {
 	return 0, 0, fmt.Errorf("bad value at offset 0x%x", off0)
 }
 
-type eventList []*Event
-
-func (l eventList) Len() int {
-	return len(l)
-}
-
-func (l eventList) Less(i, j int) bool {
-	return l[i].Seq < l[j].Seq
+// Print dumps events to stdout. For debugging.
+func Print(events []*Event) {
+	for _, ev := range events {
+		PrintEvent(ev)
+	}
 }
 
-func (l eventList) Swap(i, j int) {
-	l[i], l[j] = l[j], l[i]
+// PrintEvent dumps the event to stdout. For debugging.
+func PrintEvent(ev *Event) {
+	desc := EventDescriptions[ev.Type]
+	fmt.Printf("%v %v p=%v g=%v off=%v", ev.Ts, desc.Name, ev.P, ev.G, ev.Off)
+	for i, a := range desc.Args {
+		fmt.Printf(" %v=%v", a, ev.Args[i])
+	}
+	fmt.Printf("\n")
 }
 
-// Print dumps events to stdout. For debugging.
-func Print(events []*Event) {
-	for _, ev := range events {
-		desc := EventDescriptions[ev.Type]
-		fmt.Printf("%v %v p=%v g=%v off=%v", ev.Ts, desc.Name, ev.P, ev.G, ev.Off)
-		for i, a := range desc.Args {
-			fmt.Printf(" %v=%v", a, ev.Args[i])
+// argNum returns total number of args for the event accounting for timestamps,
+// sequence numbers and differences between trace format versions.
+func argNum(raw rawEvent, ver int) int {
+	desc := EventDescriptions[raw.typ]
+	if raw.typ == EvStack {
+		return len(raw.args)
+	}
+	narg := len(desc.Args)
+	if desc.Stack {
+		narg++
+	}
+	switch raw.typ {
+	case EvBatch, EvFrequency, EvTimerGoroutine:
+		if ver < 1007 {
+			narg++ // there was an unused arg before 1.7
+		}
+	case EvGCStart, EvGoStart, EvGoUnblock:
+		if ver < 1007 {
+			narg-- // 1.7 added an additional seq arg
+		}
+		fallthrough
+	default:
+		narg++ // timestamp
+		if ver < 1007 {
+			narg++ // sequence
 		}
-		fmt.Printf("\n")
 	}
+	return narg
 }
 
+// BreakTimestampsForTesting causes the parser to randomly alter timestamps (for testing of broken cputicks).
+var BreakTimestampsForTesting bool
+
 // Event types in the trace.
 // Verbatim copy from src/runtime/trace.go.
 const (
 	EvNone           = 0  // unused
 	EvBatch          = 1  // start of per-P batch of events [pid, timestamp]
 	EvFrequency      = 2  // contains tracer timer frequency [frequency (ticks per second)]
-	EvStack          = 3  // stack [stack id, number of PCs, array of PCs]
+	EvStack          = 3  // stack [stack id, number of PCs, array of {PC, func string ID, file string ID, line}]
 	EvGomaxprocs     = 4  // current value of GOMAXPROCS [timestamp, GOMAXPROCS, stack id]
 	EvProcStart      = 5  // start of P [timestamp, thread id]
 	EvProcStop       = 6  // stop of P [timestamp]
-	EvGCStart        = 7  // GC start [timestamp, stack id]
+	EvGCStart        = 7  // GC start [timestamp, seq, stack id]
 	EvGCDone         = 8  // GC done [timestamp]
 	EvGCScanStart    = 9  // GC scan start [timestamp]
 	EvGCScanDone     = 10 // GC scan done [timestamp]
 	EvGCSweepStart   = 11 // GC sweep start [timestamp, stack id]
 	EvGCSweepDone    = 12 // GC sweep done [timestamp]
-	EvGoCreate       = 13 // goroutine creation [timestamp, new goroutine id, start PC, stack id]
-	EvGoStart        = 14 // goroutine starts running [timestamp, goroutine id]
+	EvGoCreate       = 13 // goroutine creation [timestamp, new goroutine id, new stack id, stack id]
+	EvGoStart        = 14 // goroutine starts running [timestamp, goroutine id, seq]
 	EvGoEnd          = 15 // goroutine ends [timestamp]
 	EvGoStop         = 16 // goroutine stops (like in select{}) [timestamp, stack]
 	EvGoSched        = 17 // goroutine calls Gosched [timestamp, stack]
 	EvGoPreempt      = 18 // goroutine is preempted [timestamp, stack]
 	EvGoSleep        = 19 // goroutine calls Sleep [timestamp, stack]
 	EvGoBlock        = 20 // goroutine blocks [timestamp, stack]
-	EvGoUnblock      = 21 // goroutine is unblocked [timestamp, goroutine id, stack]
+	EvGoUnblock      = 21 // goroutine is unblocked [timestamp, goroutine id, seq, stack]
 	EvGoBlockSend    = 22 // goroutine blocks on chan send [timestamp, stack]
 	EvGoBlockRecv    = 23 // goroutine blocks on chan recv [timestamp, stack]
 	EvGoBlockSelect  = 24 // goroutine blocks on select [timestamp, stack]
@@ -730,57 +860,66 @@ const (
 	EvGoBlockCond    = 26 // goroutine blocks on Cond [timestamp, stack]
 	EvGoBlockNet     = 27 // goroutine blocks on network [timestamp, stack]
 	EvGoSysCall      = 28 // syscall enter [timestamp, stack]
-	EvGoSysExit      = 29 // syscall exit [timestamp, goroutine id, real timestamp]
+	EvGoSysExit      = 29 // syscall exit [timestamp, goroutine id, seq, real timestamp]
 	EvGoSysBlock     = 30 // syscall blocks [timestamp]
-	EvGoWaiting      = 31 // denotes that goroutine is blocked when tracing starts [goroutine id]
-	EvGoInSyscall    = 32 // denotes that goroutine is in syscall when tracing starts [goroutine id]
-	EvHeapAlloc      = 33 // memstats.heap_alloc change [timestamp, heap_alloc]
+	EvGoWaiting      = 31 // denotes that goroutine is blocked when tracing starts [timestamp, goroutine id]
+	EvGoInSyscall    = 32 // denotes that goroutine is in syscall when tracing starts [timestamp, goroutine id]
+	EvHeapAlloc      = 33 // memstats.heap_live change [timestamp, heap_alloc]
 	EvNextGC         = 34 // memstats.next_gc change [timestamp, next_gc]
 	EvTimerGoroutine = 35 // denotes timer goroutine [timer goroutine id]
 	EvFutileWakeup   = 36 // denotes that the previous wakeup of this goroutine was futile [timestamp]
-	EvCount          = 37
+	EvString         = 37 // string dictionary entry [ID, length, string]
+	EvGoStartLocal   = 38 // goroutine starts running on the same P as the last event [timestamp, goroutine id]
+	EvGoUnblockLocal = 39 // goroutine is unblocked on the same P as the last event [timestamp, goroutine id, stack]
+	EvGoSysExitLocal = 40 // syscall exit on the same P as the last event [timestamp, goroutine id, real timestamp]
+	EvCount          = 41
 )
 
 var EventDescriptions = [EvCount]struct {
-	Name  string
-	Stack bool
-	Args  []string
+	Name       string
+	minVersion int
+	Stack      bool
+	Args       []string
 }{
-	EvNone:           {"None", false, []string{}},
-	EvBatch:          {"Batch", false, []string{"p", "seq", "ticks"}},
-	EvFrequency:      {"Frequency", false, []string{"freq", "unused"}},
-	EvStack:          {"Stack", false, []string{"id", "siz"}},
-	EvGomaxprocs:     {"Gomaxprocs", true, []string{"procs"}},
-	EvProcStart:      {"ProcStart", false, []string{"thread"}},
-	EvProcStop:       {"ProcStop", false, []string{}},
-	EvGCStart:        {"GCStart", true, []string{}},
-	EvGCDone:         {"GCDone", false, []string{}},
-	EvGCScanStart:    {"GCScanStart", false, []string{}},
-	EvGCScanDone:     {"GCScanDone", false, []string{}},
-	EvGCSweepStart:   {"GCSweepStart", true, []string{}},
-	EvGCSweepDone:    {"GCSweepDone", false, []string{}},
-	EvGoCreate:       {"GoCreate", true, []string{"g", "pc"}},
-	EvGoStart:        {"GoStart", false, []string{"g"}},
-	EvGoEnd:          {"GoEnd", false, []string{}},
-	EvGoStop:         {"GoStop", true, []string{}},
-	EvGoSched:        {"GoSched", true, []string{}},
-	EvGoPreempt:      {"GoPreempt", true, []string{}},
-	EvGoSleep:        {"GoSleep", true, []string{}},
-	EvGoBlock:        {"GoBlock", true, []string{}},
-	EvGoUnblock:      {"GoUnblock", true, []string{"g"}},
-	EvGoBlockSend:    {"GoBlockSend", true, []string{}},
-	EvGoBlockRecv:    {"GoBlockRecv", true, []string{}},
-	EvGoBlockSelect:  {"GoBlockSelect", true, []string{}},
-	EvGoBlockSync:    {"GoBlockSync", true, []string{}},
-	EvGoBlockCond:    {"GoBlockCond", true, []string{}},
-	EvGoBlockNet:     {"GoBlockNet", true, []string{}},
-	EvGoSysCall:      {"GoSysCall", true, []string{}},
-	EvGoSysExit:      {"GoSysExit", false, []string{"g", "seq", "ts"}},
-	EvGoSysBlock:     {"GoSysBlock", false, []string{}},
-	EvGoWaiting:      {"GoWaiting", false, []string{"g"}},
-	EvGoInSyscall:    {"GoInSyscall", false, []string{"g"}},
-	EvHeapAlloc:      {"HeapAlloc", false, []string{"mem"}},
-	EvNextGC:         {"NextGC", false, []string{"mem"}},
-	EvTimerGoroutine: {"TimerGoroutine", false, []string{"g", "unused"}},
-	EvFutileWakeup:   {"FutileWakeup", false, []string{}},
+	EvNone:           {"None", 1005, false, []string{}},
+	EvBatch:          {"Batch", 1005, false, []string{"p", "ticks"}}, // in 1.5 format it was {"p", "seq", "ticks"}
+	EvFrequency:      {"Frequency", 1005, false, []string{"freq"}},   // in 1.5 format it was {"freq", "unused"}
+	EvStack:          {"Stack", 1005, false, []string{"id", "siz"}},
+	EvGomaxprocs:     {"Gomaxprocs", 1005, true, []string{"procs"}},
+	EvProcStart:      {"ProcStart", 1005, false, []string{"thread"}},
+	EvProcStop:       {"ProcStop", 1005, false, []string{}},
+	EvGCStart:        {"GCStart", 1005, true, []string{"seq"}}, // in 1.5 format it was {}
+	EvGCDone:         {"GCDone", 1005, false, []string{}},
+	EvGCScanStart:    {"GCScanStart", 1005, false, []string{}},
+	EvGCScanDone:     {"GCScanDone", 1005, false, []string{}},
+	EvGCSweepStart:   {"GCSweepStart", 1005, true, []string{}},
+	EvGCSweepDone:    {"GCSweepDone", 1005, false, []string{}},
+	EvGoCreate:       {"GoCreate", 1005, true, []string{"g", "stack"}},
+	EvGoStart:        {"GoStart", 1005, false, []string{"g", "seq"}}, // in 1.5 format it was {"g"}
+	EvGoEnd:          {"GoEnd", 1005, false, []string{}},
+	EvGoStop:         {"GoStop", 1005, true, []string{}},
+	EvGoSched:        {"GoSched", 1005, true, []string{}},
+	EvGoPreempt:      {"GoPreempt", 1005, true, []string{}},
+	EvGoSleep:        {"GoSleep", 1005, true, []string{}},
+	EvGoBlock:        {"GoBlock", 1005, true, []string{}},
+	EvGoUnblock:      {"GoUnblock", 1005, true, []string{"g", "seq"}}, // in 1.5 format it was {"g"}
+	EvGoBlockSend:    {"GoBlockSend", 1005, true, []string{}},
+	EvGoBlockRecv:    {"GoBlockRecv", 1005, true, []string{}},
+	EvGoBlockSelect:  {"GoBlockSelect", 1005, true, []string{}},
+	EvGoBlockSync:    {"GoBlockSync", 1005, true, []string{}},
+	EvGoBlockCond:    {"GoBlockCond", 1005, true, []string{}},
+	EvGoBlockNet:     {"GoBlockNet", 1005, true, []string{}},
+	EvGoSysCall:      {"GoSysCall", 1005, true, []string{}},
+	EvGoSysExit:      {"GoSysExit", 1005, false, []string{"g", "seq", "ts"}},
+	EvGoSysBlock:     {"GoSysBlock", 1005, false, []string{}},
+	EvGoWaiting:      {"GoWaiting", 1005, false, []string{"g"}},
+	EvGoInSyscall:    {"GoInSyscall", 1005, false, []string{"g"}},
+	EvHeapAlloc:      {"HeapAlloc", 1005, false, []string{"mem"}},
+	EvNextGC:         {"NextGC", 1005, false, []string{"mem"}},
+	EvTimerGoroutine: {"TimerGoroutine", 1005, false, []string{"g"}}, // in 1.5 format it was {"g", "unused"}
+	EvFutileWakeup:   {"FutileWakeup", 1005, false, []string{}},
+	EvString:         {"String", 1007, false, []string{}},
+	EvGoStartLocal:   {"GoStartLocal", 1007, false, []string{"g"}},
+	EvGoUnblockLocal: {"GoUnblockLocal", 1007, true, []string{"g"}},
+	EvGoSysExitLocal: {"GoSysExitLocal", 1007, false, []string{"g", "ts"}},
 }
diff --git a/src/internal/trace/parser_test.go b/src/internal/trace/parser_test.go
index fecefc4053..340f106484 100644
--- a/src/internal/trace/parser_test.go
+++ b/src/internal/trace/parser_test.go
@@ -5,6 +5,9 @@
 package trace
 
 import (
+	"bytes"
+	"io/ioutil"
+	"path/filepath"
 	"strings"
 	"testing"
 )
@@ -22,9 +25,115 @@ func TestCorruptedInputs(t *testing.T) {
 		"go 1.5 trace\x00\x00\x00\x00\xc3\x0200",
 	}
 	for _, data := range tests {
-		events, err := Parse(strings.NewReader(data))
+		events, err := Parse(strings.NewReader(data), "")
 		if err == nil || events != nil {
-			t.Fatalf("no error on input: %q\n", data)
+			t.Fatalf("no error on input: %q", data)
 		}
 	}
 }
+
+func TestParseCanned(t *testing.T) {
+	files, err := ioutil.ReadDir("./testdata")
+	if err != nil {
+		t.Fatalf("failed to read ./testdata: %v", err)
+	}
+	for _, f := range files {
+		data, err := ioutil.ReadFile(filepath.Join("./testdata", f.Name()))
+		if err != nil {
+			t.Fatalf("failed to read input file: %v", err)
+		}
+		_, err = Parse(bytes.NewReader(data), "")
+		switch {
+		case strings.HasSuffix(f.Name(), "_good"):
+			if err != nil {
+				t.Errorf("failed to parse good trace %v: %v", f.Name(), err)
+			}
+		case strings.HasSuffix(f.Name(), "_unordered"):
+			if err != ErrTimeOrder {
+				t.Errorf("unordered trace is not detected %v: %v", f.Name(), err)
+			}
+		default:
+			t.Errorf("unknown input file suffix: %v", f.Name())
+		}
+	}
+}
+
+func TestParseVersion(t *testing.T) {
+	tests := map[string]int{
+		"go 1.5 trace\x00\x00\x00\x00": 1005,
+		"go 1.7 trace\x00\x00\x00\x00": 1007,
+		"go 1.10 trace\x00\x00\x00":    1010,
+		"go 1.25 trace\x00\x00\x00":    1025,
+		"go 1.234 trace\x00\x00":       1234,
+		"go 1.2345 trace\x00":          -1,
+		"go 0.0 trace\x00\x00\x00\x00": -1,
+		"go a.b trace\x00\x00\x00\x00": -1,
+	}
+	for header, ver := range tests {
+		ver1, err := parseHeader([]byte(header))
+		if ver == -1 {
+			if err == nil {
+				t.Fatalf("no error on input: %q, version %v", header, ver1)
+			}
+		} else {
+			if err != nil {
+				t.Fatalf("failed to parse: %q (%v)", header, err)
+			}
+			if ver != ver1 {
+				t.Fatalf("wrong version: %v, want %v, input: %q", ver1, ver, header)
+			}
+		}
+	}
+}
+
+func TestTimestampOverflow(t *testing.T) {
+	// Test that parser correctly handles large timestamps (long tracing).
+	w := newWriter()
+	w.emit(EvBatch, 0, 0)
+	w.emit(EvFrequency, 1e9)
+	for ts := uint64(1); ts < 1e16; ts *= 2 {
+		w.emit(EvGoCreate, ts, ts, 0, 0)
+	}
+	if _, err := Parse(w, ""); err != nil {
+		t.Fatalf("failed to parse: %v", err)
+	}
+}
+
+type writer struct {
+	bytes.Buffer
+}
+
+func newWriter() *writer {
+	w := new(writer)
+	w.Write([]byte("go 1.7 trace\x00\x00\x00\x00"))
+	return w
+}
+
+func (w *writer) emit(typ byte, args ...uint64) {
+	nargs := byte(len(args)) - 1
+	if nargs > 3 {
+		nargs = 3
+	}
+	buf := []byte{typ | nargs<<6}
+	if nargs == 3 {
+		buf = append(buf, 0)
+	}
+	for _, a := range args {
+		buf = appendVarint(buf, a)
+	}
+	if nargs == 3 {
+		buf[1] = byte(len(buf) - 2)
+	}
+	n, err := w.Write(buf)
+	if n != len(buf) || err != nil {
+		panic("failed to write")
+	}
+}
+
+func appendVarint(buf []byte, v uint64) []byte {
+	for ; v >= 0x80; v >>= 7 {
+		buf = append(buf, 0x80|byte(v))
+	}
+	buf = append(buf, byte(v))
+	return buf
+}
diff --git a/src/internal/trace/testdata/http_1_5_good b/src/internal/trace/testdata/http_1_5_good
new file mode 100644
index 0000000000..0736cae674
--- /dev/null
+++ b/src/internal/trace/testdata/http_1_5_good
diff --git a/src/internal/trace/testdata/stress_1_5_good b/src/internal/trace/testdata/stress_1_5_good
new file mode 100644
index 0000000000..c5055ebd19
--- /dev/null
+++ b/src/internal/trace/testdata/stress_1_5_good
diff --git a/src/internal/trace/testdata/stress_1_5_unordered b/src/internal/trace/testdata/stress_1_5_unordered
new file mode 100644
index 0000000000..11f7d745ca
--- /dev/null
+++ b/src/internal/trace/testdata/stress_1_5_unordered
diff --git a/src/internal/trace/testdata/stress_start_stop_1_5_good b/src/internal/trace/testdata/stress_start_stop_1_5_good
new file mode 100644
index 0000000000..72a887b844
--- /dev/null
+++ b/src/internal/trace/testdata/stress_start_stop_1_5_good