Skip to content
Merged
Show file tree
Hide file tree
Changes from 14 commits
Commits
Show all changes
20 commits
Select commit Hold shift + click to select a range
25f23d8
deps: update perfview (removes the .il suffix from profile module names)
jamescrosswell Aug 23, 2026
fad203f
fix: bound profiler memory growth by trimming interned call stacks
jamescrosswell Aug 23, 2026
9d90d21
Tweak comments
jamescrosswell Aug 24, 2026
05a1957
Fail loudly if the TraceLog reflection target moves
jamescrosswell Aug 24, 2026
ef4fa83
Merge deps/update-perfview into fix/5469-trim-live-session-state
jamescrosswell Aug 24, 2026
ab58925
Merge remote comment tweaks
jamescrosswell Aug 24, 2026
e3d582a
Apply suggestion from @jamescrosswell
jamescrosswell Aug 24, 2026
b7db5ae
Dispose the EventPipeEventSource in the test helper
jamescrosswell Aug 24, 2026
a656b43
Merge remote comment removal
jamescrosswell Aug 24, 2026
50c51ef
Merge deps/update-perfview
jamescrosswell Aug 24, 2026
a9f09c4
Commit the regenerated sample.etlx instead of building it at test time
jamescrosswell Aug 24, 2026
129412c
Merge deps/update-perfview
jamescrosswell Aug 24, 2026
6638df7
Trim on a generation counter instead of waiting for an idle window
jamescrosswell Aug 25, 2026
21be80c
Concise comments
jamescrosswell Aug 25, 2026
cac6367
Note that a trim costs the in-flight sample
jamescrosswell Aug 25, 2026
955f72e
Merge concise comments
jamescrosswell Aug 25, 2026
137714e
Stop the trim tests racing the dispatch thread
jamescrosswell Aug 25, 2026
1456cea
Merge main
jamescrosswell Aug 26, 2026
8da501d
Latch off trimming after a failure instead of retrying every sample
jamescrosswell Aug 31, 2026
908f26f
Make the call stack budget per-factory rather than a static
jamescrosswell Aug 31, 2026
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
2 changes: 1 addition & 1 deletion modules/perfview
Submodule perfview updated 324 files
20 changes: 20 additions & 0 deletions src/Sentry.Profiling/SampleProfileBuilder.cs
Original file line number Diff line number Diff line change
Expand Up @@ -11,8 +11,12 @@ namespace Sentry.Profiling;
internal class SampleProfileBuilder
{
private readonly SentryOptions _options;
private readonly SampleProfilerSession? _session;
private readonly TraceLog _traceLog;

// The trim generation this builder's _stackIndexes cache was populated against.
private int _trimGeneration;

// Output profile being built.
public readonly SampleProfile Profile = new();

Expand All @@ -32,14 +36,30 @@ internal class SampleProfileBuilder
// TODO make downsampling conditional once this is available: https://github.com/dotnet/runtime/issues/82939
private readonly Downsampler _downsampler = new();

// For a TraceLog read from a file, where nothing trims it and no generation tracking is needed.
public SampleProfileBuilder(SentryOptions options, TraceLog traceLog)
{
_options = options;
_traceLog = traceLog;
}

public SampleProfileBuilder(SentryOptions options, SampleProfilerSession session)
: this(options, session.TraceLog)
{
_session = session;
_trimGeneration = session.TrimGeneration;
}

internal void AddSample(TraceEvent data, double timestampMs)
{
// The interning tables have been discarded since we last looked so we have to
// invalidate the _stackIndexes cache (means stacks get walked again)
if (_session is { } session && _trimGeneration != session.TrimGeneration)
{
_trimGeneration = session.TrimGeneration;
_stackIndexes.Clear();
}
Comment thread
jamescrosswell marked this conversation as resolved.

var thread = data.Thread();
if (thread is null || thread.ThreadIndex == ThreadIndex.Invalid)
{
Expand Down
14 changes: 14 additions & 0 deletions src/Sentry.Profiling/SampleProfilerSession.cs
Original file line number Diff line number Diff line change
Expand Up @@ -56,6 +56,20 @@ private SampleProfilerSession(SentryStopwatch stopwatch, EventPipeSession sessio

public TraceLog TraceLog => EventSource.TraceLog;

// Bumped every time the interning tables are discarded. Anything caching a
// CallStackIndex can invalidate it's cache whenever this changes
internal int TrimGeneration;

/// <summary>
/// Discards TraceLog's call stack interning tables, invalidating CallStackIndexes.
/// Must be called from the event processing thread.
/// </summary>
internal void TrimLiveSessionState()
{
TraceLog.TrimLiveSessionState();
TrimGeneration++;
}

private static InterlockedBoolean _throwOnNextStartupForTests = false;

internal static bool ThrowOnNextStartupForTests
Expand Down
2 changes: 1 addition & 1 deletion src/Sentry.Profiling/SamplingTransactionProfiler.cs
Original file line number Diff line number Diff line change
Expand Up @@ -24,7 +24,7 @@ public SamplingTransactionProfiler(SentryOptions options, SampleProfilerSession
_cancellationToken = cancellationToken;
_startTimeMs = session.Elapsed.TotalMilliseconds;
_endTimeMs = double.MaxValue;
_processor = new SampleProfileBuilder(options, session.TraceLog);
_processor = new SampleProfileBuilder(options, session);
session.SampleEventParser.ThreadSample += OnThreadSample;
cancellationToken.Register(() =>
{
Expand Down
44 changes: 44 additions & 0 deletions src/Sentry.Profiling/SamplingTransactionProfilerFactory.cs
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
using Microsoft.Diagnostics.Tracing;
using Sentry.Extensibility;
using Sentry.Internal;

Expand All @@ -14,10 +15,17 @@ internal class SamplingTransactionProfilerFactory : IDisposable, ITransactionPro
// Stop profiling after the given number of milliseconds.
private const int TIME_LIMIT_MS = 30_000;

// Once the interning tables exceed this many entries we discard them ASAP
internal static int MaxCallStackCount = 100_000;

private readonly SentryOptions _options;

internal Task<SampleProfilerSession> _sessionTask;

private volatile SampleProfilerSession? _session;

internal int TrimCount;

private bool _errorLogged = false;

public SamplingTransactionProfilerFactory(SentryOptions options, TimeSpan startupTimeout)
Expand All @@ -32,6 +40,9 @@ public SamplingTransactionProfilerFactory(SentryOptions options, TimeSpan startu
// This can block indefinitely.
await session.WaitForFirstEventAsync().ConfigureAwait(false);

_session = session;
session.SampleEventParser.ThreadSample += TrimSessionStateIfNeeded;

return session;
});

Expand Down Expand Up @@ -81,6 +92,39 @@ public SamplingTransactionProfilerFactory(SentryOptions options, TimeSpan startu
return null;
}

/// <summary>
/// Discards TraceLog's call stack interning tables once they grow past <see cref="MaxCallStackCount"/>.
/// <para>
/// Runs for every sample, on the session's event processing thread - which is the only thread
/// allowed to trim, so this is where it has to happen. It cannot be driven off profile completion
/// alone, because the tables grow whether or not a profile is running.
/// </para>
/// <para>
/// Safe to do mid-profile: SampleProfileBuilder keys a cache off CallStackIndex, which a trim
/// reissues from zero, but it notices the bumped generation and drops that cache.
/// </para>
/// </summary>
private void TrimSessionStateIfNeeded(TraceEvent data)
{
var session = _session;
if (session is null || session.TraceLog.CallStacks.Count <= MaxCallStackCount)
{
return;
}

try
{
_options.LogDebug("Trimming profiler session state, {0} interned call stacks.", session.TraceLog.CallStacks.Count);
session.TrimLiveSessionState();
TrimCount++;
}
catch (Exception e)
{
// Never let this take down event processing for the whole session.
_options.LogWarning(e, "Failed to trim profiler session state.");
Comment thread
jamescrosswell marked this conversation as resolved.
Outdated
}
}
Comment thread
cursor[bot] marked this conversation as resolved.

public void Dispose()
{
_sessionTask.ContinueWith(session => session.Dispose());
Expand Down
24 changes: 24 additions & 0 deletions test/Sentry.Profiling.Tests/Resources/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -49,3 +49,27 @@ And for reference, you can create a JSON that can be displayed by [SpeedScope](h
```shell-script
dotnet-trace convert sample.nettrace --format Speedscope
```

## Regenerating `sample.etlx` after a perfview submodule bump

`sample.etlx` is committed, and its format version is tied to the TraceEvent build in
`modules/perfview`. A submodule bump can therefore leave it unreadable, which surfaces as:

```
FastSerialization.SerializationException : File format is version 74 App accepts formats >= 78.
```

To regenerate it, delete the file and run the tests once — `TraceLogProcessorTests` rebuilds it from
`sample.nettrace` when it is absent:

```shell-script
rm test/Sentry.Profiling.Tests/Resources/sample.etlx
dotnet test test/Sentry.Profiling.Tests --filter "FullyQualifiedName~TraceLogProcessorTests"
```

Then commit the regenerated file, along with any `*.verified.txt` snapshot changes it produces
(`pwsh ./scripts/accept-verifier-changes.ps1` — review the diff, module names in particular).

Do **not** leave it uncommitted and rely on regeneration at test time. The path is shared by every
target framework, and `dotnet test` runs one host per TFM, so they race on both this file and the
`sample.etlx.new` temp that TraceEvent writes alongside it.
Binary file modified test/Sentry.Profiling.Tests/Resources/sample.etlx
Binary file not shown.
116 changes: 116 additions & 0 deletions test/Sentry.Profiling.Tests/SamplingTransactionProfilerTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -457,6 +457,122 @@ public void ProfilerIntegration_WithProfilingEnabled_SetsFactory()
Assert.NotNull(hub.Options.TransactionProfilerFactory);
}

[SkippableFact]
public void Profiler_WhenNoProfileRunning_TrimsInternedCallStacks()
{
Skip.If(TestEnvironment.IsGitHubActions, "Flaky in CI.");

// The interning tables grow whether or not a profile is running, so this deliberately never
// starts one - the trim has to happen off the back of ordinary samples. See #5469.
var originalMax = SamplingTransactionProfilerFactory.MaxCallStackCount;
SamplingTransactionProfilerFactory.MaxCallStackCount = 100;

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

🤖 says

SamplingTransactionProfilerTests carries [CollectionDefinition(..., DisableParallelization = true)] on itself, which defines a collection but doesn't join it — xUnit needs [Collection(name)] on the class. Tests inside one class serialize regardless, so the two new tests can't collide with each other. But ProfilingSentryOptionsExtensionsTests runs in a separate collection, and HubDispose_* starts real EventPipe sessions — those will run with a budget of 100 during the 3-second windows. Harmless today (they only assert IsDisposed), but it's a trap for the next test that asserts on profile content. An instance field on the factory instead of a static removes the global mutation and both try/finally blocks.

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

Good catch... fixed (partially) in 908f26f

Also created:

That might explain why we've had issues with flaky profiling tests (locally and in CI).

try
{
using var factory = new SamplingTransactionProfilerFactory(_testSentryOptions, TimeSpan.FromSeconds(30));
SkipIfFailsInCI(() => factory._sessionTask.Wait(60_000));
var traceLog = factory._sessionTask.Result.TraceLog;

// Produce a variety of stack shapes so the sampler has something to intern.
var stopwatch = Stopwatch.StartNew();
var random = new Random(4242);
var highWaterMark = 0;
while (stopwatch.ElapsedMilliseconds < 3_000 && factory.TrimCount == 0)
{
RecursiveWork(random.Next(8, 24), random);
highWaterMark = Math.Max(highWaterMark, traceLog.CallStacks.Count);
}

SkipIfFailsInCI(() =>
{
if (factory.TrimCount == 0)
{
throw new Exception($"No trim occurred; call stacks peaked at {highWaterMark}.");
}
});

// Having trimmed at least once, the table must have been reset rather than left to grow.
Assert.True(factory.TrimCount > 0, $"Expected at least one trim, call stacks peaked at {highWaterMark}.");
Assert.True(traceLog.CallStacks.Count < highWaterMark,
$"Expected the interning table to shrink after trimming, but it is {traceLog.CallStacks.Count} against a peak of {highWaterMark}.");
}
finally
{
SamplingTransactionProfilerFactory.MaxCallStackCount = originalMax;
}
}

[SkippableFact]
public void Profiler_WhileProfileRunning_StillTrimsInternedCallStacks()
{
Skip.If(TestEnvironment.IsGitHubActions, "Flaky in CI.");

// A profile is held open for the whole test. Trimming must still happen: profiles can run
// back to back under load, so gating the trim on "no profile running" would starve it
// exactly when the tables grow fastest. The profile is then collected to show that trimming
// mid-profile does not corrupt its output.
var originalMax = SamplingTransactionProfilerFactory.MaxCallStackCount;
SamplingTransactionProfilerFactory.MaxCallStackCount = 100;
try
{
using var factory = new SamplingTransactionProfilerFactory(_testSentryOptions, TimeSpan.FromSeconds(30));
SkipIfFailsInCI(() => factory._sessionTask.Wait(60_000));

var clock = SentryStopwatch.StartNew();
var transactionTracer = new TransactionTracer(Substitute.For<IHub>(), "test", "");
var sut = factory.Start(transactionTracer, CancellationToken.None) as SamplingTransactionProfiler;
SkipIfFailsInCI(() => ArgumentNullException.ThrowIfNull(sut));
transactionTracer.TransactionProfiler = sut;

// Discard trims from before the profile started - the tiny budget means the session
// startup alone can trigger one. From here every trim happens while _inProgress is true.
factory.TrimCount = 0;

var stopwatch = Stopwatch.StartNew();
var random = new Random(4242);
while (stopwatch.ElapsedMilliseconds < 5_000 && factory.TrimCount == 0)
{
RecursiveWork(random.Next(8, 24), random);
}

SkipIfFailsInCI(() =>
{
if (factory.TrimCount == 0)
{
throw new Exception("No trim occurred while a profile was running.");
}
});
Assert.True(factory.TrimCount > 0, "Expected trimming to happen even while a profile is running.");

sut!.Finish();
var elapsedNanoseconds = (ulong)((clock.CurrentDateTimeOffset - clock.StartDateTimeOffset).TotalMilliseconds * 1_000_000);
var collectTask = sut.CollectAsync(new SentryTransaction(transactionTracer));
collectTask.Wait();
ValidateProfile(collectTask.Result.Profile, elapsedNanoseconds);
}
finally
{
SamplingTransactionProfilerFactory.MaxCallStackCount = originalMax;
}
}

private static long RecursiveWork(int depth, Random random)
{
if (depth <= 0)
{
double sink = 0;
for (var i = 1; i < 5_000; i++)
{
sink += Math.Sqrt(i);
}
return (long)sink;
}

// Branch so that different calls produce different stack shapes.
return (random.Next(2) == 0)
? RecursiveWork(depth - 1, random) + depth
: RecursiveWork(depth - 1, random) - depth;
}

[SkippableFact]
public void Downsampler_ShouldSample_Works()
{
Expand Down
Loading
Loading