trace.go

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