trace.go

// Copyright 2015 The Go Authors. All rights reserved.
// Use of this source code is governed by a BSD-style
// license that can be found in the LICENSE file.

// Package trace contains facilities for programs to generate trace
// for Go execution tracer.
//
// Tracing runtime activities
//
// The execution trace captures a wide range of execution events such as
// goroutine creation/blocking/unblocking, syscall enter/exit/block,
// GC-related events, changes of heap size, processor start/stop, etc.
// A precise nanosecond-precision timestamp and a stack trace is
// captured for most events. The generated trace can be interpreted
// using `go tool trace`.
//
// Support for tracing tests and benchmarks built with the standard
// testing package is built into `go test`. For example, the following
// command runs the test in the current directory and writes the trace
// file (trace.out).
//
//    go test -trace=test.out
//
// This runtime/trace package provides APIs to add equivalent tracing
// support to a standalone program. See the Example that demonstrates
// how to use this API to enable tracing.
//
// There is also a standard HTTP interface to trace data. Adding the
// following line will install a handler under the /debug/pprof/trace URL
// to download a live trace:
//
//     import _ "net/http/pprof"
//
// See the net/http/pprof package for more details about all of the
// debug endpoints installed by this import.
//
// User annotation
//
// Package trace provides user annotation APIs that can be used to
// log interesting events during execution.
//
// There are three types of user annotations: log messages, spans,
// and tasks.
//
// Log emits a timestamped message to the execution trace along with
// additional information such as the category of the message and
// which goroutine called Log. The execution tracer provides UIs to filter
// and group goroutines using the log category and the message supplied
// in Log.
//
// A span is for logging a time interval during a goroutine's execution.
// By definition, a span starts and ends in the same goroutine.
// Spans can be nested to represent subintervals.
// For example, the following code records four spans in the execution
// trace to trace the durations of sequential steps in a cappuccino making
// operation.
//
//   trace.WithSpan(ctx, "makeCappuccino", func(ctx context.Context) {
//
//      // orderID allows to identify a specific order
//      // among many cappuccino order span records.
//      trace.Log(ctx, "orderID", orderID)
//
//      trace.WithSpan(ctx, "steamMilk", steamMilk)
//      trace.WithSpan(ctx, "extractCoffee", extractCoffee)
//      trace.WithSpan(ctx, "mixMilkCoffee", mixMilkCoffee)
//   })
//
// A task is a higher-level component that aids tracing of logical
// operations such as an RPC request, an HTTP request, or an
// interesting local operation which may require multiple goroutines
// working together. Since tasks can involve multiple goroutines,
// they are tracked via a context.Context object. NewContext creates
// a new task and embeds it in the returned context.Context object.
// Log messages and spans are attached to the task, if any, in the
// Context passed to Log and WithSpan.
//
// For example, assume that we decided to froth milk, extract coffee,
// and mix milk and coffee in separate goroutines. With a task,
// the trace tool can identify the goroutines involved in a specific
// cappuccino order.
//
//     ctx, taskEnd:= trace.NewContext(ctx, "makeCappuccino")
//     trace.Log(ctx, "orderID", orderID)
//
//     milk := make(chan bool)
//     espresso := make(chan bool)
//
//     go func() {
//        trace.WithSpan(ctx, "steamMilk", steamMilk)
//        milk<-true
//     })()
//     go func() {
//        trace.WithSpan(ctx, "extractCoffee", extractCoffee)
//        espresso<-true
//     })()
//     go func() {
//        defer taskEnd()  // When assemble is done, the order is complete.
//        <-espresso
//        <-milk
//        trace.WithSpan(ctx, "mixMilkCoffee", mixMilkCoffee)
//     })()
//
// The trace tool computes the latency of a task by measuring the
// time between the task creation and the task end and provides
// latency distributions for each task type found in the trace.
package trace

import (
	"io"
	"runtime"
	"sync"
	"sync/atomic"
)

// Start enables tracing for the current program.
// While tracing, the trace will be buffered and written to w.
// Start returns an error if tracing is already enabled.
func Start(w io.Writer) error {
	tracing.Lock()
	defer tracing.Unlock()

	if err := runtime.StartTrace(); err != nil {
		return err
	}
	go func() {
		for {
			data := runtime.ReadTrace()
			if data == nil {
				break
			}
			w.Write(data)
		}
	}()
	atomic.StoreInt32(&tracing.enabled, 1)
	return nil
}

// Stop stops the current tracing, if any.
// Stop only returns after all the writes for the trace have completed.
func Stop() {
	tracing.Lock()
	defer tracing.Unlock()
	atomic.StoreInt32(&tracing.enabled, 0)

	runtime.StopTrace()
}

var tracing struct {
	sync.Mutex       // gate mutators (Start, Stop)
	enabled    int32 // accessed via atomic
}