github.com/corona10/go@v0.0.0-20180224231303-7a218942be57/src/runtime/trace/annotation.go (about) 1 package trace 2 3 import ( 4 "context" 5 "fmt" 6 "sync/atomic" 7 _ "unsafe" 8 ) 9 10 type traceContextKey struct{} 11 12 // NewContext creates a child context with a new task instance with 13 // the type taskType. If the input context contains a task, the 14 // 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, taskEnd := trace.NewContext(ctx, "awesome task") 28 // trace.WithSpan(ctx, prepWork) 29 // // preparation of the task 30 // go func() { // continue processing the task in a separate goroutine. 31 // defer taskEnd() 32 // trace.WithSpan(ctx, remainingWork) 33 // } 34 func NewContext(pctx context.Context, taskType string) (ctx context.Context, end func()) { 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), func() { 40 userTaskEnd(id) 41 } 42 43 // We allocate a new task and the end function even when 44 // the tracing is disabled because the context and the detach 45 // function can be used across trace enable/disable boundaries, 46 // which complicates the problem. 47 // 48 // For example, consider the following scenario: 49 // - trace is enabled. 50 // - trace.WithSpan is called, so a new context ctx 51 // with a new span is created. 52 // - trace is disabled. 53 // - trace is enabled again. 54 // - trace APIs with the ctx is called. Is the ID in the task 55 // a valid one to use? 56 // 57 // TODO(hyangah): reduce the overhead at least when 58 // tracing is disabled. Maybe the id can embed a tracing 59 // round number and ignore ids generated from previous 60 // tracing round. 61 } 62 63 func fromContext(ctx context.Context) *task { 64 if s, ok := ctx.Value(traceContextKey{}).(*task); ok { 65 return s 66 } 67 return &bgTask 68 } 69 70 type task struct { 71 id uint64 72 // TODO(hyangah): record parent id? 73 } 74 75 var lastTaskID uint64 = 0 // task id issued last time 76 77 func newID() uint64 { 78 // TODO(hyangah): use per-P cache 79 return atomic.AddUint64(&lastTaskID, 1) 80 } 81 82 var bgTask = task{id: uint64(0)} 83 84 // Log emits a one-off event with the given category and message. 85 // Category can be empty and the API assumes there are only a handful of 86 // unique categories in the system. 87 func Log(ctx context.Context, category, message string) { 88 id := fromContext(ctx).id 89 userLog(id, category, message) 90 } 91 92 // Logf is like Log, but the value is formatted using the specified format spec. 93 func Logf(ctx context.Context, category, format string, args ...interface{}) { 94 if IsEnabled() { 95 // Ideally this should be just Log, but that will 96 // add one more frame in the stack trace. 97 id := fromContext(ctx).id 98 userLog(id, category, fmt.Sprintf(format, args...)) 99 } 100 } 101 102 const ( 103 spanStartCode = uint64(0) 104 spanEndCode = uint64(1) 105 ) 106 107 // WithSpan starts a span associated with its calling goroutine, runs fn, 108 // and then ends the span. If the context carries a task, the span is 109 // attached to the task. Otherwise, the span is attached to the background 110 // task. 111 // 112 // The spanType is used to classify spans, so there should be only a 113 // handful of unique span types. 114 func WithSpan(ctx context.Context, spanType string, fn func(context.Context)) { 115 // NOTE: 116 // WithSpan helps avoiding misuse of the API but in practice, 117 // this is very restrictive: 118 // - Use of WithSpan makes the stack traces captured from 119 // span start and end are identical. 120 // - Refactoring the existing code to use WithSpan is sometimes 121 // hard and makes the code less readable. 122 // e.g. code block nested deep in the loop with various 123 // exit point with return values 124 // - Refactoring the code to use this API with closure can 125 // cause different GC behavior such as retaining some parameters 126 // longer. 127 // This causes more churns in code than I hoped, and sometimes 128 // makes the code less readable. 129 130 id := fromContext(ctx).id 131 userSpan(id, spanStartCode, spanType) 132 defer userSpan(id, spanEndCode, spanType) 133 fn(ctx) 134 } 135 136 // StartSpan starts a span and returns a function for marking the 137 // end of the span. The span end function must be called from the 138 // same goroutine where the span was started. 139 // Within each goroutine, spans must nest. That is, spans started 140 // after this span must be ended before this span can be ended. 141 // Callers are encouraged to instead use WithSpan when possible, 142 // since it naturally satisfies these restrictions. 143 func StartSpan(ctx context.Context, spanType string) func() { 144 id := fromContext(ctx).id 145 userSpan(id, spanStartCode, spanType) 146 return func() { userSpan(id, spanEndCode, spanType) } 147 } 148 149 // IsEnabled returns whether tracing is enabled. 150 // The information is advisory only. The tracing status 151 // may have changed by the time this function returns. 152 func IsEnabled() bool { 153 enabled := atomic.LoadInt32(&tracing.enabled) 154 return enabled == 1 155 } 156 157 // 158 // Function bodies are defined in runtime/trace.go 159 // 160 161 // emits UserTaskCreate event. 162 func userTaskCreate(id, parentID uint64, taskType string) 163 164 // emits UserTaskEnd event. 165 func userTaskEnd(id uint64) 166 167 // emits UserSpan event. 168 func userSpan(id, mode uint64, spanType string) 169 170 // emits UserLog event. 171 func userLog(id uint64, category, message string)