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

fix: profiler infinite loop after a long transaction #725

Merged
merged 3 commits into from
Oct 3, 2023
Merged
Show file tree
Hide file tree
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
6 changes: 6 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
@@ -1,5 +1,11 @@
# Changelog

## Unreleased

### Bug fixes

- Fix an infinite loop in the profiler if a transaction's duration is longer than 30 seconds ([#725](https://github.com/getsentry/sentry-go/pull/725))

## 0.24.1

The Sentry SDK team is happy to announce the immediate availability of Sentry Go SDK v0.24.1.
Expand Down
36 changes: 25 additions & 11 deletions profiler.go
Original file line number Diff line number Diff line change
Expand Up @@ -236,18 +236,32 @@ func (p *profileRecorder) getBuckets(relativeStartNS, relativeEndNS uint64) (sam
return 0, nil, nil
}

// Search for the first item after the given startTime.
var start = end
samplesCount = 0
buckets = make([]*profileSamplesBucket, 0, int64((relativeEndNS-relativeStartNS)/uint64(profilerSamplingRate.Nanoseconds()))+1)
for start.Value != nil {
var bucket = start.Value.(*profileSamplesBucket)
if bucket.relativeTimeNS < relativeStartNS {
break
{ // Find the first item after the given startTime.
var start = end
var prevBucket *profileSamplesBucket
samplesCount = 0
buckets = make([]*profileSamplesBucket, 0, int64((relativeEndNS-relativeStartNS)/uint64(profilerSamplingRate.Nanoseconds()))+1)
for start.Value != nil {
var bucket = start.Value.(*profileSamplesBucket)

// If this bucket's time is before the requests start time, don't collect it (and stop iterating further).
if bucket.relativeTimeNS < relativeStartNS {
break
}

// If this bucket time is greater than previous the bucket's time, we have exhausted the whole ring buffer
// before we were able to find the start time. That means the start time is not present and we must break.
// This happens if the slice duration exceeds the ring buffer capacity.
if prevBucket != nil && bucket.relativeTimeNS > prevBucket.relativeTimeNS {
break
}

samplesCount += len(bucket.goIDs)
buckets = append(buckets, bucket)

start = start.Prev()
prevBucket = bucket
}
samplesCount += len(bucket.goIDs)
buckets = append(buckets, bucket)
start = start.Prev()
}

// Edge case - if the period requested was too short and we haven't collected enough samples.
Expand Down
47 changes: 47 additions & 0 deletions profiler_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -126,6 +126,53 @@ func TestProfilerCollection(t *testing.T) {
})
}

func TestProfilerRingBufferOverflow(t *testing.T) {
if testing.Short() {
t.Skip("Skipping in short mode.")
}

var require = require.New(t)
ticker := setupProfilerTestTicker(io.Discard)
defer restoreProfilerTicker()

profiler := startProfiling(time.Now())
defer profiler.Stop(true)

// Skip a few ticks to emulate the profiler already running before a transaction starts
for i := 0; i < 100; i++ {
require.True(ticker.Tick())
}
start := time.Now()

// Emulate a transaction running for longer than the limit (30 seconds).
// The buffer should be 3030 items long, i.e. 30 seconds * 101 samples per second.
recorder := profiler.(*profileRecorder)
require.Equal(3030, recorder.samplesBucketsHead.Len())
for i := 0; i < recorder.samplesBucketsHead.Len(); i++ {
require.True(ticker.Tick())
}

// Add a few more ticks after the transaction ends but prior collecting it.
// This emulates how the SDK normally behaves.
const ticksAfterEnd = 5
end := time.Now()
for i := 0; i < ticksAfterEnd; i++ {
require.True(ticker.Tick())
}

result := profiler.GetSlice(start, end)
require.NotNil(result)
validateProfile(t, result.trace, end.Sub(start))

// Calculate the number of buckets (profiler internal representation).
// It should be the same as the length of the ring buffer minus ticksAfterEnd.
buckets := make(map[uint64]bool)
for _, sample := range result.trace.Samples {
buckets[sample.ElapsedSinceStartNS] = true
}
require.Equal(recorder.samplesBucketsHead.Len()-ticksAfterEnd, len(buckets))
}

// Check the order of frames for a known stack trace (i.e. this test case).
func TestProfilerStackTrace(t *testing.T) {
var require = require.New(t)
Expand Down