Skip to content

Commit f4bc5cb

Browse files
author
Vance Morrison
committed
Support IncompleteAsyncMethod (at least a bit).
.NET Core added an event that helps diagnose some kinds of async deadlock (where code that should have triggered a task completion simply drops the task that should have been signaled). See release notes for more. TraceEvent synthesizes a Version number to determine if one EventSource manifest is 'better' than another. Change it so that if you add a new event the version goes a a lot, which allows you to also delete some entries and still have a better version (see comments for more).
1 parent 42887f3 commit f4bc5cb

File tree

5 files changed

+138
-32
lines changed

5 files changed

+138
-32
lines changed

src/Directory.Build.props

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -22,8 +22,8 @@
2222

2323
<PropertyGroup>
2424
<!-- These are the versions of the things we are CREATING in this repository -->
25-
<PerfViewVersion>2.0.27</PerfViewVersion>
26-
<TraceEventVersion>2.0.27</TraceEventVersion>
25+
<PerfViewVersion>2.0.28</PerfViewVersion>
26+
<TraceEventVersion>2.0.28</TraceEventVersion>
2727
</PropertyGroup>
2828

2929
<!-- versions of dependencies that more than one project use -->

src/PerfView/SupportFiles/UsersGuide.htm

Lines changed: 37 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -8314,18 +8314,49 @@ <h2>
83148314
</ul>
83158315
</li>
83168316
-->
8317+
<li>
8318+
Version 2.0.28 10/2/18
8319+
<ul>
8320+
<li>
8321+
Fixed parsing of Task Parallel library parsing to include the .NET Core 2.1 event
8322+
System.Threading.Tasks.TplEventSource/IncompleteAsyncMethod used to find 'orphaned' Async operations.
8323+
Also added this event to the default collection for TPL, so that it is always 'just here'.
8324+
8325+
Basically this is a new feature of the .NET Core task library that notices when tasks are created,
8326+
but then collected without ever being completed one way or the other. This can happen if the
8327+
TaskCompletionSource dies before it calls 'Complete' on the task.
8328+
8329+
The string in the event is the name of the method where the orphaned machine (Task) will return
8330+
when it continues. The code that was supposed to trigger the 'await' to complete is at fault.
8331+
8332+
This feature needs to be friendlier but it is a big step from knowing nothing.
8333+
</li>
8334+
<li> modified the TraceEvent library's concept of what the 'version of the manifest is to' include
8335+
a term that is 100 * the largest event ID. Thus if you add a new event (at the end), you can
8336+
remove (clean up) a few dozen unused events and still be considered 'better'. Note that this should
8337+
be used with care, as it implys that the deleted events are not EVER useful (even for old code that
8338+
still emits them), because TraceEvent will not parse them going forward (The TPL EventSource did just
8339+
this which is why it came up here.)
8340+
</li>
8341+
</ul>
8342+
</li>
83178343
<li>
83188344
Version 2.0.27 9/25/18
83198345
<ul>
8320-
<li> Fixed 'PerfView Listen EVENTSOURCE' so that it works without the * prefix for EventSources.
8346+
<li>
8347+
Fixed 'PerfView Listen EVENTSOURCE' so that it works without the * prefix for EventSources.
83218348
</li>
83228349
<li>Fixed missing descriptions for user commands</li>
8323-
<li>Added support for the /SessionName=XXXX parameter which renames both the user and kernel
8324-
session names that perfView uses (which allow you to have two PerfView's running or run
8325-
with other tools that use the kernel provider) </li>
8350+
<li>
8351+
Added support for the /SessionName=XXXX parameter which renames both the user and kernel
8352+
session names that perfView uses (which allow you to have two PerfView's running or run
8353+
with other tools that use the kernel provider)
8354+
</li>
83268355
<li>Use stack compression by default</li>
8327-
<li>Stop the kernel and user mode session concurrently. This helps when the disks are very
8328-
slow (VMs), to keep the two sessions overlapping maximally</li>
8356+
<li>
8357+
Stop the kernel and user mode session concurrently. This helps when the disks are very
8358+
slow (VMs), to keep the two sessions overlapping maximally
8359+
</li>
83298360
</ul>
83308361
</li>
83318362
<li>

src/TraceEvent/DynamicTraceEventParser.cs

Lines changed: 16 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -1972,8 +1972,12 @@ public void WriteToFile(string filePath)
19721972
/// <summary>
19731973
/// The version is defined as the sum of all the version numbers of event version numbers + the number of events defined.
19741974
/// This has the property that if you follow correct versioning protocol (all versions for a linear sequence where a new
1975-
/// versions is only modifies is predecessor by adding new events or INCREASEING the version numbers of existing events)
1975+
/// versions is only modifies is predecessor by adding new events or INCREASING the version numbers of existing events)
19761976
/// then the version number defined below will always strictly increase.
1977+
///
1978+
/// It turns out that .NET Core removed some events from the TplEtwProvider. To allow removal of truly old events
1979+
/// we also add 100* the largest event ID defined to the version number. That way if you add new events, even if you
1980+
/// removes some (less than 100) it will consider your 'better'.
19771981
/// </summary>
19781982
public int Version
19791983
{
@@ -1984,25 +1988,26 @@ public int Version
19841988
try
19851989
{
19861990
var verReader = ManifestReader;
1987-
while (
1988-
verReader.Read())
1991+
var maxEventId = 0;
1992+
while (verReader.Read())
19891993
{
19901994
if (verReader.NodeType != XmlNodeType.Element)
1991-
{
19921995
continue;
1993-
}
19941996

19951997
if (verReader.Name == "event")
19961998
{
19971999
version++;
19982000
string ver = verReader.GetAttribute("version");
1999-
int intVer;
2000-
if (ver != null && int.TryParse(ver, out intVer))
2001-
{
2001+
if (ver != null && int.TryParse(ver, out int intVer))
20022002
version += intVer;
2003-
}
2003+
2004+
string id = verReader.GetAttribute("value");
2005+
if (id != null && int.TryParse(id, out int intId) && intId > maxEventId)
2006+
maxEventId = intId;
20042007
}
20052008
}
2009+
2010+
version += maxEventId * 100;
20062011
}
20072012
catch (Exception e)
20082013
{
@@ -2022,8 +2027,8 @@ public int Version
20222027

20232028
/// <summary>
20242029
/// Returns true if the current manifest is better to use than 'otherManifest' A manifest is
2025-
/// better if it has a larger version nubmer OR, they have the same version number and it is
2026-
/// physically larger (we assume what happend is people added more properties but did not
2030+
/// better if it has a larger version number OR, they have the same version number and it is
2031+
/// physically larger (we assume what happened is people added more properties but did not
20272032
/// update the version field appropriately).
20282033
/// </summary>
20292034
public bool BetterThan(ProviderManifest otherManifest)
@@ -2088,7 +2093,6 @@ internal void ParseProviderEvents(Func<DynamicTraceEventData, EventFilterRespons
20882093
Init();
20892094
try
20902095
{
2091-
version = 0;
20922096
Dictionary<string, int> opcodes = new Dictionary<string, int>();
20932097
opcodes.Add("win:Info", 0);
20942098
opcodes.Add("win:Start", 1);
@@ -2143,14 +2147,6 @@ internal void ParseProviderEvents(Func<DynamicTraceEventData, EventFilterRespons
21432147
int taskNum = 0;
21442148
Guid taskGuid = Guid.Empty;
21452149

2146-
version++;
2147-
string ver = reader.GetAttribute("version");
2148-
int intVer;
2149-
if (ver != null && int.TryParse(ver, out intVer))
2150-
{
2151-
version += intVer;
2152-
}
2153-
21542150
int eventID = int.Parse(reader.GetAttribute("value"));
21552151
int opcode = 0;
21562152
string opcodeName = reader.GetAttribute("opcode");

src/TraceEvent/Parsers/TplTraceEventParser.cs

Lines changed: 82 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -26,7 +26,8 @@ public enum Keywords : long
2626
Asynccausalitysynchronouswork = 0x20,
2727
Taskstops = 0x40,
2828
TasksFlowActivityIds = 0x80,
29-
Default = Tasktransfer | Tasks | Parallel | Asynccausalityoperation | Asynccausalityrelation | Asynccausalitysynchronouswork | Taskstops | TasksFlowActivityIds,
29+
AsyncMethod = 0x100,
30+
Default = Tasktransfer | Tasks | Parallel | Asynccausalityoperation | Asynccausalityrelation | Asynccausalitysynchronouswork | Taskstops | TasksFlowActivityIds | AsyncMethod,
3031
};
3132

3233
public TplEtwProviderTraceEventParser(TraceEventSource source) : base(source) { }
@@ -229,6 +230,17 @@ public event Action<TraceSynchronousWorkStopArgs> TraceSynchronousWorkStop
229230
source.UnregisterEventTemplate(value, 18, ProviderGuid);
230231
}
231232
}
233+
public event Action<IncompleteAsyncMethodArgs> IncompleteAsyncMethod
234+
{
235+
add
236+
{
237+
source.RegisterEventTemplate(IncompleteAsyncMethodTemplate(value));
238+
}
239+
remove
240+
{
241+
source.UnregisterEventTemplate(value, 27, ProviderGuid);
242+
}
243+
}
232244

233245
#region private
234246
protected override string GetProviderName() { return ProviderName; }
@@ -305,13 +317,17 @@ static private TraceSynchronousWorkStopArgs TraceSynchronousWorkStopTemplate(Act
305317
{ // action, eventid, taskid, taskName, taskGuid, opcode, opcodeName, providerGuid, providerName
306318
return new TraceSynchronousWorkStopArgs(action, 18, 9, "TraceSynchronousWork", Guid.Empty, 2, "Stop", ProviderGuid, ProviderName);
307319
}
308-
320+
static private IncompleteAsyncMethodArgs IncompleteAsyncMethodTemplate(Action<IncompleteAsyncMethodArgs> action)
321+
{ // action, eventid, taskid, taskName, taskGuid, opcode, opcodeName, providerGuid, providerName
322+
return new IncompleteAsyncMethodArgs(action, 27, 65507, "IncompleteAsyncMethod", Guid.Empty, 0, "", ProviderGuid, ProviderName);
323+
}
324+
309325
static private volatile TraceEvent[] s_templates;
310326
protected internal override void EnumerateTemplates(Func<string, string, EventFilterResponse> eventsToObserve, Action<TraceEvent> callback)
311327
{
312328
if (s_templates == null)
313329
{
314-
var templates = new TraceEvent[18];
330+
var templates = new TraceEvent[19];
315331
templates[0] = LoopStartTemplate(null);
316332
templates[1] = LoopStopTemplate(null);
317333
templates[2] = InvokeStartTemplate(null);
@@ -330,6 +346,8 @@ protected internal override void EnumerateTemplates(Func<string, string, EventFi
330346
templates[15] = TraceOperationStopTemplate(null);
331347
templates[16] = TraceSynchronousWorkStartTemplate(null);
332348
templates[17] = TraceSynchronousWorkStopTemplate(null);
349+
templates[18] = IncompleteAsyncMethodTemplate(null);
350+
333351
s_templates = templates;
334352
}
335353
foreach (var template in s_templates)
@@ -1583,6 +1601,67 @@ public override object PayloadValue(int index)
15831601
private event Action<TraceSynchronousWorkStopArgs> m_target;
15841602
#endregion
15851603
}
1604+
public sealed class IncompleteAsyncMethodArgs : TraceEvent
1605+
{
1606+
public string stateMachineDescription { get { return GetUnicodeStringAt(0); } }
1607+
1608+
#region Private
1609+
internal IncompleteAsyncMethodArgs(Action<IncompleteAsyncMethodArgs> target, int eventID, int task, string taskName, Guid taskGuid, int opcode, string opcodeName, Guid providerGuid, string providerName)
1610+
: base(eventID, task, taskName, taskGuid, opcode, opcodeName, providerGuid, providerName)
1611+
{
1612+
this.m_target = target;
1613+
}
1614+
protected internal override void Dispatch()
1615+
{
1616+
m_target(this);
1617+
}
1618+
protected internal override void Validate()
1619+
{
1620+
Debug.Assert(!(Version == 0 && EventDataLength != SkipUnicodeString(0)));
1621+
Debug.Assert(!(Version > 0 && EventDataLength < SkipUnicodeString(0)));
1622+
}
1623+
protected internal override Delegate Target
1624+
{
1625+
get { return m_target; }
1626+
set { m_target = (Action<IncompleteAsyncMethodArgs>)value; }
1627+
}
1628+
public override StringBuilder ToXml(StringBuilder sb)
1629+
{
1630+
Prefix(sb);
1631+
XmlAttrib(sb, "stateMachineDescription", stateMachineDescription);
1632+
sb.Append("/>");
1633+
return sb;
1634+
}
1635+
1636+
public override string[] PayloadNames
1637+
{
1638+
get
1639+
{
1640+
if (payloadNames == null)
1641+
payloadNames = new string[] { "stateMachineDescription" };
1642+
return payloadNames;
1643+
}
1644+
}
1645+
1646+
public override object PayloadValue(int index)
1647+
{
1648+
switch (index)
1649+
{
1650+
case 0:
1651+
return stateMachineDescription;
1652+
default:
1653+
Debug.Assert(false, "Bad field index");
1654+
return null;
1655+
}
1656+
}
1657+
1658+
public static ulong GetKeywords() { return 256; }
1659+
public static string GetProviderName() { return "System.Threading.Tasks.TplEventSource"; }
1660+
public static Guid GetProviderGuid() { return new Guid("2e5dba47-a3d2-4d16-8ee0-6671ffdcd7b5"); }
1661+
private event Action<IncompleteAsyncMethodArgs> m_target;
1662+
#endregion
1663+
}
1664+
15861665
public enum AsyncCausalityStatus
15871666
{
15881667
Started = 0x0,

src/TraceEvent/TraceEventSession.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2581,7 +2581,7 @@ public static unsafe bool MaybeAnEventSource(Guid providerGuid)
25812581
return true;
25822582
}
25832583
// FrameworkEventSource predated the Guid selection convention that most eventSources use.
2584-
// Opt it in explicity
2584+
// Opt it in explicitly
25852585
if (providerGuid == FrameworkEventSourceTraceEventParser.ProviderGuid)
25862586
{
25872587
return true;

0 commit comments

Comments
 (0)