From: github-actions[bot] <41898282+github-actions[bot]@users.noreply.github.com> Date: Wed, 25 Aug 2021 15:45:46 +0000 (-0700) Subject: [release/6.0-rc1] Add event to RuntimeEventSource for AppContext switches (#57847) X-Git-Tag: accepted/tizen/unified/20220110.054933~222^2~21 X-Git-Url: http://review.tizen.org/git/?a=commitdiff_plain;h=75e6a7fc45b809ea08bf0ff58ec51fcdad391a89;p=platform%2Fupstream%2Fdotnet%2Fruntime.git [release/6.0-rc1] Add event to RuntimeEventSource for AppContext switches (#57847) * Add event to RuntimeEventSource for AppContext switches Fixes https://github.com/dotnet/runtime/issues/56142 * Respond to PR comments * Add preliminary tests * Respond to PR comments * Add keyword * Fix tests * Remove AppContext EventSource support on browser * forgot using * Fix error reporting, add comments * Respond to PR comments * Refactor tests * Fix case where s_switches is null * Fix bug * Print more info for test failure * Typo * Fix lab failure * Respond to PR comments * Respond to PR comments * Typo * Respond to PR comments * Skip RuntimeEventSource tests on wasm and android (#57890) * Skip RuntimeEventSource tests on wasm and android * Skip tests without using issues.targets * Disable test for mono (cherry picked from commit 454ac571fe489ab818c7727f11eee71d521c4366) Co-authored-by: Andy Gocke --- diff --git a/src/libraries/System.Private.CoreLib/src/System/AppContext.AnyOS.cs b/src/libraries/System.Private.CoreLib/src/System/AppContext.AnyOS.cs index c8b5fcb..94760aa 100644 --- a/src/libraries/System.Private.CoreLib/src/System/AppContext.AnyOS.cs +++ b/src/libraries/System.Private.CoreLib/src/System/AppContext.AnyOS.cs @@ -1,7 +1,10 @@ // Licensed to the .NET Foundation under one or more agreements. // The .NET Foundation licenses this file to you under the MIT license. +using System.Collections.Generic; +using System.Diagnostics; using System.Diagnostics.CodeAnalysis; +using System.Diagnostics.Tracing; using System.IO; using System.Reflection; @@ -30,5 +33,52 @@ namespace System return directory; } + + internal static void LogSwitchValues(RuntimeEventSource ev) + { + if (s_switches is not null) + { + lock (s_switches) + { + foreach (KeyValuePair kvp in s_switches) + { + // Convert bool to int because it's cheaper to log (no boxing) + ev.LogAppContextSwitch(kvp.Key, kvp.Value ? 1 : 0); + } + } + } + + if (s_dataStore is not null) + { + lock (s_dataStore) + { + if (s_switches is not null) + { + lock (s_switches) + { + LogDataStore(ev, s_switches); + } + } + else + { + LogDataStore(ev, null); + } + + static void LogDataStore(RuntimeEventSource ev, Dictionary? switches) + { + Debug.Assert(s_dataStore is not null); + foreach (KeyValuePair kvp in s_dataStore) + { + if (kvp.Value is string s && + bool.TryParse(s, out bool isEnabled) && + switches?.ContainsKey(kvp.Key) != true) + { + ev.LogAppContextSwitch(kvp.Key, isEnabled ? 1 : 0); + } + } + } + } + } + } } } diff --git a/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/RuntimeEventSource.cs b/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/RuntimeEventSource.cs index 6d57c82..3b3ac30 100644 --- a/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/RuntimeEventSource.cs +++ b/src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/RuntimeEventSource.cs @@ -14,6 +14,11 @@ namespace System.Diagnostics.Tracing { internal const string EventSourceName = "System.Runtime"; + public static class Keywords + { + public const EventKeywords AppContext = (EventKeywords)0x1; + } + private static RuntimeEventSource? s_RuntimeEventSource; private PollingCounter? _gcHeapSizeCounter; private IncrementingPollingCounter? _gen0GCCounter; @@ -50,6 +55,17 @@ namespace System.Diagnostics.Tracing // as you can't make a constructor partial. private RuntimeEventSource(int _) { } + private enum EventId : int + { + AppContextSwitch = 1 + } + + [Event((int)EventId.AppContextSwitch, Level = EventLevel.Informational, Keywords = Keywords.AppContext)] + internal void LogAppContextSwitch(string switchName, int value) + { + base.WriteEvent((int)EventId.AppContextSwitch, switchName, value); + } + protected override void OnEventCommand(EventCommandEventArgs command) { if (command.Command == EventCommand.Enable) @@ -87,6 +103,8 @@ namespace System.Diagnostics.Tracing _ilBytesJittedCounter ??= new PollingCounter("il-bytes-jitted", this, () => System.Runtime.JitInfo.GetCompiledILBytes()) { DisplayName = "IL Bytes Jitted", DisplayUnits = "B" }; _methodsJittedCounter ??= new PollingCounter("methods-jitted-count", this, () => System.Runtime.JitInfo.GetCompiledMethodCount()) { DisplayName = "Number of Methods Jitted" }; _jitTimeCounter ??= new IncrementingPollingCounter("time-in-jit", this, () => System.Runtime.JitInfo.GetCompilationTime().TotalMilliseconds) { DisplayName = "Time spent in JIT", DisplayUnits = "ms", DisplayRateTimeScale = new TimeSpan(0, 0, 1) }; + + AppContext.LogSwitchValues(this); } } diff --git a/src/tests/tracing/eventcounter/runtimecounters.cs b/src/tests/tracing/eventcounter/runtimecounters.cs index bdab454..e662364 100644 --- a/src/tests/tracing/eventcounter/runtimecounters.cs +++ b/src/tests/tracing/eventcounter/runtimecounters.cs @@ -54,7 +54,9 @@ namespace RuntimeEventCounterTests { Dictionary refreshInterval = new Dictionary(); refreshInterval.Add("EventCounterIntervalSec", "1"); - EnableEvents(source, EventLevel.Informational, (EventKeywords)(-1), refreshInterval); + EnableEvents(source, EventLevel.Informational, + (EventKeywords)(-1 & (~1 /* RuntimeEventSource.Keywords.AppContext */)), + refreshInterval); } } @@ -100,7 +102,7 @@ namespace RuntimeEventCounterTests // Create an EventListener. using (RuntimeCounterListener myListener = new RuntimeCounterListener()) { - Thread.Sleep(3000); + Thread.Sleep(3000); if (myListener.Verify()) { Console.WriteLine("Test passed"); diff --git a/src/tests/tracing/runtimeeventsource/NativeRuntimeEventSourceTest.cs b/src/tests/tracing/runtimeeventsource/NativeRuntimeEventSourceTest.cs new file mode 100644 index 0000000..43306a8 --- /dev/null +++ b/src/tests/tracing/runtimeeventsource/NativeRuntimeEventSourceTest.cs @@ -0,0 +1,114 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. + +using System; +using System.IO; +using System.Diagnostics.Tracing; +using System.Runtime.CompilerServices; +using System.Threading; +using Tracing.Tests.Common; + +namespace Tracing.Tests +{ + public sealed class NativeRuntimeEventSourceTest + { + static int Main(string[] args) + { + SimpleEventListener.EnableKeywords = (EventKeywords)0; + using (SimpleEventListener noEventsListener = new SimpleEventListener("NoEvents")) + { + // Create an EventListener. + SimpleEventListener.EnableKeywords = (EventKeywords)0x4c14fccbd; + using (SimpleEventListener listener = new SimpleEventListener("Simple")) + { + // Trigger the allocator task. + System.Threading.Tasks.Task.Run(new Action(Allocator)); + + // Wait for events. + Thread.Sleep(1000); + + // Generate some GC events. + GC.Collect(2, GCCollectionMode.Forced); + + // Wait for more events. + Thread.Sleep(1000); + + // Ensure that we've seen some events. + Assert.True("listener.EventCount > 0", listener.EventCount > 0); + } + + // Generate some more GC events. + GC.Collect(2, GCCollectionMode.Forced); + + // Ensure that we've seen no events. + Assert.True("noEventsListener.EventCount == 0", noEventsListener.EventCount == 0); + } + + return 100; + } + + private static void Allocator() + { + while (true) + { + for(int i=0; i<1000; i++) + GC.KeepAlive(new object()); + + Thread.Sleep(10); + } + } + } + + internal sealed class SimpleEventListener : EventListener + { + private string m_name; + + // Keep track of the set of keywords to be enabled. + public static EventKeywords EnableKeywords + { + get; + set; + } + + public SimpleEventListener(string name) + { + m_name = name; + } + + public int EventCount { get; private set; } = 0; + + protected override void OnEventSourceCreated(EventSource eventSource) + { + if (eventSource.Name.Equals("Microsoft-Windows-DotNETRuntime")) + { + if (EnableKeywords != 0) + { + // Enable events. + EnableEvents(eventSource, EventLevel.Verbose, EnableKeywords); + } + else + { + // Enable the provider, but not any keywords, so we should get no events as long as no rundown occurs. + EnableEvents(eventSource, EventLevel.Critical, EnableKeywords); + } + } + } + + protected override void OnEventWritten(EventWrittenEventArgs eventData) + { + Console.WriteLine($"[{m_name}] ThreadID = {eventData.OSThreadId} ID = {eventData.EventId} Name = {eventData.EventName}"); + Console.WriteLine($"TimeStamp: {eventData.TimeStamp.ToLocalTime()}"); + Console.WriteLine($"LocalTime: {DateTime.Now}"); + Console.WriteLine($"Difference: {DateTime.UtcNow - eventData.TimeStamp}"); + Assert.True("eventData.TimeStamp <= DateTime.UtcNow", eventData.TimeStamp <= DateTime.UtcNow); + for (int i = 0; i < eventData.Payload.Count; i++) + { + string payloadString = eventData.Payload[i] != null ? eventData.Payload[i].ToString() : string.Empty; + Console.WriteLine($"\tName = \"{eventData.PayloadNames[i]}\" Value = \"{payloadString}\""); + } + Console.WriteLine("\n"); + + EventCount++; + } + } +} diff --git a/src/tests/tracing/runtimeeventsource/RuntimeEventSourceTest.cs b/src/tests/tracing/runtimeeventsource/RuntimeEventSourceTest.cs index 4474176..3a4b4bd 100644 --- a/src/tests/tracing/runtimeeventsource/RuntimeEventSourceTest.cs +++ b/src/tests/tracing/runtimeeventsource/RuntimeEventSourceTest.cs @@ -1,114 +1,101 @@ // Licensed to the .NET Foundation under one or more agreements. // The .NET Foundation licenses this file to you under the MIT license. -using System; -using System.IO; +#if USE_MDT_EVENTSOURCE +using Microsoft.Diagnostics.Tracing; +#else using System.Diagnostics.Tracing; -using System.Runtime.CompilerServices; +#endif +using System; +using System.Collections.Generic; using System.Threading; -using Tracing.Tests.Common; +using System.Threading.Tasks; +using System.Diagnostics; -namespace Tracing.Tests +AppContext.SetSwitch("appContextSwitch", true); +AppDomain.CurrentDomain.SetData("appContextBoolData", true); // Not loggeed, bool key +AppDomain.CurrentDomain.SetData("appContextBoolAsStringData", "true"); +AppDomain.CurrentDomain.SetData("appContextStringData", "myString"); // Not logged, string does not parse as bool +AppDomain.CurrentDomain.SetData("appContextSwitch", "false"); // should not override the SetSwitch above + +// Create an EventListener. +using (var myListener = new RuntimeEventListener()) { - public sealed class RuntimeEventSourceTest + if (myListener.Verify()) + { + Console.WriteLine("Test passed"); + return 100; + } + else { - static int Main(string[] args) + Console.WriteLine($"Test Failed - did not see one or more of the expected runtime counters."); + Console.WriteLine("Observed events: "); + foreach (var (k, v) in myListener.ObservedEvents) { - SimpleEventListener.EnableKeywords = (EventKeywords)0; - using (SimpleEventListener noEventsListener = new SimpleEventListener("NoEvents")) - { - // Create an EventListener. - SimpleEventListener.EnableKeywords = (EventKeywords)0x4c14fccbd; - using (SimpleEventListener listener = new SimpleEventListener("Simple")) - { - // Trigger the allocator task. - System.Threading.Tasks.Task.Run(new Action(Allocator)); - - // Wait for events. - Thread.Sleep(1000); - - // Generate some GC events. - GC.Collect(2, GCCollectionMode.Forced); - - // Wait for more events. - Thread.Sleep(1000); - - // Ensure that we've seen some events. - Assert.True("listener.EventCount > 0", listener.EventCount > 0); - } + Console.WriteLine("Event: " + k + " " + v); + } + return 1; + } +} - // Generate some more GC events. - GC.Collect(2, GCCollectionMode.Forced); +public class RuntimeEventListener : EventListener +{ + internal readonly Dictionary ObservedEvents = new Dictionary(); - // Ensure that we've seen no events. - Assert.True("noEventsListener.EventCount == 0", noEventsListener.EventCount == 0); - } + private static readonly string[] s_expectedEvents = new[] { + "appContextSwitch", + "appContextBoolAsStringData", + "RuntimeHostConfigSwitch", // Set in the project file + }; - return 100; - } + private static readonly string[] s_unexpectedEvents = new[] { + "appContextBoolData", + "appContextStringData", + }; - private static void Allocator() + protected override void OnEventSourceCreated(EventSource source) + { + if (source.Name.Equals("System.Runtime")) { - while (true) - { - for(int i=0; i<1000; i++) - GC.KeepAlive(new object()); - - Thread.Sleep(10); - } + EnableEvents(source, EventLevel.Informational, (EventKeywords)1 /* RuntimeEventSource.Keywords.AppContext */); } } - internal sealed class SimpleEventListener : EventListener + protected override void OnEventWritten(EventWrittenEventArgs eventData) { - private string m_name; - - // Keep track of the set of keywords to be enabled. - public static EventKeywords EnableKeywords - { - get; - set; - } - - public SimpleEventListener(string name) + // Check AppContext switches + if (eventData is { EventName: "LogAppContextSwitch", + Payload: { Count: 2 } }) { - m_name = name; + var switchName = (string)eventData.Payload[0]; + ObservedEvents[switchName] = ((int)eventData.Payload[1]) == 1; + return; } + } - public int EventCount { get; private set; } = 0; - - protected override void OnEventSourceCreated(EventSource eventSource) + public bool Verify() + { + foreach (var key in s_expectedEvents) { - if (eventSource.Name.Equals("Microsoft-Windows-DotNETRuntime")) + if (!ObservedEvents[key]) { - if (EnableKeywords != 0) - { - // Enable events. - EnableEvents(eventSource, EventLevel.Verbose, EnableKeywords); - } - else - { - // Enable the provider, but not any keywords, so we should get no events as long as no rundown occurs. - EnableEvents(eventSource, EventLevel.Critical, EnableKeywords); - } + Console.WriteLine($"Could not find key {key}"); + return false; + } + else + { + Console.WriteLine($"Saw {key}"); } } - protected override void OnEventWritten(EventWrittenEventArgs eventData) + foreach (var key in s_unexpectedEvents) { - Console.WriteLine($"[{m_name}] ThreadID = {eventData.OSThreadId} ID = {eventData.EventId} Name = {eventData.EventName}"); - Console.WriteLine($"TimeStamp: {eventData.TimeStamp.ToLocalTime()}"); - Console.WriteLine($"LocalTime: {DateTime.Now}"); - Console.WriteLine($"Difference: {DateTime.UtcNow - eventData.TimeStamp}"); - Assert.True("eventData.TimeStamp <= DateTime.UtcNow", eventData.TimeStamp <= DateTime.UtcNow); - for (int i = 0; i < eventData.Payload.Count; i++) + if (ObservedEvents.ContainsKey(key)) { - string payloadString = eventData.Payload[i] != null ? eventData.Payload[i].ToString() : string.Empty; - Console.WriteLine($"\tName = \"{eventData.PayloadNames[i]}\" Value = \"{payloadString}\""); + Console.WriteLine($"Should not have seen {key}"); + return false; } - Console.WriteLine("\n"); - - EventCount++; } + return true; } -} +} \ No newline at end of file diff --git a/src/tests/tracing/runtimeeventsource/nativeruntimeeventsource.csproj b/src/tests/tracing/runtimeeventsource/nativeruntimeeventsource.csproj new file mode 100644 index 0000000..7033605 --- /dev/null +++ b/src/tests/tracing/runtimeeventsource/nativeruntimeeventsource.csproj @@ -0,0 +1,21 @@ + + + Exe + BuildAndRun + true + 0 + true + + true + + true + + + + + + diff --git a/src/tests/tracing/runtimeeventsource/runtimeeventsource.csproj b/src/tests/tracing/runtimeeventsource/runtimeeventsource.csproj index 7033605..7907530 100644 --- a/src/tests/tracing/runtimeeventsource/runtimeeventsource.csproj +++ b/src/tests/tracing/runtimeeventsource/runtimeeventsource.csproj @@ -4,18 +4,13 @@ BuildAndRun true 0 - true true - - true + true +