runtime/trace: rename "Span" with "Region"

"Span" is a commonly used term in many distributed tracing systems
(Dapper, OpenCensus, OpenTracing, ...). They use it to refer to a
period of time, not necessarily tied into execution of underlying
processor, thread, or goroutine, unlike the "Span" of runtime/trace
package.

Since distributed tracing and go runtime execution tracing are
already similar enough to cause confusion, this CL attempts to avoid
using the same word if possible.

"Region" is being used in a certain tracing system to refer to a code
region which is pretty close to what runtime/trace.Span currently
refers to. So, replace that.
https://software.intel.com/en-us/itc-user-and-reference-guide-defining-and-recording-functions-or-regions

This CL also tweaks APIs a bit based on jbd and heschi's comments:

  NewContext -> NewTask
    and it now returns a Task object that exports End method.

  StartSpan -> StartRegion
    and it now returns a Region object that exports End method.

Also, changed WithSpan to WithRegion and it now takes func() with no
context. Another thought is to get rid of WithRegion. It is a nice
concept but in practice, it seems problematic (a lot of code churn,
and polluting stack trace). Already, the tracing concept is very low
level, and we hope this API to be used with great care.

Recommended usage will be
   defer trace.StartRegion(ctx, "someRegion").End()

Left old APIs untouched in this CL. Once the usage of them are cleaned
up, they will be removed in a separate CL.

Change-Id: I73880635e437f3aad51314331a035dd1459b9f3a
Reviewed-on: https://go-review.googlesource.com/108296
Run-TryBot: Hyang-Ah Hana Kim <hyangah@gmail.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: JBD <jbd@google.com>

3 files changed, 117 insertions, 83 deletions

diff --git a/src/runtime/trace/annotation.go b/src/runtime/trace/annotation.go
index be92d52af8..0261d1c162 100644
--- a/src/runtime/trace/annotation.go
+++ b/src/runtime/trace/annotation.go
@@ -9,9 +9,9 @@ import (
 
 type traceContextKey struct{}
 
-// NewContext creates a child context with a new task instance with
-// the type taskType. If the input context contains a task, the
-// new task is its subtask.
+// NewTask creates a task instance with the type taskType and returns
+// it along with a Context that carries the task.
+// If the input context contains a task, the new task is its subtask.
 //
 // The taskType is used to classify task instances. Analysis tools
 // like the Go execution tracer may assume there are only a bounded
@@ -24,21 +24,19 @@ type traceContextKey struct{}
 // If the end function is called multiple times, only the first
 // call is used in the latency measurement.
 //
-//   ctx, taskEnd := trace.NewContext(ctx, "awesome task")
-//   trace.WithSpan(ctx, prepWork)
+//   ctx, task := trace.NewContext(ctx, "awesome task")
+//   trace.WithRegion(ctx, prepWork)
 //   // preparation of the task
 //   go func() {  // continue processing the task in a separate goroutine.
-//       defer taskEnd()
-//       trace.WithSpan(ctx, remainingWork)
+//       defer task.End()
+//       trace.WithRegion(ctx, remainingWork)
 //   }
-func NewContext(pctx context.Context, taskType string) (ctx context.Context, end func()) {
+func NewTask(pctx context.Context, taskType string) (ctx context.Context, task *Task) {
 	pid := fromContext(pctx).id
 	id := newID()
 	userTaskCreate(id, pid, taskType)
-	s := &task{id: id}
-	return context.WithValue(pctx, traceContextKey{}, s), func() {
-		userTaskEnd(id)
-	}
+	s := &Task{id: id}
+	return context.WithValue(pctx, traceContextKey{}, s), s
 
 	// We allocate a new task and the end function even when
 	// the tracing is disabled because the context and the detach
@@ -47,8 +45,8 @@ func NewContext(pctx context.Context, taskType string) (ctx context.Context, end
 	//
 	// For example, consider the following scenario:
 	//   - trace is enabled.
-	//   - trace.WithSpan is called, so a new context ctx
-	//     with a new span is created.
+	//   - trace.WithRegion is called, so a new context ctx
+	//     with a new region is created.
 	//   - trace is disabled.
 	//   - trace is enabled again.
 	//   - trace APIs with the ctx is called. Is the ID in the task
@@ -60,18 +58,30 @@ func NewContext(pctx context.Context, taskType string) (ctx context.Context, end
 	// tracing round.
 }
 
-func fromContext(ctx context.Context) *task {
-	if s, ok := ctx.Value(traceContextKey{}).(*task); ok {
+// NewContext is obsolete by NewTask. Do not use.
+func NewContext(pctx context.Context, taskType string) (ctx context.Context, endTask func()) {
+	ctx, t := NewTask(pctx, taskType)
+	return ctx, t.End
+}
+
+func fromContext(ctx context.Context) *Task {
+	if s, ok := ctx.Value(traceContextKey{}).(*Task); ok {
 		return s
 	}
 	return &bgTask
 }
 
-type task struct {
+// Task is a data type for tracing a user-defined, logical operation.
+type Task struct {
 	id uint64
 	// TODO(hyangah): record parent id?
 }
 
+// End marks the end of the operation represented by the Task.
+func (t *Task) End() {
+	userTaskEnd(t.id)
+}
+
 var lastTaskID uint64 = 0 // task id issued last time
 
 func newID() uint64 {
@@ -79,7 +89,7 @@ func newID() uint64 {
 	return atomic.AddUint64(&lastTaskID, 1)
 }
 
-var bgTask = task{id: uint64(0)}
+var bgTask = Task{id: uint64(0)}
 
 // Log emits a one-off event with the given category and message.
 // Category can be empty and the API assumes there are only a handful of
@@ -100,24 +110,24 @@ func Logf(ctx context.Context, category, format string, args ...interface{}) {
 }
 
 const (
-	spanStartCode = uint64(0)
-	spanEndCode   = uint64(1)
+	regionStartCode = uint64(0)
+	regionEndCode   = uint64(1)
 )
 
-// WithSpan starts a span associated with its calling goroutine, runs fn,
-// and then ends the span. If the context carries a task, the span is
-// attached to the task. Otherwise, the span is attached to the background
+// WithRegion starts a region associated with its calling goroutine, runs fn,
+// and then ends the region. If the context carries a task, the region is
+// associated with the task. Otherwise, the region is attached to the background
 // task.
 //
-// The spanType is used to classify spans, so there should be only a
-// handful of unique span types.
-func WithSpan(ctx context.Context, spanType string, fn func(context.Context)) {
+// The regionType is used to classify regions, so there should be only a
+// handful of unique region types.
+func WithRegion(ctx context.Context, regionType string, fn func()) {
 	// NOTE:
-	// WithSpan helps avoiding misuse of the API but in practice,
+	// WithRegion helps avoiding misuse of the API but in practice,
 	// this is very restrictive:
-	// - Use of WithSpan makes the stack traces captured from
-	//   span start and end are identical.
-	// - Refactoring the existing code to use WithSpan is sometimes
+	// - Use of WithRegion makes the stack traces captured from
+	//   region start and end are identical.
+	// - Refactoring the existing code to use WithRegion is sometimes
 	//   hard and makes the code less readable.
 	//     e.g. code block nested deep in the loop with various
 	//          exit point with return values
@@ -128,22 +138,46 @@ func WithSpan(ctx context.Context, spanType string, fn func(context.Context)) {
 	// makes the code less readable.
 
 	id := fromContext(ctx).id
-	userSpan(id, spanStartCode, spanType)
-	defer userSpan(id, spanEndCode, spanType)
-	fn(ctx)
+	userRegion(id, regionStartCode, regionType)
+	defer userRegion(id, regionEndCode, regionType)
+	fn()
 }
 
-// StartSpan starts a span and returns a function for marking the
-// end of the span. The span end function must be called from the
-// same goroutine where the span was started.
-// Within each goroutine, spans must nest. That is, spans started
-// after this span must be ended before this span can be ended.
-// Callers are encouraged to instead use WithSpan when possible,
-// since it naturally satisfies these restrictions.
-func StartSpan(ctx context.Context, spanType string) func() {
+// WithSpan is obsolete by WithRegion. Do not use.
+func WithSpan(ctx context.Context, spanType string, fn func(ctx context.Context)) {
+	WithRegion(ctx, spanType, func() { fn(ctx) })
+}
+
+// StartRegion starts a region and returns a function for marking the
+// end of the region. The returned Region's End function must be called
+// from the same goroutine where the region was started.
+// Within each goroutine, regions must nest. That is, regions started
+// after this region must be ended before this region can be ended.
+// Recommended usage is
+//
+//     defer trace.StartRegion(ctx, "myTracedRegion").End()
+//
+func StartRegion(ctx context.Context, regionType string) *Region {
 	id := fromContext(ctx).id
-	userSpan(id, spanStartCode, spanType)
-	return func() { userSpan(id, spanEndCode, spanType) }
+	userRegion(id, regionStartCode, regionType)
+	return &Region{id, regionType}
+}
+
+// StartSpan is obsolete by StartRegion. Do not use.
+func StartSpan(ctx context.Context, spanType string) func() {
+	r := StartRegion(ctx, spanType)
+	return r.End
+}
+
+// Region is a region of code whose execution time interval is traced.
+type Region struct {
+	id         uint64
+	regionType string
+}
+
+// End marks the end of the traced code region.
+func (r *Region) End() {
+	userRegion(r.id, regionEndCode, r.regionType)
 }
 
 // IsEnabled returns whether tracing is enabled.
@@ -164,8 +198,8 @@ func userTaskCreate(id, parentID uint64, taskType string)
 // emits UserTaskEnd event.
 func userTaskEnd(id uint64)
 
-// emits UserSpan event.
-func userSpan(id, mode uint64, spanType string)
+// emits UserRegion event.
+func userRegion(id, mode uint64, regionType string)
 
 // emits UserLog event.
 func userLog(id uint64, category, message string)
diff --git a/src/runtime/trace/annotation_test.go b/src/runtime/trace/annotation_test.go
index 0dcb9aca29..c20b009daa 100644
--- a/src/runtime/trace/annotation_test.go
+++ b/src/runtime/trace/annotation_test.go
@@ -12,11 +12,11 @@ import (
 	"testing"
 )
 
-func TestUserTaskSpan(t *testing.T) {
+func TestUserTaskRegion(t *testing.T) {
 	bgctx, cancel := context.WithCancel(context.Background())
 	defer cancel()
 
-	preExistingSpanEnd := StartSpan(bgctx, "pre-existing span")
+	preExistingRegion := StartRegion(bgctx, "pre-existing region")
 
 	buf := new(bytes.Buffer)
 	if err := Start(buf); err != nil {
@@ -25,32 +25,32 @@ func TestUserTaskSpan(t *testing.T) {
 
 	// Beginning of traced execution
 	var wg sync.WaitGroup
-	ctx, end := NewContext(bgctx, "task0") // EvUserTaskCreate("task0")
+	ctx, task := NewTask(bgctx, "task0") // EvUserTaskCreate("task0")
 	wg.Add(1)
 	go func() {
 		defer wg.Done()
-		defer end() // EvUserTaskEnd("task0")
+		defer task.End() // EvUserTaskEnd("task0")
 
-		WithSpan(ctx, "span0", func(ctx context.Context) {
-			// EvUserSpanCreate("span0", start)
-			WithSpan(ctx, "span1", func(ctx context.Context) {
+		WithRegion(ctx, "region0", func() {
+			// EvUserRegionCreate("region0", start)
+			WithRegion(ctx, "region1", func() {
 				Log(ctx, "key0", "0123456789abcdef") // EvUserLog("task0", "key0", "0....f")
 			})
-			// EvUserSpan("span0", end)
+			// EvUserRegion("region0", end)
 		})
 	}()
 
 	wg.Wait()
 
-	preExistingSpanEnd()
-	postExistingSpanEnd := StartSpan(bgctx, "post-existing span")
+	preExistingRegion.End()
+	postExistingRegion := StartRegion(bgctx, "post-existing region")
 
 	// End of traced execution
 	Stop()
 
-	postExistingSpanEnd()
+	postExistingRegion.End()
 
-	saveTrace(t, buf, "TestUserTaskSpan")
+	saveTrace(t, buf, "TestUserTaskRegion")
 	res, err := trace.Parse(buf, "")
 	if err == trace.ErrTimeOrder {
 		// golang.org/issues/16755
@@ -90,25 +90,25 @@ func TestUserTaskSpan(t *testing.T) {
 			if e.Link != nil && e.Link.Type != trace.EvUserTaskCreate {
 				t.Errorf("Unexpected linked event %q->%q", e, e.Link)
 			}
-		case trace.EvUserSpan:
+		case trace.EvUserRegion:
 			taskName := tasks[e.Args[0]]
-			spanName := e.SArgs[0]
-			got = append(got, testData{trace.EvUserSpan, []string{taskName, spanName}, []uint64{e.Args[1]}, e.Link != nil})
-			if e.Link != nil && (e.Link.Type != trace.EvUserSpan || e.Link.SArgs[0] != spanName) {
+			regionName := e.SArgs[0]
+			got = append(got, testData{trace.EvUserRegion, []string{taskName, regionName}, []uint64{e.Args[1]}, e.Link != nil})
+			if e.Link != nil && (e.Link.Type != trace.EvUserRegion || e.Link.SArgs[0] != regionName) {
 				t.Errorf("Unexpected linked event %q->%q", e, e.Link)
 			}
 		}
 	}
 	want := []testData{
 		{trace.EvUserTaskCreate, []string{"task0"}, nil, true},
-		{trace.EvUserSpan, []string{"task0", "span0"}, []uint64{0}, true},
-		{trace.EvUserSpan, []string{"task0", "span1"}, []uint64{0}, true},
+		{trace.EvUserRegion, []string{"task0", "region0"}, []uint64{0}, true},
+		{trace.EvUserRegion, []string{"task0", "region1"}, []uint64{0}, true},
 		{trace.EvUserLog, []string{"task0", "key0", "0123456789abcdef"}, nil, false},
-		{trace.EvUserSpan, []string{"task0", "span1"}, []uint64{1}, false},
-		{trace.EvUserSpan, []string{"task0", "span0"}, []uint64{1}, false},
+		{trace.EvUserRegion, []string{"task0", "region1"}, []uint64{1}, false},
+		{trace.EvUserRegion, []string{"task0", "region0"}, []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},
+		{trace.EvUserRegion, []string{"", "pre-existing region"}, []uint64{1}, false},
+		{trace.EvUserRegion, []string{"", "post-existing region"}, []uint64{0}, false},
 	}
 	if !reflect.DeepEqual(got, want) {
 		pretty := func(data []testData) string {
@@ -118,6 +118,6 @@ func TestUserTaskSpan(t *testing.T) {
 			}
 			return s.String()
 		}
-		t.Errorf("Got user span related events\n%+v\nwant:\n%+v", pretty(got), pretty(want))
+		t.Errorf("Got user region related events\n%+v\nwant:\n%+v", pretty(got), pretty(want))
 	}
 }
diff --git a/src/runtime/trace/trace.go b/src/runtime/trace/trace.go
index 1472dc31c5..f3ea312d27 100644
--- a/src/runtime/trace/trace.go
+++ b/src/runtime/trace/trace.go
@@ -39,7 +39,7 @@
 // Package trace provides user annotation APIs that can be used to
 // log interesting events during execution.
 //
-// There are three types of user annotations: log messages, spans,
+// There are three types of user annotations: log messages, regions,
 // and tasks.
 //
 // Log emits a timestamped message to the execution trace along with
@@ -48,22 +48,22 @@
 // and group goroutines using the log category and the message supplied
 // in Log.
 //
-// A span is for logging a time interval during a goroutine's execution.
-// By definition, a span starts and ends in the same goroutine.
-// Spans can be nested to represent subintervals.
-// For example, the following code records four spans in the execution
+// A region is for logging a time interval during a goroutine's execution.
+// By definition, a region starts and ends in the same goroutine.
+// Regions can be nested to represent subintervals.
+// For example, the following code records four regions in the execution
 // trace to trace the durations of sequential steps in a cappuccino making
 // operation.
 //
-//   trace.WithSpan(ctx, "makeCappuccino", func(ctx context.Context) {
+//   trace.WithRegion(ctx, "makeCappuccino", func() {
 //
 //      // orderID allows to identify a specific order
-//      // among many cappuccino order span records.
+//      // among many cappuccino order region records.
 //      trace.Log(ctx, "orderID", orderID)
 //
-//      trace.WithSpan(ctx, "steamMilk", steamMilk)
-//      trace.WithSpan(ctx, "extractCoffee", extractCoffee)
-//      trace.WithSpan(ctx, "mixMilkCoffee", mixMilkCoffee)
+//      trace.WithRegion(ctx, "steamMilk", steamMilk)
+//      trace.WithRegion(ctx, "extractCoffee", extractCoffee)
+//      trace.WithRegion(ctx, "mixMilkCoffee", mixMilkCoffee)
 //   })
 //
 // A task is a higher-level component that aids tracing of logical
@@ -72,8 +72,8 @@
 // working together. Since tasks can involve multiple goroutines,
 // they are tracked via a context.Context object. NewContext creates
 // a new task and embeds it in the returned context.Context object.
-// Log messages and spans are attached to the task, if any, in the
-// Context passed to Log and WithSpan.
+// Log messages and regions are attached to the task, if any, in the
+// Context passed to Log and WithRegion.
 //
 // For example, assume that we decided to froth milk, extract coffee,
 // and mix milk and coffee in separate goroutines. With a task,
@@ -87,18 +87,18 @@
 //     espresso := make(chan bool)
 //
 //     go func() {
-//        trace.WithSpan(ctx, "steamMilk", steamMilk)
+//        trace.WithRegion(ctx, "steamMilk", steamMilk)
 //        milk<-true
 //     })()
 //     go func() {
-//        trace.WithSpan(ctx, "extractCoffee", extractCoffee)
+//        trace.WithRegion(ctx, "extractCoffee", extractCoffee)
 //        espresso<-true
 //     })()
 //     go func() {
 //        defer taskEnd()  // When assemble is done, the order is complete.
 //        <-espresso
 //        <-milk
-//        trace.WithSpan(ctx, "mixMilkCoffee", mixMilkCoffee)
+//        trace.WithRegion(ctx, "mixMilkCoffee", mixMilkCoffee)
 //     })()
 //
 // The trace tool computes the latency of a task by measuring the