Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Avoid unnecessary time.Since() when ending spans if the endTime is already specified #3143

Open
wants to merge 2 commits into
base: main
Choose a base branch
from
Open
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
18 changes: 10 additions & 8 deletions sdk/trace/span.go
Original file line number Diff line number Diff line change
Expand Up @@ -367,17 +367,24 @@ func (s *recordingSpan) End(options ...trace.SpanEndOption) {
return
}

config := trace.NewSpanEndConfig(options...)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What other impact can moving the processing of config options before the IsRecording() short-circuit have?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hi @Aneurysm9, we only have two kinds of SpanEndOption, which are trace.WithStackTrace and trace.WithTimestamp. And the config := trace.NewSpanEndConfig(options...) is allocating on the stack, no GC impact. Therefore the impact will be looping at most two iterations on the options.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Does anyone understand the comment below this, "now that we have an end time and see if we need to do any more processing."

I can't see why we'd compute the timestamp before the short-circuit.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Does anyone understand the comment below this, "now that we have an end time and see if we need to do any more processing."

I can't see why we'd compute the timestamp before the short-circuit.

Because if we didn't the end time would be less accurate.


// Store the end time as soon as possible to avoid artificially increasing
// the span's duration in case some operation below takes a while.
et := internal.MonotonicEndTime(s.startTime)
var et time.Time
// Setting endTime to non-zero marks the span as ended and not recording.
if config.Timestamp().IsZero() {
et = internal.MonotonicEndTime(s.startTime)
} else {
et = config.Timestamp()
}

// Do relative expensive check now that we have an end time and see if we
// need to do any more processing.
if !s.IsRecording() {
return
}

config := trace.NewSpanEndConfig(options...)
if recovered := recover(); recovered != nil {
// Record but don't stop the panic.
defer panic(recovered)
Expand All @@ -402,12 +409,7 @@ func (s *recordingSpan) End(options ...trace.SpanEndOption) {
}

s.mu.Lock()
// Setting endTime to non-zero marks the span as ended and not recording.
if config.Timestamp().IsZero() {
s.endTime = et
} else {
s.endTime = config.Timestamp()
}
s.endTime = et
s.mu.Unlock()

sps := s.tracer.provider.spanProcessors.Load().(spanProcessorStates)
Expand Down