trace

Overview ¶

package trace provides activity tracing via ctx through Tasks and Spans

Basic Concepts ¶

Tracing can be used to identify where a piece of code spends its time.

The Go standard library provides package runtime/trace which is useful to identify CPU bottlenecks or to understand what happens inside the Go runtime. However, it is not ideal for application level tracing, in particular if those traces should be understandable to tech-savvy users (albeit not developers).

This package provides the concept of Tasks and Spans to express what activity is happening within an application: - Neither task nor span is really tangible but instead contained within the context.Context tree - Tasks represent concurrent activity (i.e. goroutines). - Spans represent a semantic stack trace within a task. As a consequence, whenever a context is propagated across goroutine boundary, you need to create a child task:

go func(ctx context.Context) {
  ctx, endTask = WithTask(ctx, "what-happens-inside-the-child-task")
  defer endTask()
  // ...
}(ctx)

Within the task, you can open up a hierarchy of spans. In contrast to tasks, which have can multiple concurrently running child tasks, spans must nest and not cross the goroutine boundary.

ctx, endSpan = WithSpan(ctx, "copy-dir")
defer endSpan()
for _, f := range dir.Files() {
  func() {
    ctx, endSpan := WithSpan(ctx, fmt.Sprintf("copy-file %q", f))
    defer endspan()
    b, _ := ioutil.ReadFile(f)
    _ = ioutil.WriteFile(f + ".copy", b, 0600)
  }()
}

In combination:

ctx, endTask = WithTask(ctx, "copy-dirs")
defer endTask()
for i := range dirs {
  go func(dir string) {
    ctx, endTask := WithTask(ctx, "copy-dir")
    defer endTask()
    for _, f := range filesIn(dir) {
      func() {
        ctx, endSpan := WithSpan(ctx, fmt.Sprintf("copy-file %q", f))
        defer endspan()
        b, _ := ioutil.ReadFile(f)
        _ = ioutil.WriteFile(f + ".copy", b, 0600)
      }()
    }
  }()
}

Note that a span ends at the time you call endSpan - not before and not after that. If you violate the stack-like nesting of spans by forgetting an endSpan() invocation, the out-of-order endSpan() will panic.

A similar rule applies to the endTask closure returned by WithTask: If a task has live child tasks at the time you call endTask(), the call will panic.

Recovering from endSpan() or endTask() panics will corrupt the trace stack and lead to corrupt tracefile output.

Best Practices For Naming Tasks And Spans ¶

Tasks should always have string constants as names, and must not contain the `#` character. WHy? First, the visualization by chrome://tracing draws a horizontal bar for each task in the trace. Also, the package appends `#NUM` for each concurrently running instance of a task name. Note that the `#NUM` suffix will be reused if a task has ended, in order to avoid an infinite number of horizontal bars in the visualization.

Chrome-compatible Tracefile Support ¶

The activity trace generated by usage of WithTask and WithSpan can be rendered to a JSON output file that can be loaded into chrome://tracing . Apart from function GetSpanStackOrDefault, this is the main benefit of this package.

First, there is a convenience environment variable 'ZREPL_ACTIVITY_TRACE' that can be set to an output path. From process start onward, a trace is written to that path.

More consumers can attach to the activity trace through the ChrometraceClientWebsocketHandler websocket handler.

If a write error is encountered with any consumer (including the env-var based one), the consumer is closed and will not receive further trace output.