package loggabletracer import ( "time" writer "github.com/ipfs/go-log/writer" opentracing "github.com/opentracing/opentracing-go" ) // Tracer extends the opentracing.Tracer interface with methods to // probe implementation state, for use by loggabletracer consumers. type Tracer interface { opentracing.Tracer // Options gets the Options used in New() or NewWithOptions(). Options() Options } // Options allows creating a customized Tracer via NewWithOptions. The object // must not be updated when there is an active tracer using it. type Options struct { // ShouldSample is a function which is called when creating a new Span and // determines whether that Span is sampled. The randomized TraceID is supplied // to allow deterministic sampling decisions to be made across different nodes. // For example, // // func(traceID uint64) { return traceID % 64 == 0 } // // samples every 64th trace on average. ShouldSample func(traceID uint64) bool // TrimUnsampledSpans turns potentially expensive operations on unsampled // Spans into no-ops. More precisely, tags and log events are silently // discarded. If NewSpanEventListener is set, the callbacks will still fire. TrimUnsampledSpans bool // Recorder receives Spans which have been finished. Recorder SpanRecorder // NewSpanEventListener can be used to enhance the tracer by effectively // attaching external code to trace events. See NetTraceIntegrator for a // practical example, and event.go for the list of possible events. NewSpanEventListener func() func(SpanEvent) // DropAllLogs turns log events on all Spans into no-ops. // If NewSpanEventListener is set, the callbacks will still fire. DropAllLogs bool // MaxLogsPerSpan limits the number of Logs in a span (if set to a nonzero // value). If a span has more logs than this value, logs are dropped as // necessary (and replaced with a log describing how many were dropped). // // About half of the MaxLogPerSpan logs kept are the oldest logs, and about // half are the newest logs. // // If NewSpanEventListener is set, the callbacks will still fire for all log // events. This value is ignored if DropAllLogs is true. MaxLogsPerSpan int // DebugAssertSingleGoroutine internally records the ID of the goroutine // creating each Span and verifies that no operation is carried out on // it on a different goroutine. // Provided strictly for development purposes. // Passing Spans between goroutine without proper synchronization often // results in use-after-Finish() errors. For a simple example, consider the // following pseudocode: // // func (s *Server) Handle(req http.Request) error { // sp := s.StartSpan("server") // defer sp.Finish() // wait := s.queueProcessing(opentracing.ContextWithSpan(context.Background(), sp), req) // select { // case resp := <-wait: // return resp.Error // case <-time.After(10*time.Second): // sp.LogEvent("timed out waiting for processing") // return ErrTimedOut // } // } // // This looks reasonable at first, but a request which spends more than ten // seconds in the queue is abandoned by the main goroutine and its trace // finished, leading to use-after-finish when the request is finally // processed. Note also that even joining on to a finished Span via // StartSpanWithOptions constitutes an illegal operation. // // Code bases which do not require (or decide they do not want) Spans to // be passed across goroutine boundaries can run with this flag enabled in // tests to increase their chances of spotting wrong-doers. DebugAssertSingleGoroutine bool // DebugAssertUseAfterFinish is provided strictly for development purposes. // When set, it attempts to exacerbate issues emanating from use of Spans // after calling Finish by running additional assertions. DebugAssertUseAfterFinish bool // EnableSpanPool enables the use of a pool, so that the tracer reuses spans // after Finish has been called on it. Adds a slight performance gain as it // reduces allocations. However, if you have any use-after-finish race // conditions the code may panic. EnableSpanPool bool } // DefaultOptions returns an Options object with a 1 in 64 sampling rate and // all options disabled. A Recorder needs to be set manually before using the // returned object with a Tracer. func DefaultOptions() Options { return Options{ ShouldSample: func(traceID uint64) bool { return traceID%64 == 0 }, MaxLogsPerSpan: 100, } } // NewWithOptions creates a customized Tracer. func NewWithOptions(opts Options) opentracing.Tracer { rval := &LoggableTracer{options: opts} rval.accessorPropagator = &accessorPropagator{rval} return rval } // New creates and returns a standard Tracer which defers completed Spans to // `recorder`. // Spans created by this Tracer support the ext.SamplingPriority tag: Setting // ext.SamplingPriority causes the Span to be Sampled from that point on. func New(recorder SpanRecorder) opentracing.Tracer { opts := DefaultOptions() opts.Recorder = recorder return NewWithOptions(opts) } // Implements the `Tracer` interface. type LoggableTracer struct { options Options textPropagator *textMapPropagator binaryPropagator *binaryPropagator accessorPropagator *accessorPropagator } func (t *LoggableTracer) StartSpan( operationName string, opts ...opentracing.StartSpanOption, ) opentracing.Span { if !writer.WriterGroup.Active() { return opentracing.NoopTracer.StartSpan(opentracing.NoopTracer{}, operationName) } sso := opentracing.StartSpanOptions{} for _, o := range opts { o.Apply(&sso) } return t.StartSpanWithOptions(operationName, sso) } func (t *LoggableTracer) getSpan() *spanImpl { if t.options.EnableSpanPool { sp := spanPool.Get().(*spanImpl) sp.reset() return sp } return &spanImpl{} } func (t *LoggableTracer) StartSpanWithOptions( operationName string, opts opentracing.StartSpanOptions, ) opentracing.Span { if !writer.WriterGroup.Active() { return opentracing.NoopTracer.StartSpan(opentracing.NoopTracer{}, operationName) } // Start time. startTime := opts.StartTime if startTime.IsZero() { startTime = time.Now() } // Tags. tags := opts.Tags // Build the new span. This is the only allocation: We'll return this as // an opentracing.Span. sp := t.getSpan() // Look for a parent in the list of References. // // TODO: would be nice if loggabletracer did something with all // References, not just the first one. ReferencesLoop: for _, ref := range opts.References { switch ref.Type { case opentracing.ChildOfRef, opentracing.FollowsFromRef: refCtx, ok := ref.ReferencedContext.(SpanContext) if !ok { // Could be a noopSpanContext // Ignore that parent. continue } sp.raw.Context.TraceID = refCtx.TraceID sp.raw.Context.SpanID = randomID() sp.raw.Context.Sampled = refCtx.Sampled sp.raw.ParentSpanID = refCtx.SpanID if l := len(refCtx.Baggage); l > 0 { sp.raw.Context.Baggage = make(map[string]string, l) for k, v := range refCtx.Baggage { sp.raw.Context.Baggage[k] = v } } break ReferencesLoop } } if sp.raw.Context.TraceID == 0 { // No parent Span found; allocate new trace and span ids and determine // the Sampled status. sp.raw.Context.TraceID, sp.raw.Context.SpanID = randomID2() sp.raw.Context.Sampled = t.options.ShouldSample(sp.raw.Context.TraceID) } return t.startSpanInternal( sp, operationName, startTime, tags, ) } func (t *LoggableTracer) startSpanInternal( sp *spanImpl, operationName string, startTime time.Time, tags opentracing.Tags, ) opentracing.Span { sp.tracer = t if t.options.NewSpanEventListener != nil { sp.event = t.options.NewSpanEventListener() } sp.raw.Operation = operationName sp.raw.Start = startTime sp.raw.Duration = -1 sp.raw.Tags = tags if t.options.DebugAssertSingleGoroutine { sp.SetTag(debugGoroutineIDTag, curGoroutineID()) } defer sp.onCreate(operationName) return sp } type delegatorType struct{} // Delegator is the format to use for DelegatingCarrier. var Delegator delegatorType func (t *LoggableTracer) Inject(sc opentracing.SpanContext, format interface{}, carrier interface{}) error { if !writer.WriterGroup.Active() { return opentracing.NoopTracer.Inject(opentracing.NoopTracer{}, sc, format, carrier) } switch format { case opentracing.TextMap, opentracing.HTTPHeaders: return t.textPropagator.Inject(sc, carrier) case opentracing.Binary: return t.binaryPropagator.Inject(sc, carrier) } if _, ok := format.(delegatorType); ok { return t.accessorPropagator.Inject(sc, carrier) } return opentracing.ErrUnsupportedFormat } func (t *LoggableTracer) Extract(format interface{}, carrier interface{}) (opentracing.SpanContext, error) { if !writer.WriterGroup.Active() { return opentracing.NoopTracer.Extract(opentracing.NoopTracer{}, format, carrier) } switch format { case opentracing.TextMap, opentracing.HTTPHeaders: return t.textPropagator.Extract(carrier) case opentracing.Binary: return t.binaryPropagator.Extract(carrier) } if _, ok := format.(delegatorType); ok { return t.accessorPropagator.Extract(carrier) } return nil, opentracing.ErrUnsupportedFormat } func (t *LoggableTracer) Options() Options { return t.options }