|
10 | 10 | using System.Runtime.InteropServices;
|
11 | 11 | using System.Threading;
|
12 | 12 | using System.Threading.Tasks;
|
13 |
| -using Tracing.Tests.Common; |
14 | 13 | using System.Collections.Concurrent;
|
| 14 | +using System.ComponentModel; |
| 15 | +using System.Collections; |
| 16 | +using System.Collections.Generic; |
| 17 | +using System.Text; |
15 | 18 |
|
16 | 19 | namespace Tracing.Tests
|
17 | 20 | {
|
18 | 21 | public sealed class NativeRuntimeEventSourceTest
|
19 | 22 | {
|
20 |
| - static int Main() |
| 23 | + private static int Main() |
21 | 24 | {
|
22 |
| - SimpleEventListener.EnableKeywords = (EventKeywords)0; |
23 |
| - using (SimpleEventListener noEventsListener = new SimpleEventListener("NoEvents")) |
| 25 | + // Create deaf listener |
| 26 | + Listener.Level = EventLevel.Critical; |
| 27 | + Listener.EnableKeywords = EventKeywords.None; |
| 28 | + using (Listener noEventsListener = new("NoEvents")) |
24 | 29 | {
|
25 |
| - // Create an EventListener. |
26 |
| - SimpleEventListener.EnableKeywords = (EventKeywords)0x4c14fccbd; |
27 |
| - using (SimpleEventListener listener = new SimpleEventListener("Simple")) |
| 30 | + using (NativeOverlappedClass nativeOverlappedClass = new()) |
28 | 31 | {
|
29 |
| - // Trigger the allocator task. |
30 |
| - Task.Run(new Action(Allocator)); |
| 32 | + // Create an EventListener. |
| 33 | + Listener.Level = EventLevel.Verbose; |
| 34 | + const EventKeywords EventKeywordThreading = (EventKeywords)65536; |
| 35 | + Listener.EnableKeywords = (EventKeywords)0x4c14fccbd | EventKeywordThreading; |
31 | 36 |
|
32 |
| - // If on Windows, attempt some Overlapped IO (triggers ThreadPool events) |
33 |
| - if (OperatingSystem.IsWindows()) |
| 37 | + // Check for events e.g. ThreadPoolIODequeue = 64 |
| 38 | + // At least some of these events can be found in "src\libraries\System.Private.CoreLib\src\System\Threading\NativeRuntimeEventSource.PortableThreadPool.NativeSinks.cs" |
| 39 | + Listener.TargetEventIds(63, 64, 65); |
| 40 | + |
| 41 | + using (Listener listener = new()) |
34 | 42 | {
|
| 43 | + // Trigger the allocator task. |
| 44 | + Task.Run(() => |
| 45 | + { |
| 46 | + while (true) |
| 47 | + { |
| 48 | + for (int i = 0; i < 1000; i++) |
| 49 | + { |
| 50 | + GC.KeepAlive(new object()); |
| 51 | + } |
| 52 | + |
| 53 | + Thread.Sleep(10); |
| 54 | + } |
| 55 | + }); |
| 56 | + |
| 57 | + // If on Windows, attempt some Overlapped IO (triggers ThreadPool events) |
35 | 58 | DoOverlappedIO();
|
36 |
| - } |
37 | 59 |
|
38 |
| - // Generate some GC events. |
39 |
| - GC.Collect(2, GCCollectionMode.Forced); |
| 60 | + // Trigger EventId 63 and 64 |
| 61 | + nativeOverlappedClass.ThreadPoolQueue(); |
40 | 62 |
|
41 |
| - Stopwatch sw = Stopwatch.StartNew(); |
42 |
| - |
43 |
| - while (sw.Elapsed <= TimeSpan.FromMinutes(1)) |
44 |
| - { |
45 |
| - Thread.Sleep(100); |
| 63 | + // Generate some GC events. |
| 64 | + GC.Collect(2, GCCollectionMode.Forced); |
46 | 65 |
|
47 |
| - if ((OperatingSystem.IsWindows() && listener.SeenProvidersAndEvents.Contains("Microsoft-Windows-DotNETRuntime/EVENTID(65)")) |
48 |
| - || (!OperatingSystem.IsWindows() && listener.EventCount > 0)) |
| 66 | + Stopwatch sw = Stopwatch.StartNew(); |
| 67 | + |
| 68 | + while (sw.Elapsed <= TimeSpan.FromMinutes(1d / 12d)) |
49 | 69 | {
|
50 |
| - break; |
| 70 | + Thread.Sleep(100); |
| 71 | + |
| 72 | + if ((listener.EventsLeft <= 0) || (!OperatingSystem.IsWindows() && listener.EventCount > 0)) |
| 73 | + { |
| 74 | + break; |
| 75 | + } |
51 | 76 | }
|
52 |
| - } |
53 | 77 |
|
54 |
| - // Ensure that we've seen some events. |
55 |
| - foreach (string s in listener.SeenProvidersAndEvents) |
56 |
| - { |
57 |
| - Console.WriteLine(s); |
58 |
| - } |
| 78 | + Assert2.True("listener.EventCount > 0", listener.EventCount > 0); |
59 | 79 |
|
60 |
| - Assert.True("listener.EventCount > 0", listener.EventCount > 0); |
61 |
| - |
62 |
| - if (OperatingSystem.IsWindows()) |
63 |
| - { |
64 |
| - Assert.True("Saw the ThreadPoolIOPack event", listener.SeenProvidersAndEvents.Contains("Microsoft-Windows-DotNETRuntime/EVENTID(65)")); |
| 80 | + if (OperatingSystem.IsWindows()) |
| 81 | + { |
| 82 | + StringBuilder stringBuilder = new(); |
| 83 | + foreach (var e in listener.GetFailedTargetEvents()) |
| 84 | + { |
| 85 | + stringBuilder.Append((stringBuilder.Length > 0) ? ", " : ""); |
| 86 | + stringBuilder.Append(e.Key); |
| 87 | + } |
| 88 | + Assert2.True($"At least one of the EventIds ({stringBuilder}) where heard.", stringBuilder.Length < 1); |
| 89 | + } |
65 | 90 | }
|
66 | 91 | }
|
67 | 92 |
|
68 | 93 | // Generate some more GC events.
|
69 | 94 | GC.Collect(2, GCCollectionMode.Forced);
|
70 | 95 |
|
71 | 96 | // Ensure that we've seen no events.
|
72 |
| - Assert.True("noEventsListener.EventCount == 0", noEventsListener.EventCount == 0); |
| 97 | + Assert2.True("noEventsListener.EventCount == 0", noEventsListener.EventCount == 0); |
73 | 98 | }
|
74 | 99 |
|
75 | 100 | return 100;
|
76 | 101 | }
|
77 | 102 |
|
78 |
| - private static void Allocator() |
| 103 | + private static unsafe void DoOverlappedIO() |
79 | 104 | {
|
80 |
| - while (true) |
| 105 | + if (!OperatingSystem.IsWindows()) |
81 | 106 | {
|
82 |
| - for(int i=0; i<1000; i++) |
83 |
| - { |
84 |
| - GC.KeepAlive(new object()); |
85 |
| - } |
86 |
| - |
87 |
| - Thread.Sleep(10); |
| 107 | + return; |
88 | 108 | }
|
89 |
| - } |
90 |
| - |
91 |
| - private static unsafe void DoOverlappedIO() |
92 |
| - { |
93 | 109 | Console.WriteLine("DOOVERLAPPEDIO");
|
94 | 110 | Overlapped overlapped = new();
|
95 | 111 | NativeOverlapped* pOverlap = overlapped.Pack(null, null);
|
96 | 112 | Overlapped.Free(pOverlap);
|
97 | 113 | }
|
| 114 | + |
| 115 | + private static class Assert2 |
| 116 | + { |
| 117 | + public static void True(string name, bool condition) |
| 118 | + { |
| 119 | + if (!condition) |
| 120 | + { |
| 121 | + throw new Exception( |
| 122 | + string.Format("Condition '{0}' is not true", name)); |
| 123 | + } |
| 124 | + } |
| 125 | + } |
98 | 126 | }
|
99 | 127 |
|
100 |
| - internal sealed class SimpleEventListener : EventListener |
| 128 | + internal sealed unsafe class NativeOverlappedClass : IDisposable |
101 | 129 | {
|
102 |
| - public ConcurrentBag<string> SeenProvidersAndEvents { get; private set; } = new(); |
103 |
| - private string m_name; |
| 130 | + private bool disposedValue; |
| 131 | + private readonly NativeOverlapped* nativeOverlapped; |
104 | 132 |
|
105 |
| - // Keep track of the set of keywords to be enabled. |
106 |
| - public static EventKeywords EnableKeywords |
| 133 | + public NativeOverlappedClass() |
107 | 134 | {
|
108 |
| - get; |
109 |
| - set; |
| 135 | + if (OperatingSystem.IsWindows()) |
| 136 | + { |
| 137 | + nativeOverlapped = new Overlapped().Pack(null, null); |
| 138 | + } |
110 | 139 | }
|
111 | 140 |
|
112 |
| - public SimpleEventListener(string name) |
| 141 | + public bool ThreadPoolQueue() |
113 | 142 | {
|
114 |
| - m_name = name; |
| 143 | + return OperatingSystem.IsWindows() && ThreadPool.UnsafeQueueNativeOverlapped(nativeOverlapped); |
115 | 144 | }
|
116 | 145 |
|
117 |
| - public int EventCount { get; private set; } = 0; |
118 |
| - |
119 |
| - protected override void OnEventSourceCreated(EventSource eventSource) |
| 146 | + private void Dispose(bool disposing) |
120 | 147 | {
|
121 |
| - if (eventSource.Name.Equals("Microsoft-Windows-DotNETRuntime")) |
| 148 | + if (!disposedValue) |
122 | 149 | {
|
123 |
| - if (EnableKeywords != 0) |
| 150 | + if (disposing) |
124 | 151 | {
|
125 |
| - // Enable events. |
126 |
| - EnableEvents(eventSource, EventLevel.Verbose, EnableKeywords); |
| 152 | + // TODO: dispose managed state (managed objects) |
127 | 153 | }
|
128 |
| - else |
| 154 | + |
| 155 | + if (OperatingSystem.IsWindows()) |
129 | 156 | {
|
130 |
| - // Enable the provider, but not any keywords, so we should get no events as long as no rundown occurs. |
131 |
| - EnableEvents(eventSource, EventLevel.Critical, EnableKeywords); |
| 157 | + Overlapped.Free(nativeOverlapped); |
132 | 158 | }
|
| 159 | + |
| 160 | + disposedValue = true; |
133 | 161 | }
|
134 | 162 | }
|
135 | 163 |
|
136 |
| - protected override void OnEventWritten(EventWrittenEventArgs eventData) |
| 164 | + ~NativeOverlappedClass() |
137 | 165 | {
|
138 |
| - Console.WriteLine($"[{m_name}] ThreadID = {eventData.OSThreadId} ID = {eventData.EventId} Name = {eventData.EventName}"); |
139 |
| - Console.WriteLine($"TimeStamp: {eventData.TimeStamp.ToLocalTime()}"); |
140 |
| - Console.WriteLine($"LocalTime: {DateTime.Now}"); |
141 |
| - Console.WriteLine($"Difference: {DateTime.UtcNow - eventData.TimeStamp}"); |
142 |
| - Assert.True("eventData.TimeStamp <= DateTime.UtcNow", eventData.TimeStamp <= DateTime.UtcNow); |
143 |
| - for (int i = 0; i < eventData.Payload.Count; i++) |
| 166 | + Dispose(disposing: false); |
| 167 | + } |
| 168 | + |
| 169 | + public void Dispose() |
| 170 | + { |
| 171 | + Dispose(disposing: true); |
| 172 | + GC.SuppressFinalize(this); |
| 173 | + } |
| 174 | + } |
| 175 | + |
| 176 | + internal sealed class Listener : EventListener |
| 177 | + { |
| 178 | + public static string EventSourceName = "Microsoft-Windows-DotNETRuntime"; |
| 179 | + public static EventLevel Level = EventLevel.Verbose; |
| 180 | + public static EventKeywords EnableKeywords = EventKeywords.All; |
| 181 | + |
| 182 | + public int EventCount { get; private set; } = 0; |
| 183 | + public int EventsLeft { get; private set; } = 0; |
| 184 | + |
| 185 | + private static readonly ConcurrentBag<int> targetEventIds = new(); |
| 186 | + private static readonly (string, string) defaultEventSourceNameName = ("Failed to listen", "Was not heard or didn't fire"); |
| 187 | + |
| 188 | + private readonly string name = ""; |
| 189 | + private readonly ConcurrentDictionary<int, (string, string)> eventIdSourceNameNames = new(); |
| 190 | + |
| 191 | + public Listener(string name = nameof(Listener)) |
| 192 | + { |
| 193 | + this.name = $"({name}) "; |
| 194 | + } |
| 195 | + |
| 196 | + public static void TargetEventIds(params int[] ids) |
| 197 | + { |
| 198 | + targetEventIds.Clear(); |
| 199 | + |
| 200 | + foreach (int id in ids) |
| 201 | + { |
| 202 | + targetEventIds.Add(id); |
| 203 | + } |
| 204 | + } |
| 205 | + public IEnumerable<KeyValuePair<int, (string, string)>> GetFailedTargetEvents() |
| 206 | + { |
| 207 | + foreach (KeyValuePair<int, (string, string)> e in eventIdSourceNameNames) |
| 208 | + { |
| 209 | + if (e.Value == defaultEventSourceNameName) |
| 210 | + { |
| 211 | + yield return e; |
| 212 | + } |
| 213 | + } |
| 214 | + } |
| 215 | + public override void Dispose() |
| 216 | + { |
| 217 | + base.Dispose(); |
| 218 | + |
| 219 | + foreach (KeyValuePair<int, (string, string)> e in eventIdSourceNameNames) |
144 | 220 | {
|
145 |
| - string payloadString = eventData.Payload[i] != null ? eventData.Payload[i].ToString() : string.Empty; |
146 |
| - Console.WriteLine($"\tName = \"{eventData.PayloadNames[i]}\" Value = \"{payloadString}\""); |
| 221 | + WriteLine(e); |
147 | 222 | }
|
148 |
| - Console.WriteLine("\n"); |
149 | 223 |
|
150 |
| - SeenProvidersAndEvents.Add($"{eventData.EventSource.Name}"); |
151 |
| - SeenProvidersAndEvents.Add($"{eventData.EventSource.Name}/EVENTID({eventData.EventId})"); |
| 224 | + WriteLine("\n"); |
| 225 | + } |
| 226 | + |
| 227 | + protected override void OnEventSourceCreated(EventSource eventSource) |
| 228 | + { |
| 229 | + if ((eventSource.Name == EventSourceName) && eventIdSourceNameNames.IsEmpty) |
| 230 | + { |
| 231 | + foreach (var targetEventId in targetEventIds) |
| 232 | + { |
| 233 | + eventIdSourceNameNames[targetEventId] = defaultEventSourceNameName; |
| 234 | + } |
| 235 | + EventsLeft = eventIdSourceNameNames.Count; |
152 | 236 |
|
| 237 | + EnableEvents(eventSource, Level, EnableKeywords); |
| 238 | + } |
| 239 | + } |
| 240 | + protected override void OnEventWritten(EventWrittenEventArgs eventWrittenEventArgs) |
| 241 | + { |
153 | 242 | EventCount++;
|
| 243 | + |
| 244 | + KeyValuePair<int, (string SourceName, string Name)> e = new( |
| 245 | + eventWrittenEventArgs.EventId, |
| 246 | + (eventWrittenEventArgs.EventSource.Name, eventWrittenEventArgs.EventName ?? "")); |
| 247 | + |
| 248 | + EventsLeft -= (eventIdSourceNameNames.TryGetValue(e.Key, out (string, string) value) && value == defaultEventSourceNameName) ? 1 : 0; |
| 249 | + eventIdSourceNameNames[e.Key] = e.Value; |
| 250 | + |
| 251 | + WriteLine(e); |
| 252 | + |
| 253 | + WriteLine($"OSThreadId = {eventWrittenEventArgs.OSThreadId}", ConsoleColor.Yellow); |
| 254 | + |
| 255 | + WriteLine($"TimeStamp: {eventWrittenEventArgs.TimeStamp.ToLocalTime()}"); |
| 256 | + WriteLine($"local time: {DateTime.Now}"); |
| 257 | + WriteLine($"Difference: {DateTime.UtcNow - eventWrittenEventArgs.TimeStamp}"); |
| 258 | + |
| 259 | + for (int i = 0; (i < eventWrittenEventArgs.PayloadNames?.Count) && (i < eventWrittenEventArgs.Payload?.Count); i++) |
| 260 | + { |
| 261 | + WriteLine($"{eventWrittenEventArgs.PayloadNames[i]} = {eventWrittenEventArgs.Payload[i]}", ConsoleColor.Magenta); |
| 262 | + } |
| 263 | + |
| 264 | + WriteLine("\n"); |
| 265 | + } |
| 266 | + |
| 267 | + private void Write(object? o = null, ConsoleColor? consoleColor = null) |
| 268 | + { |
| 269 | + ConsoleColor foregroundColor = Console.ForegroundColor; |
| 270 | + |
| 271 | + if (o is KeyValuePair<int, (string, string)> e) |
| 272 | + { |
| 273 | + Console.ForegroundColor = ConsoleColor.Cyan; |
| 274 | + Console.Write(name); |
| 275 | + |
| 276 | + Console.ForegroundColor = (e.Value != defaultEventSourceNameName) ? ConsoleColor.Green : ConsoleColor.Red; |
| 277 | + } |
| 278 | + else if (consoleColor != null) |
| 279 | + { |
| 280 | + Console.ForegroundColor = (ConsoleColor)consoleColor; |
| 281 | + } |
| 282 | + Console.Write(o); |
| 283 | + |
| 284 | + Console.ForegroundColor = foregroundColor; |
| 285 | + } |
| 286 | + private void WriteLine(object? o = null, ConsoleColor? consoleColor = null) |
| 287 | + { |
| 288 | + Write(o, consoleColor); |
| 289 | + Console.WriteLine(); |
154 | 290 | }
|
155 | 291 | }
|
156 | 292 | }
|
0 commit comments