internal/trace: remove backlinks from span/task end to start

This is an updated version of golang.org/cl/96395, with the fix to
TestUserSpan.

This reverts commit 7b6f6267e90a8e4eab37a3f2164ba882e6222adb.

Change-Id: I31eec8ba0997f9178dffef8dac608e731ab70872
Reviewed-on: https://go-review.googlesource.com/98236
Run-TryBot: Hyang-Ah Hana Kim <hyangah@gmail.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Heschi Kreinick <heschi@google.com>

src/cmd/trace/annotations.go

@@ -152,6 +152,65 @@ type annotationAnalysisResult struct {
 	gcEvents []*trace.Event       // GCStartevents, sorted
 }
 
+type activeSpanTracker struct {
+	stacks map[uint64][]*trace.Event // goid to stack of active span start events
+}
+
+func (t *activeSpanTracker) top(goid uint64) *trace.Event {
+	if t.stacks == nil {
+		return nil
+	}
+	stk := t.stacks[goid]
+	if len(stk) == 0 {
+		return nil
+	}
+	return stk[len(stk)-1]
+}
+
+func (t *activeSpanTracker) addSpanEvent(ev *trace.Event, task *taskDesc) *spanDesc {
+	if ev.Type != trace.EvUserSpan {
+		return nil
+	}
+	if t.stacks == nil {
+		t.stacks = make(map[uint64][]*trace.Event)
+	}
+
+	goid := ev.G
+	stk := t.stacks[goid]
+
+	var sd *spanDesc
+	switch mode := ev.Args[1]; mode {
+	case 0: // span start
+		t.stacks[goid] = append(stk, ev) // push
+		sd = &spanDesc{
+			name:  ev.SArgs[0],
+			task:  task,
+			goid:  goid,
+			start: ev,
+			end:   ev.Link,
+		}
+	case 1: // span end
+		if n := len(stk); n > 0 {
+			stk = stk[:n-1] // pop
+		} else {
+			// There is no matching span start event; can happen if the span start was before tracing.
+			sd = &spanDesc{
+				name:  ev.SArgs[0],
+				task:  task,
+				goid:  goid,
+				start: nil,
+				end:   ev,
+			}
+		}
+		if len(stk) == 0 {
+			delete(t.stacks, goid)
+		} else {
+			t.stacks[goid] = stk
+		}
+	}
+	return sd
+}
+
 // analyzeAnnotations analyzes user annotation events and
 // returns the task descriptors keyed by internal task id.
 func analyzeAnnotations() (annotationAnalysisResult, error) {
@@ -166,14 +225,14 @@ func analyzeAnnotations() (annotationAnalysisResult, error) {
 	}
 
 	tasks := allTasks{}
-	activeSpans := map[uint64][]*trace.Event{} // goid to active span start events
 	var gcEvents []*trace.Event
+	var activeSpans activeSpanTracker
 
 	for _, ev := range events {
 		goid := ev.G
 
 		switch typ := ev.Type; typ {
-		case trace.EvUserTaskCreate, trace.EvUserTaskEnd, trace.EvUserLog, trace.EvUserSpan:
+		case trace.EvUserTaskCreate, trace.EvUserTaskEnd, trace.EvUserLog:
 			taskid := ev.Args[0]
 			task := tasks.task(taskid)
 			task.addEvent(ev)
@@ -189,18 +248,13 @@ func analyzeAnnotations() (annotationAnalysisResult, error) {
 				}
 			}
 
-			if typ == trace.EvUserSpan {
-				mode := ev.Args[1]
-				spans := activeSpans[goid]
-				if mode == 0 { // start
-					activeSpans[goid] = append(spans, ev) // push
-				} else { // end
-					if n := len(spans); n > 1 {
-						activeSpans[goid] = spans[:n-1] // pop
-					} else if n == 1 {
-						delete(activeSpans, goid)
-					}
-				}
+		case trace.EvUserSpan:
+			taskid := ev.Args[0]
+			task := tasks.task(taskid)
+			task.addEvent(ev)
+			sd := activeSpans.addSpanEvent(ev, task)
+			if task != nil && sd != nil {
+				task.spans = append(task.spans, sd)
 			}
 
 		case trace.EvGoCreate:
@@ -209,11 +263,11 @@ func analyzeAnnotations() (annotationAnalysisResult, error) {
 			//
 			// TODO(hyangah): the task info needs to propagate
 			// to all decendents, not only to the immediate child.
-			spans := activeSpans[goid]
-			if len(spans) == 0 {
+			s := activeSpans.top(goid)
+			if s == nil {
 				continue
 			}
-			taskid := spans[len(spans)-1].Args[0]
+			taskid := s.Args[0]
 			task := tasks.task(taskid)
 			task.addEvent(ev)
 
@@ -326,21 +380,6 @@ func (task *taskDesc) addEvent(ev *trace.Event) {
 		task.create = ev
 	case trace.EvUserTaskEnd:
 		task.end = ev
-	case trace.EvUserSpan:
-		if mode := ev.Args[1]; mode == 0 { // start
-			task.spans = append(task.spans, &spanDesc{
-				name:  ev.SArgs[0],
-				task:  task,
-				goid:  ev.G,
-				start: ev,
-				end:   ev.Link})
-		} else if ev.Link == nil { // span end without matching start
-			task.spans = append(task.spans, &spanDesc{
-				name: ev.SArgs[0],
-				task: task,
-				goid: ev.G,
-				end:  ev})
-		}
 	}
 }
 

src/internal/trace/parser.go

@@ -56,8 +56,7 @@ type Event struct {
 	// for GoSysExit: the next GoStart
 	// for GCMarkAssistStart: the associated GCMarkAssistDone
 	// for UserTaskCreate: the UserTaskEnd
-	// for UsetTaskEnd: the UserTaskCreate
-	// for UserSpan: the corresponding span start or end event
+	// for UserSpan: if the start span, the corresponding UserSpan end event
 	Link *Event
 }
 
@@ -810,9 +809,10 @@ func postProcessTrace(ver int, events []*Event) error {
 			}
 			tasks[ev.Args[0]] = ev
 		case EvUserTaskEnd:
-			if prevEv, ok := tasks[ev.Args[0]]; ok {
-				prevEv.Link = ev
-				ev.Link = prevEv
+			taskid := ev.Args[0]
+			if taskCreateEv, ok := tasks[taskid]; ok {
+				taskCreateEv.Link = ev
+				delete(tasks, taskid)
 			}
 		case EvUserSpan:
 			mode := ev.Args[1]
@@ -828,7 +828,6 @@ func postProcessTrace(ver int, events []*Event) error {
 					}
 					// Link span start event with span end event
 					s.Link = ev
-					ev.Link = s
 
 					if n > 1 {
 						activeSpans[ev.G] = spans[:n-1]

src/runtime/trace/annotation_test.go

@@ -3,9 +3,11 @@ package trace_test
 import (
 	"bytes"
 	"context"
+	"fmt"
 	"internal/trace"
 	"reflect"
 	. "runtime/trace"
+	"strings"
 	"sync"
 	"testing"
 )
@@ -102,13 +104,20 @@ func TestUserTaskSpan(t *testing.T) {
 		{trace.EvUserSpan, []string{"task0", "span0"}, []uint64{0}, true},
 		{trace.EvUserSpan, []string{"task0", "span1"}, []uint64{0}, true},
 		{trace.EvUserLog, []string{"task0", "key0", "0123456789abcdef"}, nil, false},
-		{trace.EvUserSpan, []string{"task0", "span1"}, []uint64{1}, true},
-		{trace.EvUserSpan, []string{"task0", "span0"}, []uint64{1}, true},
-		{trace.EvUserTaskEnd, []string{"task0"}, nil, true},
+		{trace.EvUserSpan, []string{"task0", "span1"}, []uint64{1}, false},
+		{trace.EvUserSpan, []string{"task0", "span0"}, []uint64{1}, false},
+		{trace.EvUserTaskEnd, []string{"task0"}, nil, false},
 		{trace.EvUserSpan, []string{"", "pre-existing span"}, []uint64{1}, false},
 		{trace.EvUserSpan, []string{"", "post-existing span"}, []uint64{0}, false},
 	}
 	if !reflect.DeepEqual(got, want) {
-		t.Errorf("Got user span related events %+v\nwant: %+v", got, want)
+		pretty := func(data []testData) string {
+			var s strings.Builder
+			for _, d := range data {
+				s.WriteString(fmt.Sprintf("\t%+v\n", d))
+			}
+			return s.String()
+		}
+		t.Errorf("Got user span related events\n%+v\nwant:\n%+v", pretty(got), pretty(want))
 	}
 }