summaryrefslogtreecommitdiff
path: root/src/internal/trace
diff options
context:
space:
mode:
Diffstat (limited to 'src/internal/trace')
-rw-r--r--src/internal/trace/parser.go74
-rw-r--r--src/internal/trace/parser_test.go4
2 files changed, 51 insertions, 27 deletions
diff --git a/src/internal/trace/parser.go b/src/internal/trace/parser.go
index bfe6b73015..294a52f976 100644
--- a/src/internal/trace/parser.go
+++ b/src/internal/trace/parser.go
@@ -20,12 +20,13 @@ import (
type Event struct {
Off int // offset in input file (for debugging and error reporting)
Type byte // one of Ev*
+ 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
StkID uint64 // unique stack ID
Stk []*Frame // stack trace (can be empty)
- Args [2]uint64 // event-type-specific arguments
+ Args [3]uint64 // event-type-specific arguments
// linked event (can be nil), depends on event type:
// for GCStart: the GCStop
// for GCScanStart: the GCScanDone
@@ -88,12 +89,12 @@ type rawEvent struct {
// It does not care about specific event types and argument meaning.
func readTrace(r io.Reader) ([]rawEvent, error) {
// Read and validate trace header.
- var buf [8]byte
+ var buf [16]byte
off, err := r.Read(buf[:])
- if off != 8 || err != nil {
+ if off != 16 || err != nil {
return nil, fmt.Errorf("failed to read header: read %v, err %v", off, err)
}
- if bytes.Compare(buf[:], []byte("gotrace\x00")) != 0 {
+ if bytes.Compare(buf[:], []byte("go 1.5 trace\x00\x00\x00\x00")) != 0 {
return nil, fmt.Errorf("not a trace file")
}
@@ -111,10 +112,10 @@ func readTrace(r io.Reader) ([]rawEvent, error) {
}
off += n
typ := buf[0] << 2 >> 2
- narg := buf[0]>>6 + 1
+ narg := buf[0] >> 6
ev := rawEvent{typ: typ, off: off0}
- if narg <= 3 {
- for i := 0; i < int(narg); i++ {
+ if narg < 3 {
+ for i := 0; i < int(narg)+2; i++ { // sequence number and time stamp are present but not counted in narg
var v uint64
v, off, err = readVal(r, off)
if err != nil {
@@ -123,7 +124,7 @@ func readTrace(r io.Reader) ([]rawEvent, error) {
ev.args = append(ev.args, v)
}
} else {
- // If narg == 4, the first value is length of the event in bytes.
+ // If narg == 3, the first value is length of the event in bytes.
var v uint64
v, off, err = readVal(r, off)
if err != nil {
@@ -150,7 +151,7 @@ func readTrace(r io.Reader) ([]rawEvent, error) {
// Parse events transforms raw events into events.
// It does analyze and verify per-event-type arguments.
func parseEvents(rawEvents []rawEvent) (events []*Event, err error) {
- var ticksPerSec, lastTs int64
+ var ticksPerSec, lastSeq, lastTs int64
var lastG, timerGoid uint64
var lastP int
lastGs := make(map[int]uint64) // last goroutine running on P
@@ -171,6 +172,7 @@ func parseEvents(rawEvents []rawEvent) (events []*Event, err error) {
narg++
}
if raw.typ != EvBatch && raw.typ != EvFrequency && raw.typ != EvTimerGoroutine {
+ narg++ // sequence number
narg++ // timestamp
}
if len(raw.args) != narg {
@@ -184,7 +186,8 @@ func parseEvents(rawEvents []rawEvent) (events []*Event, err error) {
lastGs[lastP] = lastG
lastP = int(raw.args[0])
lastG = lastGs[lastP]
- lastTs = int64(raw.args[1])
+ lastSeq = int64(raw.args[1])
+ lastTs = int64(raw.args[2])
case EvFrequency:
ticksPerSec = int64(raw.args[0])
if ticksPerSec <= 0 {
@@ -221,13 +224,15 @@ func parseEvents(rawEvents []rawEvent) (events []*Event, err error) {
}
default:
e := &Event{Off: raw.off, Type: raw.typ, P: lastP, G: lastG}
- e.Ts = lastTs + int64(raw.args[0])
+ 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+1]
+ e.Args[i] = raw.args[i+2]
}
if desc.Stack {
- e.StkID = raw.args[len(desc.Args)+1]
+ e.StkID = raw.args[len(desc.Args)+2]
}
switch raw.typ {
case EvGoStart:
@@ -241,10 +246,11 @@ func parseEvents(rawEvents []rawEvent) (events []*Event, err error) {
EvGoSysBlock:
lastG = 0
case EvGoSysExit:
- if e.Args[1] != 0 {
- // EvGoSysExit emission is delayed until the thread has a P.
- // Give it the real timestamp.
- e.Ts = int64(e.Args[1])
+ // 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])
}
}
events = append(events, e)
@@ -262,10 +268,8 @@ func parseEvents(rawEvents []rawEvent) (events []*Event, err error) {
}
}
- // Sort by time and translate cpu ticks to real time.
- // Use stable sort because adjacent events in a batch can have the same timestamp
- // (this was observed on some VMs).
- sort.Stable(eventList(events))
+ // 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
@@ -341,6 +345,10 @@ func removeFutile(events []*Event) ([]*Event, error) {
return newEvents, nil
}
+// ErrTimeOrder is returned by Parse when the trace contains
+// time stamps that do not respect actual event ordering.
+var ErrTimeOrder = fmt.Errorf("time stamps out of order")
+
// postProcessTrace does inter-event verification and information restoration.
// 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
@@ -555,6 +563,18 @@ 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
}
@@ -639,7 +659,7 @@ func readVal(r io.Reader, off0 int) (v uint64, off int, err error) {
var n int
n, err = r.Read(buf[:])
if err != nil || n != 1 {
- return 0, 0, fmt.Errorf("failed to read trace at offset: read %v, error %v", off0, n, err)
+ return 0, 0, fmt.Errorf("failed to read trace at offset %d: read %v, error %v", off0, n, err)
}
off++
v |= uint64(buf[0]&0x7f) << (uint(i) * 7)
@@ -657,7 +677,7 @@ func (l eventList) Len() int {
}
func (l eventList) Less(i, j int) bool {
- return l[i].Ts < l[j].Ts
+ return l[i].Seq < l[j].Seq
}
func (l eventList) Swap(i, j int) {
@@ -725,8 +745,8 @@ var EventDescriptions = [EvCount]struct {
Args []string
}{
EvNone: {"None", false, []string{}},
- EvBatch: {"Batch", false, []string{"p", "ticks"}},
- EvFrequency: {"Frequency", false, []string{"freq"}},
+ 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"}},
@@ -753,12 +773,12 @@ var EventDescriptions = [EvCount]struct {
EvGoBlockCond: {"GoBlockCond", true, []string{}},
EvGoBlockNet: {"GoBlockNet", true, []string{}},
EvGoSysCall: {"GoSysCall", true, []string{}},
- EvGoSysExit: {"GoSysExit", false, []string{"g", "ts"}},
+ 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"}},
+ EvTimerGoroutine: {"TimerGoroutine", false, []string{"g", "unused"}},
EvFutileWakeup: {"FutileWakeup", false, []string{}},
}
diff --git a/src/internal/trace/parser_test.go b/src/internal/trace/parser_test.go
index 7d066e86fe..0eeb3e600e 100644
--- a/src/internal/trace/parser_test.go
+++ b/src/internal/trace/parser_test.go
@@ -16,6 +16,10 @@ func TestCorruptedInputs(t *testing.T) {
"gotrace\x00Q00\x020",
"gotrace\x00T00\x020",
"gotrace\x00\xc3\x0200",
+ "go 1.5 trace\x00\x00\x00\x00\x020",
+ "go 1.5 trace\x00\x00\x00\x00Q00\x020",
+ "go 1.5 trace\x00\x00\x00\x00T00\x020",
+ "go 1.5 trace\x00\x00\x00\x00\xc3\x0200",
}
for _, data := range tests {
events, err := Parse(strings.NewReader(data))
View Lorry Controller Status