From 657a652153b51184fc743971963d74b2b2eb1e0d Mon Sep 17 00:00:00 2001 From: Ian Cottrell Date: Fri, 27 Mar 2020 18:59:18 -0400 Subject: [PATCH] internal/telemetry: add a synchronization to telemetry Some things that used to be safe due to the global lock now need ther own synchronization primitives. Fixes golang/go#38102 Change-Id: I03c692682d57620d96fe84b7dc74efae0d3f8f09 Reviewed-on: https://go-review.googlesource.com/c/tools/+/226317 Run-TryBot: Ian Cottrell Reviewed-by: Rebecca Stambler Reviewed-by: Robert Findley --- internal/lsp/debug/trace.go | 13 ++++--- internal/telemetry/export/metric/exporter.go | 4 ++ internal/telemetry/export/ocagent/ocagent.go | 8 ++-- internal/telemetry/export/trace.go | 39 ++++++++++++++++---- 4 files changed, 47 insertions(+), 17 deletions(-) diff --git a/internal/lsp/debug/trace.go b/internal/lsp/debug/trace.go index 53b4994658..1ea83aee5c 100644 --- a/internal/lsp/debug/trace.go +++ b/internal/lsp/debug/trace.go @@ -93,8 +93,8 @@ func (t *traces) ProcessEvent(ctx context.Context, ev event.Event, tags event.Ta SpanID: span.ID.SpanID, ParentID: span.ParentID, Name: span.Name, - Start: span.Start.At, - Tags: renderTags(span.Start.Tags()), + Start: span.Start().At, + Tags: renderTags(span.Start().Tags()), } t.unfinished[span.ID] = td // and wire up parents if we have them @@ -117,10 +117,11 @@ func (t *traces) ProcessEvent(ctx context.Context, ev event.Event, tags event.Ta } delete(t.unfinished, span.ID) - td.Finish = span.Finish.At - td.Duration = span.Finish.At.Sub(span.Start.At) - td.Events = make([]traceEvent, len(span.Events)) - for i, event := range span.Events { + td.Finish = span.Finish().At + td.Duration = span.Finish().At.Sub(span.Start().At) + events := span.Events() + td.Events = make([]traceEvent, len(events)) + for i, event := range events { td.Events[i] = traceEvent{ Time: event.At, Tags: renderTags(event.Tags()), diff --git a/internal/telemetry/export/metric/exporter.go b/internal/telemetry/export/metric/exporter.go index 914a7fc9ee..ebf59b0429 100644 --- a/internal/telemetry/export/metric/exporter.go +++ b/internal/telemetry/export/metric/exporter.go @@ -7,6 +7,7 @@ package metric import ( "context" + "sync" "time" "golang.org/x/tools/internal/telemetry/event" @@ -28,10 +29,13 @@ func (e *Config) subscribe(key event.Key, s subscriber) { } func (e *Config) Exporter(output event.Exporter) event.Exporter { + var mu sync.Mutex return func(ctx context.Context, ev event.Event, tagMap event.TagMap) context.Context { if !ev.IsRecord() { return output(ctx, ev, tagMap) } + mu.Lock() + defer mu.Unlock() var metrics []Data for it := ev.Tags(); it.Valid(); it.Advance() { tag := it.Tag() diff --git a/internal/telemetry/export/ocagent/ocagent.go b/internal/telemetry/export/ocagent/ocagent.go index 4c423eb00c..5af78612e4 100644 --- a/internal/telemetry/export/ocagent/ocagent.go +++ b/internal/telemetry/export/ocagent/ocagent.go @@ -198,10 +198,10 @@ func convertSpan(span *export.Span) *wire.Span { ParentSpanID: span.ParentID[:], Name: toTruncatableString(span.Name), Kind: wire.UnspecifiedSpanKind, - StartTime: convertTimestamp(span.Start.At), - EndTime: convertTimestamp(span.Finish.At), - Attributes: convertAttributes(event.Filter(span.Start.Tags(), event.Name)), - TimeEvents: convertEvents(span.Events), + StartTime: convertTimestamp(span.Start().At), + EndTime: convertTimestamp(span.Finish().At), + Attributes: convertAttributes(event.Filter(span.Start().Tags(), event.Name)), + TimeEvents: convertEvents(span.Events()), SameProcessAsParentSpan: true, //TODO: StackTrace? //TODO: Links? diff --git a/internal/telemetry/export/trace.go b/internal/telemetry/export/trace.go index ffe86add65..48e38631e8 100644 --- a/internal/telemetry/export/trace.go +++ b/internal/telemetry/export/trace.go @@ -7,6 +7,7 @@ package export import ( "context" "fmt" + "sync" "golang.org/x/tools/internal/telemetry/event" ) @@ -20,9 +21,10 @@ type Span struct { Name string ID SpanContext ParentID SpanID - Start event.Event - Finish event.Event - Events []event.Event + mu sync.Mutex + start event.Event + finish event.Event + events []event.Event } type contextKeyType int @@ -50,12 +52,14 @@ func Spans(output event.Exporter) event.Exporter { switch { case ev.IsLog(), ev.IsLabel(): if span := GetSpan(ctx); span != nil { - span.Events = append(span.Events, ev) + span.mu.Lock() + span.events = append(span.events, ev) + span.mu.Unlock() } case ev.IsStartSpan(): span := &Span{ Name: event.Name.Get(tagMap), - Start: ev, + start: ev, } if parent := GetSpan(ctx); parent != nil { span.ID.TraceID = parent.ID.TraceID @@ -67,7 +71,9 @@ func Spans(output event.Exporter) event.Exporter { ctx = context.WithValue(ctx, spanContextKey, span) case ev.IsEndSpan(): if span := GetSpan(ctx); span != nil { - span.Finish = ev + span.mu.Lock() + span.finish = ev + span.mu.Unlock() } case ev.IsDetach(): ctx = context.WithValue(ctx, spanContextKey, nil) @@ -80,10 +86,29 @@ func (s *SpanContext) Format(f fmt.State, r rune) { fmt.Fprintf(f, "%v:%v", s.TraceID, s.SpanID) } +func (s *Span) Start() event.Event { + // start never changes after construction, so we dont need to hold the mutex + return s.start +} + +func (s *Span) Finish() event.Event { + s.mu.Lock() + defer s.mu.Unlock() + return s.finish +} + +func (s *Span) Events() []event.Event { + s.mu.Lock() + defer s.mu.Unlock() + return s.events +} + func (s *Span) Format(f fmt.State, r rune) { + s.mu.Lock() + defer s.mu.Unlock() fmt.Fprintf(f, "%v %v", s.Name, s.ID) if s.ParentID.IsValid() { fmt.Fprintf(f, "[%v]", s.ParentID) } - fmt.Fprintf(f, " %v->%v", s.Start, s.Finish) + fmt.Fprintf(f, " %v->%v", s.start, s.finish) }