tracing

README

Tracing in Onet

TLDR

Import the tracing service:

import _ go.dedis.ch/onet/v3/tracing/service

Sign up on https://honeycomb.io and get an API key. Create a dataset on honeycomb.io. Run your binary like this:

HONEYCOMB_API_KEY=api_key:dataset ./conode

Start tracing!

Why

While logging is quite important in setting up and running a system, it has its limits:

• it gets garbled when multiple nodes run at the same time
• only prepared messages can be seen
• difficult to filter and chose which messages are printed

This is why tracing exists, which I learnt from Charity Majors: https://twitter.com/mipsytipsy With her great name, good writing style, calling out people while still listening to suggestions, she convinced me that tracing is needed, not only logging, monitoring, ..., but tracing. The biggest advantage of tracing is to be able to look at collected traces that contain one or more spans. Each trace tells a little story about what's happening in the code. Usually it's a user interaction, but for onet it also makes sense to have protocols behaviour's traced.

How

In order not to have to rewrite a lot of code, this tracing module uses the onet/log package to simulate the tracing. By signing up as a Logger, this package gets informed of every log.* call. It looks at the stack that lead up to that call and decides to which trace this log belongs. This allows it to use all the log.* calls already in the code and to start directly tracing. In order to detect trace-starts, there is a list of methods that indicate a new trace.

As go doesn't support tracing of which go-routines are started by which other go-routine, the tracing mechanism needs some manual support: log.TraceID allows different go-routines to register to the tracing service as spans belonging together. This method is used to link different parts of the protocol together, by using the onet.Token.RoundID as unique identifier. This should even work cross-node.

Add your own traces

There is a good chance that it will work out-of-the box. If you want to add your own methods where a trace should start, simply add them to the environment:

export TRACING_ENTRY_POINTS="github.com/org/repo/pkg.method"
export TRACING_DONE_MSGS="done with tracing"
HONEYCOMB_API_KEY=api_key:dataset ./conode

If you're wondering what traces are available, you can set

export TRACING_PRINT_SINGLE_SPANS=10

This will output stack-traces with length 10 on all unregistered spans. The outputted lines can be added to TRACING_ENTRY_POINTS, as well as a meaningful done message to TRACING_DONE_MSGS. And voilà, your own tracing is enabled.

Unknown traces

Some of the traces will not be found. If you set TRACING_CREATE_SINGLE_SPANS=true, these unknown traces will be created as traces with a single span. This is not pretty, but might turn out useful sometimes.

Debugging

As loggers cannot use onet/log, you can set the following environment variable to output some debugging information about what's happening:

export TRACING_DEBUG=true 

Documentation

Index

• type Span
• type Trace
• type TraceLogger
  • func NewHoneycombLogger(api, dataset string) *TraceLogger
  • func NewHoneycombLoggerDebug() *TraceLogger
  • func NewHoneycombLoggerFromEnv() (*TraceLogger, error)
  • func NewLogger(nt newTrace) *TraceLogger
  • func (logger *TraceLogger) AddDoneMsgs(dms ...string)
  • func (logger *TraceLogger) AddEntryPoints(eps ...string)
  • func (logger *TraceLogger) AddEnvironment() error
  • func (logger *TraceLogger) AddOnetDefaults(si *network.ServerIdentity)
  • func (logger *TraceLogger) AddStats(c *onet.Context, repeat time.Duration)
  • func (logger *TraceLogger) Close()
  • func (logger *TraceLogger) GetLoggerInfo() *log.LoggerInfo
  • func (logger *TraceLogger) Log(level int, msg string)
  • func (logger *TraceLogger) TraceID(id []byte)

Types

type Span

type Span interface {
	AddField(key string, val interface{})
	CreateChild(ctx context.Context) (context.Context, Span)
	Send()
}

Span interfaces the methods that are used by the wrappers, for easier testing and eventual usage of other tools than HoneyComb.

type Trace

type Trace interface {
	// AddFiled adds a key/val to the trace.
	//This key/val pair will be set to all spans contained in this trace.
	AddField(key string, val interface{})
	// There is at least one span for each trace, which is the root span.
	GetRootSpan() Span
	// Finishes the trace and sends it to the main service.
	// Once Send is called,
	//further interactions with the Trace structure are not defined.
	Send()
}

Trace interfaces the methods that are used by the wrappers, for easier testing and eventual usage of other tools.

type TraceLogger

type TraceLogger struct {
	// Don't create spans for calls that are not in entryPoints
	NoSingleSpans bool
	// Print spans that are not in entryPoints so that the slice can be updated.
	PrintSingleSpans int
	// LogLevel is the minimum log level that is sent to the tracing service
	LogLevel int
	// As the TraceLogger cannot use onet/log, turn on/off debug messages here.
	Debug bool
	// contains filtered or unexported fields
}

The TraceLogger implements the interface Logger to be registered in onet/log. It has also some convenience methods to connect to a standard cothority installation, including putting the nodeName in the logging information.

func NewHoneycombLogger

func NewHoneycombLogger(api, dataset string) *TraceLogger

NewHoneycombLogger sets up a new logger that is connected to a honeycomb trace-storage. The API can be found when signing up for a free account.

func NewHoneycombLoggerDebug

func NewHoneycombLoggerDebug() *TraceLogger

NewHoneycombLoggerDebug sets up a new honeycomb logger that will output all its data traces to stdout. Perfect for debugging...

func NewHoneycombLoggerFromEnv

func NewHoneycombLoggerFromEnv() (*TraceLogger, error)

NewHoneycombLoggerFromEnv checks the HONEYCOMB_API_KEY and extracts the api and dataset from it.

func NewLogger

func NewLogger(nt newTrace) *TraceLogger

NewLogger returns a new TraceLogger, already registered to the logging system. You might want to use the NewHoneyCombLogger or newSimulLogger instead, which make it easier to set up the tracing logger.

func (*TraceLogger) AddDoneMsgs

func (logger *TraceLogger) AddDoneMsgs(dms ...string)

AddDoneMsgs takes all given done messages and adds them to the internal list. Empty done messages are discarded.

func (*TraceLogger) AddEntryPoints

func (logger *TraceLogger) AddEntryPoints(eps ...string)

AddEntryPoints takes all given entry points and adds them to the internal list. Empty entry points are discarded.

func (*TraceLogger) AddEnvironment

func (logger *TraceLogger) AddEnvironment() error

AddEnvironment reads the environment variables defined to initialize the variables. The following environmental variables are available:

• TRACING_PRINT_SINGLE_SPANS - output a stack trace of single spans to let you trace where you could/should add a TRACING_ENTRY_POINT
• TRACING_CREATE_SINGLE_SPANS - whenever there is no entry point found, the system can create single spans that are not linked together. This is a fallback to regular logging when we cannot simulate traces.
• TRACING_LOG_LEVEL - sets the minimal log level that is sent to the tracing service
• TRACING_DEBUG - if true, fmt.Println is used for some additional debugging messages, as onet/log cannot be used within the logger
• TRACING_ENTRY_POINTS - a "::" separated list of entry points that can be used to refine the tracing. The name of the entry points are the same as given by TRACING_PRINT_SINGLE_SPAN
• TRACING_DONE_MSGS - a "::" separated list of done msgs that will close the started trace. This is due to the simulation of actual traces, because we can't really know when the trace should end.

func (*TraceLogger) AddOnetDefaults

func (logger *TraceLogger) AddOnetDefaults(si *network.ServerIdentity)

AddOnetDefaults sets a number of entry-points that are useful when running a project using onet. These entry-points allow to track quite accurately what is happening, both for the servie-calls over websockets, as well as the protocol-messages.

func (*TraceLogger) AddStats

func (logger *TraceLogger) AddStats(c *onet.Context, repeat time.Duration)

AddStats sends statistics of the current node on a regular basis to the tracing service. The sending stops once Logger.Close is called.

func (*TraceLogger) Close

func (logger *TraceLogger) Close()

Close implements the Logger interface.

func (*TraceLogger) GetLoggerInfo

func (logger *TraceLogger) GetLoggerInfo() *log.LoggerInfo

GetLoggerInfo implements the Logger interface.

func (*TraceLogger) Log

func (logger *TraceLogger) Log(level int, msg string)

Log implements the Logger interface. It calls the getTraceSpan with the appropriate callLvl to remove the stack trace due to onet/log.

func (*TraceLogger) TraceID

func (logger *TraceLogger) TraceID(id []byte)

TraceID stores the go-routine ID / TraceID pair for help in merging new go-routines.