Skip to content
Draft
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
137 changes: 137 additions & 0 deletions src/TraceEvent/TraceEvent.Tests/Parsing/EventPipeParsing.cs
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,7 @@
using System.IO;
using System.Linq;
using System.Text;
using System.Threading;
using System.Threading.Tasks;
using Xunit;
using Xunit.Abstractions;
Expand Down Expand Up @@ -217,6 +218,142 @@ public async Task SessionStreaming(bool initialRundown)
}
}

#if NETCOREAPP3_0_OR_GREATER
[Fact]
#else
[Fact(Skip = "EventPipeSession connection is only available to target apps on .NET Core 3.0 or later")]
#endif
public async Task ResetCallStacksDiscardsInternedStacksAndKeepsInterning()
{
// In a real time session the call stack interning tables grow for the lifetime of the
// session: every distinct stack observed is interned and nothing is released, so a long
// running session grows without bound. ResetCallStacks discards them.
//
// This verifies both halves of the contract: the tables are actually emptied, and stacks
// observed afterwards are still interned and still resolve to methods.
const int MinimumInternedStacks = 8;

var client = new DiagnosticsClient(Process.GetCurrentProcess().Id);
var providers = new[]
{
new EventPipeProvider(SampleProfilerTraceEventParser.ProviderName, EventLevel.Informational),
};

using (var session = client.StartEventPipeSession(providers, requestRundown: false))
{
using (var traceSource = CreateFromEventPipeSession(session, EventPipeRundownConfiguration.Enable(client)))
{
var traceLog = traceSource.TraceLog;
var sampleEventParser = new SampleProfilerTraceEventParser(traceSource);

int stacksBeforeReset = 0;
int stacksAfterReset = -1;
// RunContinuationsAsynchronously so awaiting this cannot resume inline on the
// event processing thread - the continuation below stops the session and waits
// on the processing task, which would deadlock if it ran on that thread.
var stackAfterReset = new TaskCompletionSource<CallStackIndex>(TaskCreationOptions.RunContinuationsAsynchronously);

sampleEventParser.ThreadSample += delegate (ClrThreadSampleTraceData e)
{
// ResetCallStacks has to run on the thread that processes events, which is the
// thread this callback runs on.
if (stacksAfterReset < 0)
{
// Let enough distinct stacks accumulate for the 'before' value to be meaningful.
if (traceLog.CallStacks.Count < MinimumInternedStacks)
{
return;
}

stacksBeforeReset = traceLog.CallStacks.Count;
traceLog.ResetCallStacks();
stacksAfterReset = traceLog.CallStacks.Count;
return;
}

// Anything interned after the reset must still be usable.
CallStackIndex callStackIndex = e.CallStackIndex();
if (callStackIndex != CallStackIndex.Invalid)
{
stackAfterReset.TrySetResult(callStackIndex);
}
};

var processingTask = Task.Run(traceSource.Process);

// Keep a little work running so the sampler sees a variety of stacks.
var workDone = new CancellationTokenSource();
var workTask = Task.Run(() =>
{
while (!workDone.IsCancellationRequested)
{
RecursiveWork(12);
}
});

try
{
Task completed = await Task.WhenAny(stackAfterReset.Task, Task.Delay(TimeSpan.FromSeconds(60)));
Assert.True(completed == stackAfterReset.Task,
$"Timed out waiting for a call stack after the reset (interned before reset: {stacksBeforeReset}).");
}
finally
{
workDone.Cancel();
await workTask;
}

Assert.True(stacksBeforeReset >= MinimumInternedStacks,
$"Expected at least {MinimumInternedStacks} interned call stacks before the reset, saw {stacksBeforeReset}.");

// The interning tables were emptied.
Assert.Equal(0, stacksAfterReset);

// ...and interning continued to work afterwards, all the way through to a method name.
CallStackIndex postResetStack = await stackAfterReset.Task;
CodeAddressIndex codeAddressIndex = traceLog.CallStacks.CodeAddressIndex(postResetStack);
Assert.NotEqual(CodeAddressIndex.Invalid, codeAddressIndex);
MethodIndex methodIndex = traceLog.CodeAddresses.MethodIndex(codeAddressIndex);
Assert.NotEqual(MethodIndex.Invalid, methodIndex);
Assert.NotEmpty(traceLog.CodeAddresses.Methods[methodIndex].FullMethodName);
Assert.True(traceLog.CallStacks.Count > 0, "Expected the interning tables to refill after the reset.");

// Every index in a post-reset stack must refer to the *new* table. If any part of
// the interning state survived the reset (for example the per-thread roots), stale
// indexes from the old table leak back in here. Those do not throw - GrowableArray
// indexes its backing store without bounds checking against Count - so the stack
// would silently resolve to the wrong frames. Walking the whole chain and range
// checking each link is what actually catches that.
int stackCount = traceLog.CallStacks.Count;
int depth = 0;
for (CallStackIndex frame = postResetStack; frame != CallStackIndex.Invalid; frame = traceLog.CallStacks.Caller(frame))
{
Assert.InRange((int)frame, 0, stackCount - 1);
Assert.True(++depth <= stackCount,
"Walking the post-reset call stack did not terminate; the interning tables are inconsistent.");
}

session.Stop();
await processingTask;
}
}
}

private static long RecursiveWork(int depth)
{
if (depth <= 0)
{
double sink = 0;
for (int i = 1; i < 10000; i++)
{
sink += Math.Sqrt(i);
}
return (long)sink;
}

return RecursiveWork(depth - 1) + depth;
}

[Fact]
public void V1IsUnsupported()
{
Expand Down
49 changes: 49 additions & 0 deletions src/TraceEvent/TraceLog.cs
Original file line number Diff line number Diff line change
Expand Up @@ -975,6 +975,42 @@ private void FlushRealTimeEventsNoLock(int minimumAgeMs)
}
}

/// <summary>
/// Discards every call stack interned so far, releasing the memory held by the call stack
/// interning tables (see <see cref="CallStacks"/>).
/// <para>
/// In a real time session those tables grow for the lifetime of the session: every distinct
/// call stack that is observed is interned and nothing is ever released. For a long running
/// process with diverse stacks that growth is unbounded. Trace files do not have this problem
/// because the session is finite, which is why this is restricted to real time sessions.
/// </para>
/// <para>
/// Every <see cref="CallStackIndex"/> obtained before this call is invalidated and must not be
/// used afterwards, so only call this when no such index is still live. Call stacks observed
/// after the call are interned from scratch, so no information is lost going forward - only
/// the ability to resolve indexes handed out earlier.
/// </para>
/// <para>
/// Must be called from the thread that processes events (for example from within an event
/// callback). Calling it concurrently with event processing races with call stack interning.
/// </para>
/// </summary>
/// <exception cref="InvalidOperationException">The TraceLog is not a real time session.</exception>
public void ResetCallStacks()
{
if (!IsRealTime)
{
throw new InvalidOperationException("ResetCallStacks is only supported for real time sessions.");
}

callStacks.Clear();

// These map events to the indexes we just invalidated, so also need clearing.
// A length reset is enough here - they hold structs, so nothing is retained.
eventsToStacks.Clear();
cswitchBlockingEventsToStacks.Clear();
}

/// <summary>
/// Given a process's virtual address 'address' and an event which acts as a
/// context (determines which process and what time in that process), return
Expand Down Expand Up @@ -7821,6 +7857,19 @@ internal void SetSize(int origSize)
callStacks.RemoveRange(origSize, callStacks.Count - origSize);
}

/// <summary>
/// Discards every interned call stack, returning the interning tables to their initial state.
/// Only meaningful for a real time session, where these tables would otherwise grow for the
/// lifetime of the session. See <see cref="TraceLog.ResetCallStacks"/>.
/// </summary>
internal void Clear()
{
// GrowableArray.Clear() only resets the length so we have to assign fresh arrays
callStacks = new GrowableArray<CallStackInfo>();
callees = new GrowableArray<List<CallStackIndex>>();
threads = new GrowableArray<List<CallStackIndex>>();
}

/// <summary>
/// Returns an index that represents the 'threads' of the stack. It encodes the thread which owns this stack into this.
/// We encode this as -ThreadIndex - 2 (since -1 is the Invalid node)
Expand Down
Loading