Skip to content

Commit

Permalink
Merge pull request #1731 from kouvel/Contention
Browse files Browse the repository at this point in the history
  • Loading branch information
@brianrob
brianrob authored May 30, 2023
2 parents bb24ad9 + 56414f2 commit c73119d
Show file tree
Hide file tree
Showing 6 changed files with 112 additions and 15 deletions.
2 changes: 2 additions & 0 deletions src/TraceEvent/Ctf/CtfTraceEventSource.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -134,8 +134,10 @@ private static Dictionary<string, ETWMapping> InitEventMap()
result["DotNETRuntime:ThreadPoolWorkingThreadCount"] = new ETWMapping(Parsers.ClrTraceEventParser.ProviderGuid, 1, 60, 0);
result["DotNETRuntime:ExceptionThrown"] = new ETWMapping(Parsers.ClrTraceEventParser.ProviderGuid, 1, 80, 0);
result["DotNETRuntime:ExceptionThrown_V1"] = new ETWMapping(Parsers.ClrTraceEventParser.ProviderGuid, 1, 80, 1);
result["DotNETRuntime:LockCreated"] = new ETWMapping(Parsers.ClrTraceEventParser.ProviderGuid, 0, 90, 0);
result["DotNETRuntime:Contention"] = new ETWMapping(Parsers.ClrTraceEventParser.ProviderGuid, 1, 81, 0);
result["DotNETRuntime:ContentionStart_V1"] = new ETWMapping(Parsers.ClrTraceEventParser.ProviderGuid, 1, 81, 1);
result["DotNETRuntime:ContentionStart_V2"] = new ETWMapping(Parsers.ClrTraceEventParser.ProviderGuid, 1, 81, 2);
result["DotNETRuntime:StrongNameVerificationStart"] = new ETWMapping(Parsers.ClrTraceEventParser.ProviderGuid, 1, 181, 0);
result["DotNETRuntime:StrongNameVerificationStart_V1"] = new ETWMapping(Parsers.ClrTraceEventParser.ProviderGuid, 1, 181, 1);
result["DotNETRuntime:AuthenticodeVerificationStart"] = new ETWMapping(Parsers.ClrTraceEventParser.ProviderGuid, 1, 183, 0);
Expand Down
101 changes: 98 additions & 3 deletions src/TraceEvent/Parsers/ClrTraceEventParser.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1216,6 +1216,18 @@ public event Action<EmptyTraceData> ExceptionStop
source.UnregisterEventTemplate(value, 256, ProviderGuid);
}
}
public event Action<ContentionLockCreatedTraceData> ContentionLockCreated
{
add
{
RegisterTemplate(ContentionLockCreatedTemplate(value));
}
remove
{
source.UnregisterEventTemplate(value, 90, ProviderGuid);
source.UnregisterEventTemplate(value, 11, ContentionTaskGuid);
}
}
public event Action<ContentionStartTraceData> ContentionStart
{
add
Expand Down Expand Up @@ -2162,13 +2174,17 @@ static private ThreadPoolMinMaxThreadsTraceData ThreadPoolMinMaxThreadsTemplate(
{ // action, eventid, taskid, taskName, taskGuid, opcode, opcodeName, providerGuid, providerName
return new ThreadPoolMinMaxThreadsTraceData(action, 59, 38, "ThreadPoolMinMaxThreads", ThreadPoolMinMaxThreadsTaskGuid, 0, "Info", ProviderGuid, ProviderName);
}
static private ContentionLockCreatedTraceData ContentionLockCreatedTemplate(Action<ContentionLockCreatedTraceData> action)
{ // action, eventid, taskid, taskName, taskGuid, opcode, opcodeName, providerGuid, providerName
return new ContentionLockCreatedTraceData(action, 90, 8, "Contention", ContentionTaskGuid, 11, "LockCreated", ProviderGuid, ProviderName);
}

static private volatile TraceEvent[] s_templates;
protected internal override void EnumerateTemplates(Func<string, string, EventFilterResponse> eventsToObserve, Action<TraceEvent> callback)
{
if (s_templates == null)
{
var templates = new TraceEvent[144];
var templates = new TraceEvent[145];
templates[0] = new GCStartTraceData(null, 1, 1, "GC", GCTaskGuid, 1, "Start", ProviderGuid, ProviderName);
templates[1] = new GCEndTraceData(null, 2, 1, "GC", GCTaskGuid, 2, "Stop", ProviderGuid, ProviderName);
templates[2] = new GCNoUserDataTraceData(null, 3, 1, "GC", GCTaskGuid, 132, "RestartEEStop", ProviderGuid, ProviderName);
Expand Down Expand Up @@ -2322,6 +2338,7 @@ protected internal override void EnumerateTemplates(Func<string, string, EventFi
templates[141] = ThreadPoolMinMaxThreadsTemplate(null);
templates[142] = GCLOHCompactTemplate(null);
templates[143] = GCFitBucketInfoTemplate(null);
templates[144] = ContentionLockCreatedTemplate(null);

s_templates = templates;
}
Expand Down Expand Up @@ -9448,10 +9465,78 @@ public override object PayloadValue(int index)
private event Action<ExceptionTraceData> Action;
#endregion
}
public sealed class ContentionLockCreatedTraceData : TraceEvent
{
public Address LockID { get { return (Address)GetInt64At(0); } }
public Address AssociatedObjectID { get { return (Address)GetInt64At(8); } }
public int ClrInstanceID { get { return GetInt16At(16); } }

#region Private
internal ContentionLockCreatedTraceData(Action<ContentionLockCreatedTraceData> target, int eventID, int task, string taskName, Guid taskGuid, int opcode, string opcodeName, Guid providerGuid, string providerName)
: base(eventID, task, taskName, taskGuid, opcode, opcodeName, providerGuid, providerName)
{
m_target = target;
}
protected internal override void Dispatch()
{
m_target(this);
}
protected internal override void Validate()
{
Debug.Assert(!(Version == 0 && EventDataLength != 18));
Debug.Assert(!(Version > 1 && EventDataLength < 18));
}
protected internal override Delegate Target
{
get { return m_target; }
set { m_target = (Action<ContentionLockCreatedTraceData>)value; }
}
public override StringBuilder ToXml(StringBuilder sb)
{
Prefix(sb);
XmlAttribHex(sb, "LockID", LockID);
XmlAttribHex(sb, "AssociatedObjectID", AssociatedObjectID);
XmlAttrib(sb, "ClrInstanceID", ClrInstanceID);
sb.Append("/>");
return sb;
}

public override string[] PayloadNames
{
get
{
if (payloadNames == null)
payloadNames = new string[] { "LockID", "AssociatedObjectID", "ClrInstanceID" };
return payloadNames;
}
}

public override object PayloadValue(int index)
{
switch (index)
{
case 0:
return LockID;
case 1:
return AssociatedObjectID;
case 2:
return ClrInstanceID;
default:
Debug.Assert(false, "Bad field index");
return null;
}
}

private event Action<ContentionLockCreatedTraceData> m_target;
#endregion
}
public sealed class ContentionStartTraceData : TraceEvent
{
public ContentionFlags ContentionFlags { get { if (Version >= 1) return (ContentionFlags)GetByteAt(0); return (ContentionFlags)0; } }
public int ClrInstanceID { get { if (Version >= 1) return GetInt16At(1); return 0; } }
public Address LockID { get { if (Version >= 2) { return (Address)GetInt64At(3); } return 0; } }
public Address AssociatedObjectID { get { if (Version >= 2) { return (Address)GetInt64At(11); } return 0; } }
public long LockOwnerThreadID { get { if (Version >= 2) { return GetInt64At(19); } return 0; } }

#region Private
internal ContentionStartTraceData(Action<ContentionStartTraceData> target, int eventID, int task, string taskName, Guid taskGuid, int opcode, string opcodeName, Guid providerGuid, string providerName)
Expand All @@ -9468,7 +9553,8 @@ protected internal override void Validate()
// Not sure if hand editing is appropriate but the start event is size 3 whereas the stop event is size 11
// and both of them come here
Debug.Assert(!(Version == 1 && EventDataLength != 3 && EventDataLength != 11));
Debug.Assert(!(Version > 1 && EventDataLength < 3));
Debug.Assert(!(Version == 2 && EventDataLength != 27));
Debug.Assert(!(Version > 2 && EventDataLength < 27));
}
protected internal override Delegate Target
{
Expand All @@ -9480,6 +9566,9 @@ public override StringBuilder ToXml(StringBuilder sb)
Prefix(sb);
XmlAttrib(sb, "ContentionFlags", ContentionFlags);
XmlAttrib(sb, "ClrInstanceID", ClrInstanceID);
XmlAttribHex(sb, "LockID", LockID);
XmlAttribHex(sb, "AssociatedObjectID", AssociatedObjectID);
XmlAttrib(sb, "LockOwnerThreadID", LockOwnerThreadID);
sb.Append("/>");
return sb;
}
Expand All @@ -9489,7 +9578,7 @@ public override string[] PayloadNames
get
{
if (payloadNames == null)
payloadNames = new string[] { "ContentionFlags", "ClrInstanceID" };
payloadNames = new string[] { "ContentionFlags", "ClrInstanceID", "LockID", "AssociatedObjectID", "LockOwnerThreadID" };
return payloadNames;
}
}
Expand All @@ -9502,6 +9591,12 @@ public override object PayloadValue(int index)
return ContentionFlags;
case 1:
return ClrInstanceID;
case 2:
return LockID;
case 3:
return AssociatedObjectID;
case 4:
return LockOwnerThreadID;
default:
Debug.Assert(false, "Bad field index");
return null;
Expand Down
2 changes: 1 addition & 1 deletion ...ent/TraceEvent.Tests/inputs/eventpipe-dotnetcore3.0-win-x64-objver4.nettrace.baseline.txt
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
Microsoft-DotNETCore-SampleProfiler/Thread/Sample, 35161, <Event MSec= "18.1697" PID="10064" PName="Process(10064)" TID="7532" EventName="Thread/Sample" Type="External">\r\n</Event>
Microsoft-Windows-DotNETRuntime/AppDomainResourceManagement/ThreadCreated, 14, <Event MSec= "17.8861" PID="10064" PName="Process(10064)" TID="3444" EventName="AppDomainResourceManagement/ThreadCreated" ManagedThreadID="0x0000019A7A321810" AppDomainID="0x0000019A783A12A0" Flags="0x00000000" ManagedThreadIndex="3" OSThreadID="3,444" ClrInstanceID="3"/>
Microsoft-Windows-DotNETRuntime/Contention/Start, 8, <Event MSec= "3098.9569" PID="10064" PName="Process(10064)" TID="12248" EventName="Contention/Start" ContentionFlags="Managed" ClrInstanceID="3"/>
Microsoft-Windows-DotNETRuntime/Contention/Start, 8, <Event MSec= "3098.9569" PID="10064" PName="Process(10064)" TID="12248" EventName="Contention/Start" ContentionFlags="Managed" ClrInstanceID="3" LockID="0x00000000" AssociatedObjectID="0x00000000" LockOwnerThreadID="0"/>
Microsoft-Windows-DotNETRuntime/Contention/Stop, 8, <Event MSec= "3235.9560" PID="10064" PName="Process(10064)" TID="12272" EventName="Contention/Stop" ContentionFlags="Managed" ClrInstanceID="3" DurationNs="137400255.241591"/>
Microsoft-Windows-DotNETRuntime/GC, 16, <Event MSec= "1598.5796" PID="10064" PName="Process(10064)" TID="7532" EventName="GC" ProviderName="Microsoft-Windows-DotNETRuntime" FormattedMessage="BytesAllocated=3,784;\r\n;\r\nClrInstanceID=3 " BytesAllocated="3,784" ClrInstanceID="3"/>
Microsoft-Windows-DotNETRuntime/GC/AllocationTick, 35458, <Event MSec= "2331.8048" PID="10064" PName="Process(10064)" TID="6920" EventName="GC/AllocationTick" AllocationAmount="0x000196A0" AllocationKind="Small" ClrInstanceID="3" AllocationAmount64="104,096" TypeID="0x00007FFEA911EA28" TypeName="System.Object[]" HeapIndex="0" Address="0x0000019A00017FE8"/>
Expand Down
10 changes: 5 additions & 5 deletions src/TraceEvent/TraceEvent.Tests/inputs/net.4.5.2.x86.baseline.txt
View file
Original file line number Diff line number Diff line change
Expand Up @@ -386,9 +386,9 @@ EVENT 10,341.477: PerfView/StopReason PID=3988; TID=3992; PName=PerfView; ProceN
EVENT 10,343.929: PerfView/CommandLineParameters PID=3988; TID=2784; PName=PerfView; ProceNum=4; DataLen=266; commandLine= "/DataFile:net.4.5....; currentDirectory=Z:\PerfInvestigation...; version=2.0.57;
EVENT 10,343.930: PerfView/Tracing/Stop PID=3988; TID=2784; PName=PerfView; ProceNum=4; DataLen=0;
EVENT 10,344.217: PerfView/StartAndStopTimes PID=3988; TID=2784; PName=PerfView; ProceNum=4; DataLen=8; startTimeRelativeMSec=9,935; stopTimeRelativeMSec=0;
EVENT 10,345.209: Microsoft-Windows-DotNETRuntime/Contention/Start PID=3988; TID=3992; PName=PerfView; ProceNum=6; DataLen=3; ContentionFlags=Native; ClrInstanceID=11;
EVENT 10,345.209: Microsoft-Windows-DotNETRuntime/Contention/Start PID=3988; TID=3992; PName=PerfView; ProceNum=6; DataLen=3; ContentionFlags=Native; ClrInstanceID=11; LockID=0x00000000; AssociatedObjectID=0x00000000; LockOwnerThreadID=0;
EVENT 10,345.211: Microsoft-Windows-DotNETRuntime/Contention/Stop PID=3988; TID=3992; PName=PerfView; ProceNum=6; DataLen=3; ContentionFlags=Native; ClrInstanceID=11; DurationNs=0.000;
EVENT 10,346.029: Microsoft-Windows-DotNETRuntime/Contention/Start PID=3988; TID=3992; PName=PerfView; ProceNum=6; DataLen=3; ContentionFlags=Native; ClrInstanceID=11;
EVENT 10,346.029: Microsoft-Windows-DotNETRuntime/Contention/Start PID=3988; TID=3992; PName=PerfView; ProceNum=6; DataLen=3; ContentionFlags=Native; ClrInstanceID=11; LockID=0x00000000; AssociatedObjectID=0x00000000; LockOwnerThreadID=0;
EVENT 10,346.031: Microsoft-Windows-DotNETRuntime/Contention/Stop PID=3988; TID=3992; PName=PerfView; ProceNum=6; DataLen=3; ContentionFlags=Native; ClrInstanceID=11; DurationNs=0.000;
EVENT 10,352.885: Microsoft-Windows-Immersive-Shell/ImmersiveShellAppManagerOnShellHookMessage/Start PID=2876; TID=3016; PName=explorer; ProceNum=4; DataLen=4; Message=19;
EVENT 10,352.889: Microsoft-Windows-Immersive-Shell/ImmersiveShellAppManagerSetActiveProcess/Start PID=2876; TID=3016; PName=explorer; ProceNum=4; DataLen=0;
Expand All @@ -404,18 +404,18 @@ EVENT 10,375.028: System.Threading.Tasks.TplEventSource/TaskScheduled/Send PID=3
EVENT 10,375.031: System.Diagnostics.Eventing.FrameworkEventSource/ThreadPoolEnqueueWork PID=3988; TID=2784; PName=PerfView; ProceNum=7; DataLen=8; workID=64,033,296;
EVENT 10,375.125: System.Diagnostics.Eventing.FrameworkEventSource/ThreadPoolDequeueWork PID=3988; TID=2916; PName=PerfView; ProceNum=2; DataLen=8; workID=64,033,152;
EVENT 10,375.130: System.Diagnostics.Eventing.FrameworkEventSource/ThreadPoolDequeueWork PID=3988; TID=4088; PName=PerfView; ProceNum=4; DataLen=8; workID=64,033,224;
EVENT 10,375.135: Microsoft-Windows-DotNETRuntime/Contention/Start PID=3988; TID=4088; PName=PerfView; ProceNum=4; DataLen=3; ContentionFlags=Native; ClrInstanceID=11;
EVENT 10,375.135: Microsoft-Windows-DotNETRuntime/Contention/Start PID=3988; TID=4088; PName=PerfView; ProceNum=4; DataLen=3; ContentionFlags=Native; ClrInstanceID=11; LockID=0x00000000; AssociatedObjectID=0x00000000; LockOwnerThreadID=0;
EVENT 10,375.236: Microsoft-Windows-DotNETRuntime/ThreadPoolWorkerThread/Start PID=3988; TID=3744; PName=PerfView; ProceNum=0; DataLen=10; ActiveWorkerThreadCount=6; RetiredWorkerThreadCount=0; ClrInstanceID=11;
EVENT 10,375.249: Microsoft-Windows-DotNETRuntime/AppDomainResourceManagement/ThreadCreated PID=3988; TID=3744; PName=PerfView; ProceNum=0; DataLen=30; ManagedThreadID=218,392,976; AppDomainID=26,248,536; Flags=4; ManagedThreadIndex=7; OSThreadID=3,744; ClrInstanceID=11;
EVENT 10,375.290: Microsoft-Windows-DotNETRuntime/ThreadPoolWorkerThread/Start PID=3988; TID=3784; PName=PerfView; ProceNum=1; DataLen=10; ActiveWorkerThreadCount=7; RetiredWorkerThreadCount=0; ClrInstanceID=11;
EVENT 10,375.302: Microsoft-Windows-DotNETRuntime/AppDomainResourceManagement/ThreadCreated PID=3988; TID=3784; PName=PerfView; ProceNum=1; DataLen=30; ManagedThreadID=168,229,896; AppDomainID=26,248,536; Flags=4; ManagedThreadIndex=9; OSThreadID=3,784; ClrInstanceID=11;
EVENT 10,375.325: System.Diagnostics.Eventing.FrameworkEventSource/ThreadPoolDequeueWork PID=3988; TID=3744; PName=PerfView; ProceNum=0; DataLen=8; workID=64,033,296;
EVENT 10,375.330: Microsoft-Windows-DotNETRuntime/Contention/Start PID=3988; TID=3744; PName=PerfView; ProceNum=0; DataLen=3; ContentionFlags=Native; ClrInstanceID=11;
EVENT 10,375.330: Microsoft-Windows-DotNETRuntime/Contention/Start PID=3988; TID=3744; PName=PerfView; ProceNum=0; DataLen=3; ContentionFlags=Native; ClrInstanceID=11; LockID=0x00000000; AssociatedObjectID=0x00000000; LockOwnerThreadID=0;
EVENT 10,375.337: Microsoft-Windows-DotNETRuntime/ThreadPoolWorkerThread/Start PID=3988; TID=3780; PName=PerfView; ProceNum=3; DataLen=10; ActiveWorkerThreadCount=7; RetiredWorkerThreadCount=0; ClrInstanceID=11;
EVENT 10,375.351: Microsoft-Windows-DotNETRuntime/AppDomainResourceManagement/ThreadCreated PID=3988; TID=3780; PName=PerfView; ProceNum=3; DataLen=30; ManagedThreadID=216,756,040; AppDomainID=26,248,536; Flags=4; ManagedThreadIndex=8; OSThreadID=3,780; ClrInstanceID=11;
EVENT 10,375.381: Microsoft-Windows-DotNETRuntime/ThreadPoolWorkerThread/Start PID=3988; TID=3776; PName=PerfView; ProceNum=5; DataLen=10; ActiveWorkerThreadCount=7; RetiredWorkerThreadCount=0; ClrInstanceID=11;
EVENT 10,375.397: Microsoft-Windows-DotNETRuntime/Contention/Stop PID=3988; TID=3744; PName=PerfView; ProceNum=0; DataLen=3; ContentionFlags=Native; ClrInstanceID=11; DurationNs=0.000;
EVENT 10,375.415: Microsoft-Windows-DotNETRuntime/Contention/Start PID=3988; TID=3744; PName=PerfView; ProceNum=0; DataLen=3; ContentionFlags=Native; ClrInstanceID=11;
EVENT 10,375.415: Microsoft-Windows-DotNETRuntime/Contention/Start PID=3988; TID=3744; PName=PerfView; ProceNum=0; DataLen=3; ContentionFlags=Native; ClrInstanceID=11; LockID=0x00000000; AssociatedObjectID=0x00000000; LockOwnerThreadID=0;
EVENT 10,375.614: Microsoft-Windows-DotNETRuntime/Contention/Stop PID=3988; TID=3744; PName=PerfView; ProceNum=0; DataLen=3; ContentionFlags=Native; ClrInstanceID=11; DurationNs=0.000;
EVENT 10,375.768: Microsoft-Windows-DotNETRuntime/Contention/Stop PID=3988; TID=4088; PName=PerfView; ProceNum=4; DataLen=3; ContentionFlags=Native; ClrInstanceID=11; DurationNs=0.000;
EVENT 10,375.986: System.Threading.Tasks.TplEventSource/TaskExecute/Start PID=3988; TID=4088; PName=PerfView; ProceNum=4; DataLen=12; OriginatingTaskSchedulerID=1; OriginatingTaskID=0; TaskID=3;
Expand Down
Loading

0 comments on commit c73119d

Please sign in to comment.