Skip to content

Commit 9ebda3d

Browse files
authored
Add EventPipe EventSource serialization testing (#120887)
We've had EventSource serialization tests for a long time but EventPipe never got added to it. Unforetunately not testing EventPipe in this way previously meant that quite a few discrepancies between EventPipe and ETW went unnoticed. As a first step to documenting and/or resolving the problems I wanted to get EventPipe running in the same set of tests. I also did several other small fixes and improvements while doing the work. - EventPipeListener added as a new 3rd target for EventSource (in addition to EventListener and ETW which are there now) - Modified the Listener test abstraction so that EventPipe could also work - Removed assumption that providers can changed after the listener starts running - Added capability flags to indicate whether listeners supported certain kinds of serialization behavior - Worked around incomplete implementation of IDictionary for payloads in TraceEvent - Leveraged xunit theory attribute to avoid needing different top-level APIs for every listener configuration - Fixed EventTestHarness assert which had actual and expected values swapped - TestsWrite: Fixed mistaken call to Array.Equals with Assert.Equal so the test actually validates what it was supposed to - Removed ActiveIssue 88305 attribute which was already closed in the past. - Moved some test cases from TestsWriteEvent.Etw.cs to TestsWriteEvent.cs so that they can run for other listeners when supported.
1 parent 3683bd5 commit 9ebda3d

File tree

12 files changed

+736
-462
lines changed

12 files changed

+736
-462
lines changed

eng/Versions.props

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -110,6 +110,7 @@
110110
<MicrosoftDiaSymReaderVersion>2.0.0</MicrosoftDiaSymReaderVersion>
111111
<MicrosoftDiaSymReaderNativeVersion>17.10.0-beta1.24272.1</MicrosoftDiaSymReaderNativeVersion>
112112
<TraceEventVersion>3.1.16</TraceEventVersion>
113+
<MicrosoftDiagnosticsNetCoreClientVersion>0.2.621003</MicrosoftDiagnosticsNetCoreClientVersion>
113114
<NETStandardLibraryRefVersion>2.1.0</NETStandardLibraryRefVersion>
114115
<NetStandardLibraryVersion>2.0.3</NetStandardLibraryVersion>
115116
<MicrosoftDiagnosticsToolsRuntimeClientVersion>1.0.4-preview6.19326.1</MicrosoftDiagnosticsToolsRuntimeClientVersion>

src/libraries/System.Diagnostics.Tracing/tests/BasicEventSourceTest/Harness/EtwListener.cs

Lines changed: 35 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -32,20 +32,25 @@ internal static void EnsureStopped()
3232
public EtwListener(string dataFileName = "EventSourceTestData.etl", string sessionName = "EventSourceTestSession")
3333
{
3434
_dataFileName = dataFileName;
35+
_sessionName = sessionName;
36+
_pendingCommands = new List<(string eventSourceName, EventCommand command, FilteringOptions options)>();
3537

3638
// Today you have to be Admin to turn on ETW events (anyone can write ETW events).
3739
if (TraceEventSession.IsElevated() != true)
3840
{
3941
throw new SkipTestException("Need to be elevated to run. ");
4042
}
43+
}
4144

42-
if (dataFileName == null)
45+
public override void Start()
46+
{
47+
if (_dataFileName == null)
4348
{
44-
Debug.WriteLine("Creating a real time session " + sessionName);
49+
Debug.WriteLine("Creating a real time session " + _sessionName);
4550

4651
Task.Factory.StartNew(delegate ()
4752
{
48-
var session = new TraceEventSession(sessionName, dataFileName);
53+
var session = new TraceEventSession(_sessionName, _dataFileName);
4954
session.Source.AllEvents += OnEventHelper;
5055
Debug.WriteLine("Listening for real time events");
5156
_session = session; // Indicate that we are alive.
@@ -58,13 +63,31 @@ public EtwListener(string dataFileName = "EventSourceTestData.etl", string sessi
5863
else
5964
{
6065
// Normalize to a full path name.
61-
dataFileName = Path.GetFullPath(dataFileName);
62-
Debug.WriteLine("Creating ETW data file " + Path.GetFullPath(dataFileName));
63-
_session = new TraceEventSession(sessionName, dataFileName);
66+
_dataFileName = Path.GetFullPath(_dataFileName);
67+
Debug.WriteLine("Creating ETW data file " + Path.GetFullPath(_dataFileName));
68+
_session = new TraceEventSession(_sessionName, _dataFileName);
69+
}
70+
foreach(var cmd in _pendingCommands)
71+
{
72+
ApplyEventSourceCommand(cmd.eventSourceName, cmd.command, cmd.options);
6473
}
6574
}
6675

76+
public override bool IsDynamicConfigChangeSupported => true;
77+
6778
public override void EventSourceCommand(string eventSourceName, EventCommand command, FilteringOptions options = null)
79+
{
80+
if (_session == null)
81+
{
82+
_pendingCommands.Add((eventSourceName, command, options));
83+
}
84+
else
85+
{
86+
ApplyEventSourceCommand(eventSourceName, command, options);
87+
}
88+
}
89+
90+
private void ApplyEventSourceCommand(string eventSourceName, EventCommand command, FilteringOptions options = null)
6891
{
6992
if (command == EventCommand.Enable)
7093
{
@@ -111,6 +134,8 @@ public override void Dispose()
111134
}
112135
}
113136

137+
public override string ToString() => "EtwListener";
138+
114139
#region private
115140
private void OnEventHelper(TraceEvent data)
116141
{
@@ -136,7 +161,8 @@ private void OnEventHelper(TraceEvent data)
136161
/// </summary>
137162
internal class EtwEvent : Event
138163
{
139-
public override bool IsEtw { get { return true; } }
164+
public override bool IsEnumValueStronglyTyped(bool selfDescribing, bool isWriteEvent) => !selfDescribing;
165+
public override bool IsSizeAndPointerCoallescedIntoSingleArg => true;
140166
public override string ProviderName { get { return _data.ProviderName; } }
141167
public override string EventName { get { return _data.EventName; } }
142168
public override object PayloadValue(int propertyIndex, string propertyName)
@@ -162,7 +188,9 @@ public override string PayloadString(int propertyIndex, string propertyName)
162188

163189
private bool _disposed;
164190
private string _dataFileName;
191+
private string _sessionName;
165192
private volatile TraceEventSession _session;
193+
private List<(string eventSourceName, EventCommand command, FilteringOptions options)> _pendingCommands;
166194
#endregion
167195

168196
}
Lines changed: 179 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,179 @@
1+
// Licensed to the .NET Foundation under one or more agreements.
2+
// The .NET Foundation licenses this file to you under the MIT license.
3+
4+
using System;
5+
using System.Collections.Generic;
6+
using System.Diagnostics;
7+
using System.Diagnostics.Tracing;
8+
using System.Linq;
9+
using System.Threading;
10+
using System.Threading.Tasks;
11+
using Microsoft.Diagnostics.NETCore.Client;
12+
using Microsoft.Diagnostics.Tracing;
13+
using Xunit;
14+
15+
namespace BasicEventSourceTests
16+
{
17+
/// <summary>
18+
/// Implementation of Listener for EventPipe (in-process collection using DiagnosticsClient + EventPipeEventSource).
19+
/// </summary>
20+
internal sealed class EventPipeListener : Listener
21+
{
22+
private readonly List<(string eventSourceName, EventCommand command, FilteringOptions options)> _pendingCommands = new();
23+
private readonly Dictionary<string, FilteringOptions> _enabled = new(StringComparer.Ordinal);
24+
private EventPipeSession _session;
25+
private Task _processingTask;
26+
private bool _disposed;
27+
28+
public override bool IsDynamicConfigChangeSupported => false;
29+
30+
/// <summary>
31+
/// EventPipe NetTrace V5 format can't emit the metadata for a Boolean8 HasValue field that self-describing events use.
32+
/// </summary>
33+
public override bool IsSelfDescribingNullableSupported => false;
34+
35+
public override bool IsEventPipe => true;
36+
37+
public EventPipeListener() { }
38+
39+
public override void EventSourceCommand(string eventSourceName, EventCommand command, FilteringOptions options = null)
40+
{
41+
if (eventSourceName is null)
42+
{
43+
throw new ArgumentNullException(nameof(eventSourceName));
44+
}
45+
46+
if (_session != null)
47+
{
48+
throw new InvalidOperationException("EventPipeEventListener does not support dynamic configuration changes after Start().");
49+
}
50+
_pendingCommands.Add((eventSourceName, command, options));
51+
}
52+
53+
public override void Start()
54+
{
55+
if (_session != null)
56+
{
57+
return; // already started
58+
}
59+
60+
// Build provider enable list from pending commands
61+
foreach (var (eventSourceName, command, options) in _pendingCommands)
62+
{
63+
if (command == EventCommand.Enable)
64+
{
65+
var effective = options ?? new FilteringOptions();
66+
_enabled[eventSourceName] = effective;
67+
}
68+
else if (command == EventCommand.Disable)
69+
{
70+
_enabled.Remove(eventSourceName);
71+
}
72+
else
73+
{
74+
throw new NotImplementedException();
75+
}
76+
}
77+
78+
var providers = new List<EventPipeProvider>();
79+
foreach (var kvp in _enabled)
80+
{
81+
var opt = kvp.Value;
82+
providers.Add(new EventPipeProvider(kvp.Key, (EventLevel)opt.Level, (long)opt.Keywords, opt.Args));
83+
}
84+
85+
var client = new DiagnosticsClient(Environment.ProcessId);
86+
_session = client.StartEventPipeSession(providers, false);
87+
88+
_processingTask = Task.Factory.StartNew(() => ProcessEvents(_session), TaskCreationOptions.LongRunning);
89+
}
90+
91+
private void ProcessEvents(EventPipeSession session)
92+
{
93+
using var source = new EventPipeEventSource(session.EventStream);
94+
source.Dynamic.All += traceEvent =>
95+
{
96+
// EventPipe adds extra events we didn't ask for, ignore them.
97+
if (traceEvent.ProviderName == "Microsoft-DotNETCore-EventPipe")
98+
{
99+
return;
100+
}
101+
102+
OnEvent?.Invoke(new EventPipeEvent(traceEvent));
103+
};
104+
source.Process();
105+
}
106+
107+
public override void Dispose()
108+
{
109+
if (_disposed)
110+
{
111+
return;
112+
}
113+
114+
try
115+
{
116+
_disposed = true;
117+
_session?.Stop();
118+
119+
if (_processingTask != null && !_processingTask.Wait(TimeSpan.FromSeconds(5)))
120+
{
121+
// If the session is still streaming data then session.Dispose() below will disconnect the stream
122+
// and likely cause the thread running source.Process() to throw.
123+
Assert.Fail("EventPipeEventListener processing task failed to complete in 5 seconds.");
124+
}
125+
}
126+
finally
127+
{
128+
_session?.Dispose();
129+
}
130+
}
131+
132+
public override string ToString() => "EventPipeListener";
133+
134+
/// <summary>
135+
/// Wrapper mapping TraceEvent (EventPipe) to harness Event abstraction.
136+
/// </summary>
137+
private sealed class EventPipeEvent : Event
138+
{
139+
private readonly TraceEvent _data;
140+
private readonly IList<string> _payloadNames;
141+
private readonly IList<object> _payloadValues;
142+
143+
public EventPipeEvent(TraceEvent data)
144+
{
145+
_data = data;
146+
// EventPipe has a discrepancy with ETW for self-describing events - it exposes a single top-level object whereas ETW considers each of the fields within
147+
// that object as top-level named fields. To workaround that we unwrap any top-level object at payload index 0.
148+
if(data.PayloadNames.Length > 0 && data.PayloadValue(0) is IDictionary<string,object> d)
149+
{
150+
_payloadNames = d.Select(kv => kv.Key).ToList();
151+
_payloadValues = d.Select(kv => kv.Value).ToList();
152+
}
153+
else
154+
{
155+
_payloadNames = data.PayloadNames;
156+
_payloadValues = new List<object>();
157+
for(int i = 0; i < _payloadNames.Count; i++)
158+
{
159+
_payloadValues.Add(data.PayloadValue(i));
160+
}
161+
}
162+
}
163+
164+
public override string ProviderName => _data.ProviderName;
165+
public override string EventName => _data.EventName;
166+
public override int PayloadCount => _payloadNames.Count;
167+
public override IList<string> PayloadNames => _payloadNames;
168+
169+
public override object PayloadValue(int propertyIndex, string propertyName)
170+
{
171+
if (propertyName != null)
172+
{
173+
Assert.Equal(propertyName, _payloadNames[propertyIndex]);
174+
}
175+
return _payloadValues[propertyIndex];
176+
}
177+
}
178+
}
179+
}

src/libraries/System.Diagnostics.Tracing/tests/BasicEventSourceTest/Harness/EventTestHarness.cs

Lines changed: 18 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -112,9 +112,14 @@ public static void RunTests(List<SubTest> tests, Listener listener, EventSource
112112
using (TestHarnessEventSource testHarnessEventSource = new TestHarnessEventSource())
113113
{
114114
// Turn on the test EventSource.
115-
listener.EventSourceSynchronousEnable(source, options);
115+
listener.EventSourceCommand(source.Name, EventCommand.Enable, options);
116116
// And the harnesses's EventSource.
117-
listener.EventSourceSynchronousEnable(testHarnessEventSource);
117+
listener.EventSourceCommand(testHarnessEventSource.Name, EventCommand.Enable);
118+
119+
// Start the session and wait for the sources to be enabled.
120+
listener.Start();
121+
listener.WaitForEventSourceStateChange(source, true);
122+
listener.WaitForEventSourceStateChange(testHarnessEventSource, true);
118123

119124
// Generate events for all the tests, surrounded by events that tell us we are starting a test.
120125
int testNumber = 0;
@@ -126,12 +131,16 @@ public static void RunTests(List<SubTest> tests, Listener listener, EventSource
126131
}
127132
testHarnessEventSource.StartTest("", testNumber); // Empty test marks the end of testing.
128133

129-
// Disable the listeners.
130-
listener.EventSourceCommand(source.Name, EventCommand.Disable);
131-
listener.EventSourceCommand(testHarnessEventSource.Name, EventCommand.Disable);
134+
135+
if (listener.IsDynamicConfigChangeSupported)
136+
{
137+
// Disable the listeners.
138+
listener.EventSourceSynchronousDisable(source);
139+
listener.EventSourceSynchronousDisable(testHarnessEventSource);
132140

133-
// Send something that should be ignored.
134-
testHarnessEventSource.IgnoreEvent();
141+
// Send something that should be ignored.
142+
testHarnessEventSource.IgnoreEvent();
143+
}
135144
}
136145
}
137146
catch (Exception e)
@@ -164,8 +173,8 @@ public static void RunTests(List<SubTest> tests, Listener listener, EventSource
164173

165174
listener.Dispose(); // Indicate we are done listening. For the ETW file based cases, we do all the processing here
166175

167-
// expectedTetst number are the number of tests we successfully ran.
168-
Assert.Equal(expectedTestNumber, tests.Count);
176+
int actualTestsRun = expectedTestNumber;
177+
Assert.Equal(tests.Count, actualTestsRun);
169178
}
170179

171180
public class EventTestHarnessException : Exception

0 commit comments

Comments
 (0)