Skip to content

Commit 906b19d

Browse files
authored
Stack view for Contention events (#2000)
* Stack view for Contention events Metric is equal to the duration of contention in milliseconds EventData DurationNs fake frame * Include the same view for WaitHandleWait event * Fixed some comments * More fixes * Fixed documentation and class names
1 parent 2402837 commit 906b19d

File tree

4 files changed

+433
-0
lines changed

4 files changed

+433
-0
lines changed

.gitignore

+3
Original file line numberDiff line numberDiff line change
@@ -205,3 +205,6 @@ OSExtensions.cs
205205
password.txt
206206
documentation/internal/
207207
*.userosscache
208+
209+
# Rider
210+
.idea/

src/PerfView/PerfViewData.cs

+119
Original file line numberDiff line numberDiff line change
@@ -37,6 +37,7 @@
3737
using System.Windows;
3838
using System.Windows.Media;
3939
using System.Xml;
40+
using Microsoft.Diagnostics.Tracing.Computers;
4041
using Microsoft.Diagnostics.Tracing.Parsers.Tpl;
4142
using Utilities;
4243
using Address = System.UInt64;
@@ -994,6 +995,19 @@ protected bool IsMyFormat(string fileName)
994995

995996
private static Dictionary<string, PerfViewFile> s_internTable = new Dictionary<string, PerfViewFile>();
996997
#endregion
998+
999+
protected static void ConfigureStackWindowForStartStopThreadTime(StackWindow stackWindow)
1000+
{
1001+
var foldPats = StartStopLatencyComputer.GetDefaultFoldPatterns();
1002+
for (var i = 0; i < foldPats.Length; i++)
1003+
{
1004+
if (i == 0)
1005+
{
1006+
stackWindow.FoldRegExTextBox.Text = foldPats[i];
1007+
}
1008+
stackWindow.FoldRegExTextBox.Items.Insert(0, foldPats[i]);
1009+
}
1010+
}
9971011
}
9981012

9991013
// Used for new user defined file formats.
@@ -6289,6 +6303,28 @@ string GetAllocationType(CallStackIndex csi)
62896303

62906304
return stackSource;
62916305
}
6306+
else if (streamName == "Contention")
6307+
{
6308+
var contentionSource = new MutableTraceEventStackSource(eventLog);
6309+
contentionSource.ShowUnknownAddresses = App.CommandLineArgs.ShowUnknownAddresses;
6310+
contentionSource.ShowOptimizationTiers = App.CommandLineArgs.ShowOptimizationTiers;
6311+
6312+
var computer = new ContentionLatencyComputer(eventLog, contentionSource);
6313+
computer.GenerateStacks();
6314+
6315+
return contentionSource;
6316+
}
6317+
else if (streamName == "WaitHandleWait")
6318+
{
6319+
var waitHandleWaitSource = new MutableTraceEventStackSource(eventLog);
6320+
waitHandleWaitSource.ShowUnknownAddresses = App.CommandLineArgs.ShowUnknownAddresses;
6321+
waitHandleWaitSource.ShowOptimizationTiers = App.CommandLineArgs.ShowOptimizationTiers;
6322+
6323+
var computer = new WaitHandleWaitLatencyComputer(eventLog, waitHandleWaitSource);
6324+
computer.GenerateStacks();
6325+
6326+
return waitHandleWaitSource;
6327+
}
62926328
else
62936329
{
62946330
throw new Exception("Unknown stream " + streamName);
@@ -7010,6 +7046,11 @@ protected internal override void ConfigureStackWindow(string stackSourceName, St
70107046
stackWindow.FoldRegExTextBox.Text = prev;
70117047
stackWindow.FoldRegExTextBox.Items.Insert(0, prev);
70127048
}
7049+
7050+
if (stackSourceName == "Contention" || stackSourceName == "WaitHandleWait")
7051+
{
7052+
ConfigureStackWindowForStartStopThreadTime(stackWindow);
7053+
}
70137054

70147055
if (m_extraTopStats != null)
70157056
{
@@ -7033,6 +7074,7 @@ protected internal override void ConfigureStackWindow(string stackSourceName, St
70337074
}
70347075
}
70357076
}
7077+
70367078
public override bool SupportsProcesses { get { return true; } }
70377079

70387080
/// <summary>
@@ -7160,6 +7202,8 @@ protected override Action<Action> OpenImpl(Window parentWindow, StatusBar worker
71607202
bool hasAssemblyLoad = false;
71617203
bool hasJIT = false;
71627204
bool hasUserCrit = false;
7205+
bool hasContention = false;
7206+
bool hasWaitHandle = false;
71637207

71647208
var stackEvents = new List<TraceEventCounts>();
71657209
foreach (var counts in tracelog.Stats)
@@ -7237,6 +7281,16 @@ protected override Action<Action> OpenImpl(Window parentWindow, StatusBar worker
72377281
hasUserCrit = true;
72387282
}
72397283

7284+
if (name.StartsWith("Contention/Start"))
7285+
{
7286+
hasContention = true;
7287+
}
7288+
7289+
if (name.StartsWith("WaitHandleWait/Start"))
7290+
{
7291+
hasWaitHandle = true;
7292+
}
7293+
72407294
if (counts.StackCount > 0)
72417295
{
72427296
hasAnyStacks = true;
@@ -7495,6 +7549,16 @@ protected override Action<Action> OpenImpl(Window parentWindow, StatusBar worker
74957549
}
74967550
}
74977551

7552+
if (hasContention)
7553+
{
7554+
advanced.Children.Add(new PerfViewStackSource(this, "Contention"));
7555+
}
7556+
7557+
if (hasWaitHandle)
7558+
{
7559+
advanced.Children.Add(new PerfViewStackSource(this, "WaitHandleWait"));
7560+
}
7561+
74987562
if (hasAnyStacks)
74997563
{
75007564
advanced.Children.Add(new PerfViewStackSource(this, "Any"));
@@ -8920,6 +8984,8 @@ protected override Action<Action> OpenImpl(Window parentWindow, StatusBar worker
89208984
bool hasMemAllocStacks = false;
89218985
bool hasTypeLoad = false;
89228986
bool hasAssemblyLoad = false;
8987+
bool hasContention = false;
8988+
bool hasWaitHandle = false;
89238989
if (m_traceLog != null)
89248990
{
89258991
foreach (TraceEventCounts eventStats in m_traceLog.Stats)
@@ -8961,6 +9027,14 @@ protected override Action<Action> OpenImpl(Window parentWindow, StatusBar worker
89619027
{
89629028
hasAssemblyLoad = true;
89639029
}
9030+
else if (eventStats.EventName.StartsWith("Contention/Start"))
9031+
{
9032+
hasContention = true;
9033+
}
9034+
else if (eventStats.EventName.StartsWith("WaitHandleWait/Start"))
9035+
{
9036+
hasWaitHandle = true;
9037+
}
89649038
}
89659039
}
89669040

@@ -9012,6 +9086,16 @@ protected override Action<Action> OpenImpl(Window parentWindow, StatusBar worker
90129086
{
90139087
advanced.AddChild(new PerfViewRuntimeLoaderStats(this));
90149088
}
9089+
9090+
if (hasContention)
9091+
{
9092+
advanced.AddChild(new PerfViewStackSource(this, "Contention"));
9093+
}
9094+
9095+
if (hasWaitHandle)
9096+
{
9097+
advanced.AddChild(new PerfViewStackSource(this, "WaitHandleWait"));
9098+
}
90159099
}
90169100

90179101
if (memory.Children.Count > 0)
@@ -9144,6 +9228,36 @@ protected internal override StackSource OpenStackSourceImpl(string streamName, T
91449228
stackSource.DoneAddingSamples();
91459229
return stackSource;
91469230
}
9231+
case "Contention":
9232+
{
9233+
var eventLog = GetTraceLog(log);
9234+
9235+
var contentionSource = new MutableTraceEventStackSource(eventLog);
9236+
// EventPipe currently only has managed code stacks.
9237+
contentionSource.OnlyManagedCodeStacks = true;
9238+
contentionSource.ShowUnknownAddresses = App.CommandLineArgs.ShowUnknownAddresses;
9239+
contentionSource.ShowOptimizationTiers = App.CommandLineArgs.ShowOptimizationTiers;
9240+
9241+
var computer = new ContentionLatencyComputer(eventLog, contentionSource);
9242+
computer.GenerateStacks();
9243+
9244+
return contentionSource;
9245+
}
9246+
case "WaitHandleWait":
9247+
{
9248+
var eventLog = GetTraceLog(log);
9249+
9250+
var waitHandleWaitSource = new MutableTraceEventStackSource(eventLog);
9251+
// EventPipe currently only has managed code stacks.
9252+
waitHandleWaitSource.OnlyManagedCodeStacks = true;
9253+
waitHandleWaitSource.ShowUnknownAddresses = App.CommandLineArgs.ShowUnknownAddresses;
9254+
waitHandleWaitSource.ShowOptimizationTiers = App.CommandLineArgs.ShowOptimizationTiers;
9255+
9256+
var computer = new WaitHandleWaitLatencyComputer(eventLog, waitHandleWaitSource);
9257+
computer.GenerateStacks();
9258+
9259+
return waitHandleWaitSource;
9260+
}
91479261
case "Thread Time (with StartStop Activities)":
91489262
{
91499263
var eventLog = GetTraceLog(log);
@@ -9351,6 +9465,11 @@ protected internal override void ConfigureStackWindow(string stackSourceName, St
93519465
stackWindow.ComputeMaxInTopStats = true;
93529466
}
93539467

9468+
if (stackSourceName == "Contention" || stackSourceName == "WaitHandleWait")
9469+
{
9470+
ConfigureStackWindowForStartStopThreadTime(stackWindow);
9471+
}
9472+
93549473
if (m_extraTopStats != null)
93559474
{
93569475
stackWindow.ExtraTopStats += " " + m_extraTopStats;

src/PerfView/SupportFiles/UsersGuide.htm

+22
Original file line numberDiff line numberDiff line change
@@ -2437,6 +2437,28 @@ <h2>
24372437
objects pinned because they are pointed to by a async pinned handle at the time of
24382438
the heap snapshot.
24392439
</li>
2440+
<li>
2441+
<strong><a id="ContentionStacks">Contention Stacks</a></strong> - This view aggregates Contention events.&nbsp;
2442+
Contention event is fired when a thread tries to acquire a managed lock that is currently owned
2443+
by another thread. Note that each event has useful event data that is folded by default.
2444+
For example, unfolding <code>EventData DurationNs</code> reveals individual pauses of each thread: this can be useful
2445+
to correlate a particular long wait to another events in the trace. Note that not all contention events
2446+
are real OS-level waits: the runtime may first spin wait to try acquire the lock fast. The metric
2447+
represents the amount of time spent to acquire the lock in milliseconds.
2448+
</li>
2449+
<li>
2450+
<strong><a id="WaitHandleWaitStacks">WaitHandleWait Stacks</a></strong> - This view is similar to <a href="#ContentionStacks">Contention Stacks</a>
2451+
in a sense that it allows to diagnose the blocking waits. However, there are important differences.
2452+
Contention events are emitted exclusively on <code>System.Threading.Monitor</code> and <code>System.Threading.Lock</code> code paths.
2453+
WaitHandleWait events are lower level and fire when the OS-provided wait handle is used to block the thread execution.
2454+
For example, WaitHandleWait will catch waiting inside <code>SemaphoreSlim.Wait()</code> while Contention event won't.
2455+
WaitHandleWait can be fired alongside the Contention event: for instance, during <code>Monitor.Enter</code> if spin waiting
2456+
was not enough to acquire the lock. Also note that WaitHandleWait is much more noisy: you'd need to clean up
2457+
the stacks from "legit" waiting like a main thread waiting for application shutdown signal, or a consumer thread
2458+
that waits for new items in a blocking channel. WaitHandleWait may not cover all waits in your application, like waits that
2459+
bypass the dotnet runtime or waits on other synchronous OS APIs like a blocking write to a socket.
2460+
For more details, refer to <a href="https://github.com/dotnet/runtime/pull/94737#discussion_r1409607825">this diagram</a> from the original PR.
2461+
</li>
24402462
<li>
24412463
<strong><a id="AnyStacks">Any Stacks</a></strong> - This view shows
24422464
every event that has a stack.&nbsp; It is useful when none of the more specialized

0 commit comments

Comments
 (0)