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