Skip to content

Commit

Permalink
fix(tracing): Make Span.Finish a no-op when the span is already finis…
Browse files Browse the repository at this point in the history
…hed (#660)
  • Loading branch information
tonyo authored Jul 5, 2023
1 parent 1b2ac13 commit 6db2fc7
Show file tree
Hide file tree
Showing 2 changed files with 60 additions and 28 deletions.
63 changes: 35 additions & 28 deletions tracing.go
Original file line number Diff line number Diff line change
Expand Up @@ -60,6 +60,8 @@ type Span struct { //nolint: maligned // prefer readability over optimal memory
contexts map[string]Context
// profiler instance if attached, nil otherwise.
profiler transactionProfiler
// a Once instance to make sure that Finish() is only called once.
finishOnce sync.Once
}

// TraceParentContext describes the context of a (remote) parent span.
Expand Down Expand Up @@ -196,35 +198,11 @@ func StartSpan(ctx context.Context, operation string, options ...SpanOption) *Sp

// Finish sets the span's end time, unless already set. If the span is the root
// of a span tree, Finish sends the span tree to Sentry as a transaction.
//
// The logic is executed at most once per span, so that (incorrectly) calling it twice
// never double sends to Sentry.
func (s *Span) Finish() {
// TODO(tracing): maybe make Finish run at most once, such that
// (incorrectly) calling it twice never double sends to Sentry.

// For the timing to be correct, the profiler must be stopped before s.EndTime.
var profile *profileInfo
if s.profiler != nil {
profile = s.profiler.Finish(s)
}

if s.EndTime.IsZero() {
s.EndTime = monotonicTimeSince(s.StartTime)
}

if !s.Sampled.Bool() {
return
}
event := s.toEvent()
if event == nil {
return
}

event.sdkMetaData.transactionProfile = profile

// TODO(tracing): add breadcrumbs
// (see https://github.com/getsentry/sentry-python/blob/f6f3525f8812f609/sentry_sdk/tracing.py#L372)

hub := hubFromContext(s.ctx)
hub.CaptureEvent(event)
s.finishOnce.Do(s.doFinish)
}

// Context returns the context containing the span.
Expand Down Expand Up @@ -353,6 +331,35 @@ func (s *Span) SetDynamicSamplingContext(dsc DynamicSamplingContext) {
}
}

// doFinish runs the actual Span.Finish() logic.
func (s *Span) doFinish() {
// For the timing to be correct, the profiler must be stopped before s.EndTime.
var profile *profileInfo
if s.profiler != nil {
profile = s.profiler.Finish(s)
}

if s.EndTime.IsZero() {
s.EndTime = monotonicTimeSince(s.StartTime)
}

if !s.Sampled.Bool() {
return
}
event := s.toEvent()
if event == nil {
return
}

event.sdkMetaData.transactionProfile = profile

// TODO(tracing): add breadcrumbs
// (see https://github.com/getsentry/sentry-python/blob/f6f3525f8812f609/sentry_sdk/tracing.py#L372)

hub := hubFromContext(s.ctx)
hub.CaptureEvent(event)
}

// sentryTracePattern matches either
//
// TRACE_ID - SPAN_ID
Expand Down
25 changes: 25 additions & 0 deletions tracing_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -980,3 +980,28 @@ func TestAdjustingTransactionSourceBeforeSending(t *testing.T) {
})
}
}

// This is a regression test for https://github.com/getsentry/sentry-go/issues/587
// Without the "spans can be finished only once" fix, this test will fail
// when run with race detection ("-race").
func TestSpanFinishConcurrentlyWithoutRaces(t *testing.T) {
ctx := NewTestContext(ClientOptions{
EnableTracing: true,
TracesSampleRate: 1,
})
transaction := StartTransaction(ctx, "op")

go func() {
for {
transaction.Finish()
}
}()

go func() {
for {
transaction.Finish()
}
}()

time.Sleep(50 * time.Millisecond)
}

0 comments on commit 6db2fc7

Please sign in to comment.