trace

README

Go Package: trace

Get:

go get -u github.com/cstockton/go-trace

Intro

Package trace extends the features of the Go execution tracer. This project is currently experimental, you can read issue #1 for more information.

While keeping in mind they are meant to serve as a example rather than useful tools, feel free to check the cmd directory for tracecat & tracegrep which use the encoding package.

Sub Package: Encoding

Package encoding implements a streaming Decoder and Encoder for all versions of the Go trace format. For a higher level interface see the parent trace package.

Overview

This library will Decode all previous versions of the trace codec, while only emitting Events in the latest version. Unlike the go tool it does not buffer events during decoding to make them immediately available. This limits the aggregation and correlation to look-behind operations and shared state, but enables the ability to stream events from applications in real time. Most of the API closely resembles events emitted from the runtime. To get a quick primer I suggest starting with the "Go Execution Tracer" design document located at: https://golang.org/s/go15trace

In general Events have intuitive names and it's easy to correlate to your code, for when you can't it may help to better understand the scheduler by reading the design doc at https://golang.org/s/go11sched as well. It's a bit dated but remains conceptually accurate and serves as a good primer. After that https://github.com/golang/go/wiki/DesignDocuments for GC, preemption, syscalls and everything else.

Compatibility

The Go trace format seems to be evolving continuously as new events are added and old events refined. This is a good thing but it does make it difficult to provide backwards compatibility. The maintenance burden of representing each event as it's native versions format would be high and error prone. Not to mention difficult to consume as you special cased each version.

So instead all prior trace format versions will be properly decoded by this library into a single Event structure matching the latest version. If an Event argument is missing in the source version then we try to discover a sane default, in most cases a zero value.

Example:

data, err := ioutil.ReadFile(`testdata/go1.8rc1/tiny_log.trace`)
if err != nil {
	fmt.Println(`Err:`, err)
	return
}

var i, created int
dec := encoding.NewDecoder(bytes.NewReader(data))
for dec.More() {
	evt, err := dec.Decode()
	if err != nil {
		break // err will be in Err()
	}
	if evt.Type() == encoding.EvGoCreate {
		created++
	}
	if i += 1; i%40 == 0 {
		fmt.Println(evt) // printing a sampling of data
	}
}
if err := dec.Err(); err != nil {
	fmt.Println(`Err:`, err)
}
fmt.Printf("Created %v goroutines\n", created)

Output:

// Output:
// encoding.HeapAlloc
// encoding.HeapAlloc
// encoding.HeapAlloc
// encoding.GoStartLocal
// encoding.ProcStop
// encoding.String("/one/ws/godev1.8/go/src/time/sys_unix.go")
// encoding.String("testing.(*M).before")
// encoding.Stack[3]:
// testing.(*M).before [PC 4917480]
// 	/one/ws/godev1.8/go/src/testing/testing.go:914
// testing.(*M).Run [PC 4913544]
// 	/one/ws/godev1.8/go/src/testing/testing.go:815
// main.main [PC 5212775]
// 	log/_test/_testmain.go:56
//
// Created 12 goroutines

Contributing

Feel free to create issues for bugs, please ensure code coverage remains 100% with any pull requests.

Bugs and Patches

Feel free to report bugs and submit pull requests.

• bugs: https://github.com/cstockton/go-trace/issues
• patches: https://github.com/cstockton/go-trace/pulls

Documentation

Overview

Package trace extends the features of the Go execution tracer.

Example

package main

import (
	"fmt"
	"os"

	"github.com/cstockton/go-trace/encoding"
	"github.com/cstockton/go-trace/event"
)

func main() {
	f, err := os.Open(`internal/tracefile/testdata/go1.8/log.trace`)
	if err != nil {
		fmt.Println(`Err:`, err)
		return
	}
	defer f.Close()

	var (
		evt event.Event
		d   = encoding.NewDecoder(f)
	)
	for d.More() {
		evt.Reset()
		if err := d.Decode(&evt); err != nil {
			break
		}
		if evt.Type == event.EvGoSysCall {
			fmt.Println(evt.Type) // print syscall events
		}
	}
	if err := d.Err(); err != nil {
		fmt.Println(`Err: `, err)
		return
	}

}

Output:

event.GoSysCall
event.GoSysCall
event.GoSysCall
event.GoSysCall
event.GoSysCall
event.GoSysCall
event.GoSysCall
event.GoSysCall
event.GoSysCall
event.GoSysCall
event.GoSysCall

Example (RuntimeDecoding)

sleepFn := func(wg *sync.WaitGroup) {
	defer wg.Done()
	<-time.After(time.Millisecond * 100)
}

r, w := io.Pipe()
trace.Start(w)

var wg sync.WaitGroup
wg.Add(3)
go sleepFn(&wg)
go sleepFn(&wg)
go sleepFn(&wg)
wg.Wait()

go func() {
	defer w.Close()
	trace.Stop()
}()

var (
	dec  = encoding.NewDecoder(r)
	evt  event.Event
	evts []*event.Event
)

v, err := dec.Version()
if err != nil {
	fmt.Println(`Err:`, err)
	return
}

tr, err := event.NewTrace(v)
if err != nil {
	fmt.Println(`Err:`, err)
	return
}

for dec.More() {
	evt.Reset()
	if err := dec.Decode(&evt); err != nil {
		break
	}
	if err := tr.Visit(&evt); err != nil {
		fmt.Println(`Err:`, err)
	}
	evts = append(evts, evt.Copy())
}
if err := dec.Err(); err != nil {
	fmt.Println(`Err: `, err)
	return
}

// Lets make sure a goroutine is started for this func
findPC := uint64(reflect.ValueOf(sleepFn).Pointer())
findName := runtime.FuncForPC(uintptr(findPC)).Name()

for _, e := range evts {
	if e.Type != event.EvGoCreate {
		continue
	}

	// We want a stack for the new StackID
	stack := tr.Stacks[e.Get(`NewStackID`)]
	if len(stack) < 1 {
		continue
	}

	name := runtime.FuncForPC(uintptr(stack[0].PC())).Name()
	if findName == name {
		stack, ok := tr.Stacks[e.Get(`StackID`)]
		if !ok {
			fmt.Println(`No stack exists for event:`, e)
		}

		// can't print stack in a unit test due to lack of determnism
		// fmt.Println(stack)
		fmt.Printf("\nFound EvGoCreate for `sleepFn` with new stack:\n====\n")
		for _, frame := range stack {
			fmt.Printf("  %v\n", frame.Func())
		}
	}
}

Output:

Found EvGoCreate for `sleepFn` with new stack:
====
  github.com/cstockton/go-trace_test.Example_runtimeDecoding
  testing.runExample
  testing.runExamples
  testing.(*M).Run
  main.main

Found EvGoCreate for `sleepFn` with new stack:
====
  github.com/cstockton/go-trace_test.Example_runtimeDecoding
  testing.runExample
  testing.runExamples
  testing.(*M).Run
  main.main

Found EvGoCreate for `sleepFn` with new stack:
====
  github.com/cstockton/go-trace_test.Example_runtimeDecoding
  testing.runExample
  testing.runExamples
  testing.(*M).Run
  main.main

Index

• func Start(w io.Writer) error
• func Stop()

Examples

• Package
• Package (RuntimeDecoding)

Functions

func Start

func Start(w io.Writer) error

Start enables tracing for the current program. See the trace.Start function in the standard library for further documentation.

func Stop

func Stop()

Stop stops the current tracing, if any. See the trace.Stop function in the standard library for further documentation.