Skip to content

Commit

Permalink
fix: profiler infinite loop after a long transaction (#725)
Browse files Browse the repository at this point in the history
Co-authored-by: Michael Hoffmann <michael.hoffmann@sentry.io>
  • Loading branch information
vaind and cleptric committed Oct 3, 2023
1 parent 7e37ede commit f1f0176
Show file tree
Hide file tree
Showing 3 changed files with 78 additions and 11 deletions.
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

0 comments on commit f1f0176

Please sign in to comment.