1 // Copyright 2015 The Go Authors. All rights reserved. 2 // Use of this source code is governed by a BSD-style 3 // license that can be found in the LICENSE file. 4 5 // Package trace contains facilities for programs to generate traces 6 // for the Go execution tracer. 7 // 8 // Tracing runtime activities 9 // 10 // The execution trace captures a wide range of execution events such as 11 // goroutine creation/blocking/unblocking, syscall enter/exit/block, 12 // GC-related events, changes of heap size, processor start/stop, etc. 13 // A precise nanosecond-precision timestamp and a stack trace is 14 // captured for most events. The generated trace can be interpreted 15 // using `go tool trace`. 16 // 17 // Support for tracing tests and benchmarks built with the standard 18 // testing package is built into `go test`. For example, the following 19 // command runs the test in the current directory and writes the trace 20 // file (trace.out). 21 // 22 // go test -trace=test.out 23 // 24 // This runtime/trace package provides APIs to add equivalent tracing 25 // support to a standalone program. See the Example that demonstrates 26 // how to use this API to enable tracing. 27 // 28 // There is also a standard HTTP interface to trace data. Adding the 29 // following line will install a handler under the /debug/pprof/trace URL 30 // to download a live trace: 31 // 32 // import _ "net/http/pprof" 33 // 34 // See the net/http/pprof package for more details about all of the 35 // debug endpoints installed by this import. 36 // 37 // User annotation 38 // 39 // Package trace provides user annotation APIs that can be used to 40 // log interesting events during execution. 41 // 42 // There are three types of user annotations: log messages, regions, 43 // and tasks. 44 // 45 // Log emits a timestamped message to the execution trace along with 46 // additional information such as the category of the message and 47 // which goroutine called Log. The execution tracer provides UIs to filter 48 // and group goroutines using the log category and the message supplied 49 // in Log. 50 // 51 // A region is for logging a time interval during a goroutine's execution. 52 // By definition, a region starts and ends in the same goroutine. 53 // Regions can be nested to represent subintervals. 54 // For example, the following code records four regions in the execution 55 // trace to trace the durations of sequential steps in a cappuccino making 56 // operation. 57 // 58 // trace.WithRegion(ctx, "makeCappuccino", func() { 59 // 60 // // orderID allows to identify a specific order 61 // // among many cappuccino order region records. 62 // trace.Log(ctx, "orderID", orderID) 63 // 64 // trace.WithRegion(ctx, "steamMilk", steamMilk) 65 // trace.WithRegion(ctx, "extractCoffee", extractCoffee) 66 // trace.WithRegion(ctx, "mixMilkCoffee", mixMilkCoffee) 67 // }) 68 // 69 // A task is a higher-level component that aids tracing of logical 70 // operations such as an RPC request, an HTTP request, or an 71 // interesting local operation which may require multiple goroutines 72 // working together. Since tasks can involve multiple goroutines, 73 // they are tracked via a context.Context object. NewTask creates 74 // a new task and embeds it in the returned context.Context object. 75 // Log messages and regions are attached to the task, if any, in the 76 // Context passed to Log and WithRegion. 77 // 78 // For example, assume that we decided to froth milk, extract coffee, 79 // and mix milk and coffee in separate goroutines. With a task, 80 // the trace tool can identify the goroutines involved in a specific 81 // cappuccino order. 82 // 83 // ctx, task := trace.NewTask(ctx, "makeCappuccino") 84 // trace.Log(ctx, "orderID", orderID) 85 // 86 // milk := make(chan bool) 87 // espresso := make(chan bool) 88 // 89 // go func() { 90 // trace.WithRegion(ctx, "steamMilk", steamMilk) 91 // milk <- true 92 // }() 93 // go func() { 94 // trace.WithRegion(ctx, "extractCoffee", extractCoffee) 95 // espresso <- true 96 // }() 97 // go func() { 98 // defer task.End() // When assemble is done, the order is complete. 99 // <-espresso 100 // <-milk 101 // trace.WithRegion(ctx, "mixMilkCoffee", mixMilkCoffee) 102 // }() 103 // 104 // 105 // The trace tool computes the latency of a task by measuring the 106 // time between the task creation and the task end and provides 107 // latency distributions for each task type found in the trace. 108 package trace 109 110 import ( 111 "io" 112 "runtime" 113 "sync" 114 "sync/atomic" 115 ) 116 117 // Start enables tracing for the current program. 118 // While tracing, the trace will be buffered and written to w. 119 // Start returns an error if tracing is already enabled. 120 func Start(w io.Writer) error { 121 tracing.Lock() 122 defer tracing.Unlock() 123 124 if err := runtime.StartTrace(); err != nil { 125 return err 126 } 127 go func() { 128 for { 129 data := runtime.ReadTrace() 130 if data == nil { 131 break 132 } 133 w.Write(data) 134 } 135 }() 136 atomic.StoreInt32(&tracing.enabled, 1) 137 return nil 138 } 139 140 // Stop stops the current tracing, if any. 141 // Stop only returns after all the writes for the trace have completed. 142 func Stop() { 143 tracing.Lock() 144 defer tracing.Unlock() 145 atomic.StoreInt32(&tracing.enabled, 0) 146 147 runtime.StopTrace() 148 } 149 150 var tracing struct { 151 sync.Mutex // gate mutators (Start, Stop) 152 enabled int32 // accessed via atomic 153 } 154