cmd/trace: distinguish task endTimestamp and lastTimestamp

A task may have other user annotation events after the task ends.
So far, task.lastTimestamp returned the task end event if the
event available. This change introduces task.endTimestamp for that
and makes task.lastTimestamp returns the "last" seen event's timestamp
if the task is ended.

If the task is not ended, both returns the last timestamp of the entire
trace assuming the task is still active.

This fixes the task-oriented trace view mode not to drop user
annotation instances when they appear outside a task's lifespan.
Adds a test.

Change-Id: Iba1062914f224edd521b9ee55c6cd5e180e55359
Reviewed-on: https://go-review.googlesource.com/109175
Reviewed-by: Heschi Kreinick <heschi@google.com>

1 files changed, 59 insertions, 0 deletions

diff --git a/src/cmd/trace/trace_test.go b/src/cmd/trace/trace_test.go
index aff3863802..852d745b29 100644
--- a/src/cmd/trace/trace_test.go
+++ b/src/cmd/trace/trace_test.go
@@ -5,8 +5,10 @@
 package main
 
 import (
+	"context"
 	"internal/trace"
 	"io/ioutil"
+	rtrace "runtime/trace"
 	"strings"
 	"testing"
 )
@@ -172,3 +174,60 @@ func TestPreemptedMarkAssist(t *testing.T) {
 		t.Errorf("Got %v MARK ASSIST events, want %v", marks, 2)
 	}
 }
+
+func TestFoo(t *testing.T) {
+	prog0 := func() {
+		ctx, task := rtrace.NewTask(context.Background(), "ohHappyDay")
+		rtrace.Log(ctx, "", "log before task ends")
+		task.End()
+		rtrace.Log(ctx, "", "log after task ends") // log after task ends
+	}
+	if err := traceProgram(t, prog0, "TestFoo"); err != nil {
+		t.Fatalf("failed to trace the program: %v", err)
+	}
+	res, err := parseTrace()
+	if err != nil {
+		t.Fatalf("failed to parse the trace: %v", err)
+	}
+	annotRes, _ := analyzeAnnotations()
+	var task *taskDesc
+	for _, t := range annotRes.tasks {
+		if t.name == "ohHappyDay" {
+			task = t
+			break
+		}
+	}
+	if task == nil {
+		t.Fatal("failed to locate expected task event")
+	}
+
+	params := &traceParams{
+		parsed:    res,
+		mode:      modeTaskOriented,
+		startTime: task.firstTimestamp() - 1,
+		endTime:   task.lastTimestamp() + 1,
+		tasks:     []*taskDesc{task},
+	}
+
+	c := viewerDataTraceConsumer(ioutil.Discard, 0, 1<<63-1)
+
+	var logBeforeTaskEnd, logAfterTaskEnd bool
+	c.consumeViewerEvent = func(ev *ViewerEvent, _ bool) {
+		if ev.Name == "log before task ends" {
+			logBeforeTaskEnd = true
+		}
+		if ev.Name == "log after task ends" {
+			logAfterTaskEnd = true
+		}
+	}
+	if err := generateTrace(params, c); err != nil {
+		t.Fatalf("generateTrace failed: %v", err)
+	}
+	if !logBeforeTaskEnd {
+		t.Error("failed to find 'log before task ends'")
+	}
+	if !logAfterTaskEnd {
+		t.Error("failed to find 'log after task ends'")
+	}
+
+}