Source file src/runtime/trace/annotation.go

Documentation: runtime/trace

     1  package trace
     2  
     3  import (
     4  	"context"
     5  	"fmt"
     6  	"sync/atomic"
     7  	_ "unsafe"
     8  )
     9  
    10  type traceContextKey struct{}
    11  
    12  // NewTask creates a task instance with the type taskType and returns
    13  // it along with a Context that carries the task.
    14  // If the input context contains a task, the new task is its subtask.
    15  //
    16  // The taskType is used to classify task instances. Analysis tools
    17  // like the Go execution tracer may assume there are only a bounded
    18  // number of unique task types in the system.
    19  //
    20  // The returned end function is used to mark the task's end.
    21  // The trace tool measures task latency as the time between task creation
    22  // and when the end function is called, and provides the latency
    23  // distribution per task type.
    24  // If the end function is called multiple times, only the first
    25  // call is used in the latency measurement.
    26  //
    27  //   ctx, task := trace.NewTask(ctx, "awesomeTask")
    28  //   trace.WithRegion(ctx, "preparation", prepWork)
    29  //   // preparation of the task
    30  //   go func() {  // continue processing the task in a separate goroutine.
    31  //       defer task.End()
    32  //       trace.WithRegion(ctx, "remainingWork", remainingWork)
    33  //   }()
    34  func NewTask(pctx context.Context, taskType string) (ctx context.Context, task *Task) {
    35  	pid := fromContext(pctx).id
    36  	id := newID()
    37  	userTaskCreate(id, pid, taskType)
    38  	s := &Task{id: id}
    39  	return context.WithValue(pctx, traceContextKey{}, s), s
    40  
    41  	// We allocate a new task and the end function even when
    42  	// the tracing is disabled because the context and the detach
    43  	// function can be used across trace enable/disable boundaries,
    44  	// which complicates the problem.
    45  	//
    46  	// For example, consider the following scenario:
    47  	//   - trace is enabled.
    48  	//   - trace.WithRegion is called, so a new context ctx
    49  	//     with a new region is created.
    50  	//   - trace is disabled.
    51  	//   - trace is enabled again.
    52  	//   - trace APIs with the ctx is called. Is the ID in the task
    53  	//   a valid one to use?
    54  	//
    55  	// TODO(hyangah): reduce the overhead at least when
    56  	// tracing is disabled. Maybe the id can embed a tracing
    57  	// round number and ignore ids generated from previous
    58  	// tracing round.
    59  }
    60  
    61  func fromContext(ctx context.Context) *Task {
    62  	if s, ok := ctx.Value(traceContextKey{}).(*Task); ok {
    63  		return s
    64  	}
    65  	return &bgTask
    66  }
    67  
    68  // Task is a data type for tracing a user-defined, logical operation.
    69  type Task struct {
    70  	id uint64
    71  	// TODO(hyangah): record parent id?
    72  }
    73  
    74  // End marks the end of the operation represented by the Task.
    75  func (t *Task) End() {
    76  	userTaskEnd(t.id)
    77  }
    78  
    79  var lastTaskID uint64 = 0 // task id issued last time
    80  
    81  func newID() uint64 {
    82  	// TODO(hyangah): use per-P cache
    83  	return atomic.AddUint64(&lastTaskID, 1)
    84  }
    85  
    86  var bgTask = Task{id: uint64(0)}
    87  
    88  // Log emits a one-off event with the given category and message.
    89  // Category can be empty and the API assumes there are only a handful of
    90  // unique categories in the system.
    91  func Log(ctx context.Context, category, message string) {
    92  	id := fromContext(ctx).id
    93  	userLog(id, category, message)
    94  }
    95  
    96  // Logf is like Log, but the value is formatted using the specified format spec.
    97  func Logf(ctx context.Context, category, format string, args ...interface{}) {
    98  	if IsEnabled() {
    99  		// Ideally this should be just Log, but that will
   100  		// add one more frame in the stack trace.
   101  		id := fromContext(ctx).id
   102  		userLog(id, category, fmt.Sprintf(format, args...))
   103  	}
   104  }
   105  
   106  const (
   107  	regionStartCode = uint64(0)
   108  	regionEndCode   = uint64(1)
   109  )
   110  
   111  // WithRegion starts a region associated with its calling goroutine, runs fn,
   112  // and then ends the region. If the context carries a task, the region is
   113  // associated with the task. Otherwise, the region is attached to the background
   114  // task.
   115  //
   116  // The regionType is used to classify regions, so there should be only a
   117  // handful of unique region types.
   118  func WithRegion(ctx context.Context, regionType string, fn func()) {
   119  	// NOTE:
   120  	// WithRegion helps avoiding misuse of the API but in practice,
   121  	// this is very restrictive:
   122  	// - Use of WithRegion makes the stack traces captured from
   123  	//   region start and end are identical.
   124  	// - Refactoring the existing code to use WithRegion is sometimes
   125  	//   hard and makes the code less readable.
   126  	//     e.g. code block nested deep in the loop with various
   127  	//          exit point with return values
   128  	// - Refactoring the code to use this API with closure can
   129  	//   cause different GC behavior such as retaining some parameters
   130  	//   longer.
   131  	// This causes more churns in code than I hoped, and sometimes
   132  	// makes the code less readable.
   133  
   134  	id := fromContext(ctx).id
   135  	userRegion(id, regionStartCode, regionType)
   136  	defer userRegion(id, regionEndCode, regionType)
   137  	fn()
   138  }
   139  
   140  // StartRegion starts a region and returns a function for marking the
   141  // end of the region. The returned Region's End function must be called
   142  // from the same goroutine where the region was started.
   143  // Within each goroutine, regions must nest. That is, regions started
   144  // after this region must be ended before this region can be ended.
   145  // Recommended usage is
   146  //
   147  //     defer trace.StartRegion(ctx, "myTracedRegion").End()
   148  //
   149  func StartRegion(ctx context.Context, regionType string) *Region {
   150  	if !IsEnabled() {
   151  		return noopRegion
   152  	}
   153  	id := fromContext(ctx).id
   154  	userRegion(id, regionStartCode, regionType)
   155  	return &Region{id, regionType}
   156  }
   157  
   158  // Region is a region of code whose execution time interval is traced.
   159  type Region struct {
   160  	id         uint64
   161  	regionType string
   162  }
   163  
   164  var noopRegion = &Region{}
   165  
   166  // End marks the end of the traced code region.
   167  func (r *Region) End() {
   168  	if r == noopRegion {
   169  		return
   170  	}
   171  	userRegion(r.id, regionEndCode, r.regionType)
   172  }
   173  
   174  // IsEnabled reports whether tracing is enabled.
   175  // The information is advisory only. The tracing status
   176  // may have changed by the time this function returns.
   177  func IsEnabled() bool {
   178  	enabled := atomic.LoadInt32(&tracing.enabled)
   179  	return enabled == 1
   180  }
   181  
   182  //
   183  // Function bodies are defined in runtime/trace.go
   184  //
   185  
   186  // emits UserTaskCreate event.
   187  func userTaskCreate(id, parentID uint64, taskType string)
   188  
   189  // emits UserTaskEnd event.
   190  func userTaskEnd(id uint64)
   191  
   192  // emits UserRegion event.
   193  func userRegion(id, mode uint64, regionType string)
   194  
   195  // emits UserLog event.
   196  func userLog(id uint64, category, message string)
   197  

View as plain text