[release/6.0-rc1] Add event to RuntimeEventSource for AppContext switches (#57847)
authorgithub-actions[bot] <41898282+github-actions[bot]@users.noreply.github.com>
Wed, 25 Aug 2021 15:45:46 +0000 (08:45 -0700)
committerGitHub <noreply@github.com>
Wed, 25 Aug 2021 15:45:46 +0000 (08:45 -0700)
* 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 <angocke@microsoft.com>
src/libraries/System.Private.CoreLib/src/System/AppContext.AnyOS.cs
src/libraries/System.Private.CoreLib/src/System/Diagnostics/Tracing/RuntimeEventSource.cs
src/tests/tracing/eventcounter/runtimecounters.cs
src/tests/tracing/runtimeeventsource/NativeRuntimeEventSourceTest.cs [new file with mode: 0644]
src/tests/tracing/runtimeeventsource/RuntimeEventSourceTest.cs
src/tests/tracing/runtimeeventsource/nativeruntimeeventsource.csproj [new file with mode: 0644]
src/tests/tracing/runtimeeventsource/runtimeeventsource.csproj

index c8b5fcb..94760aa 100644 (file)
@@ -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<string, bool> 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<string, bool>? switches)
+                    {
+                        Debug.Assert(s_dataStore is not null);
+                        foreach (KeyValuePair<string, object?> 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);
+                            }
+                        }
+                    }
+                }
+            }
+        }
     }
 }
index 6d57c82..3b3ac30 100644 (file)
@@ -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);
             }
 
         }
index bdab454..e662364 100644 (file)
@@ -54,7 +54,9 @@ namespace RuntimeEventCounterTests
             {
                 Dictionary<string, string> refreshInterval = new Dictionary<string, string>();
                 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 (file)
index 0000000..43306a8
--- /dev/null
@@ -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++;
+        }
+    }
+}
index 4474176..3a4b4bd 100644 (file)
 // 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<string, bool> ObservedEvents = new Dictionary<string, bool>();
 
-                // 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 (file)
index 0000000..7033605
--- /dev/null
@@ -0,0 +1,21 @@
+<Project Sdk="Microsoft.NET.Sdk">
+  <PropertyGroup>
+    <OutputType>Exe</OutputType>
+    <CLRTestKind>BuildAndRun</CLRTestKind>
+    <AllowUnsafeBlocks>true</AllowUnsafeBlocks>
+    <CLRTestPriority>0</CLRTestPriority>
+    <GCStressIncompatible>true</GCStressIncompatible>
+    <!-- This test has a secondary thread with an infinite loop -->
+    <UnloadabilityIncompatible>true</UnloadabilityIncompatible>
+    <!--
+      Test is blocking official build.
+      Related failures: #18907, #19340, #22441, #22729.
+      Issue tracking to re-enable: #22898.
+    -->
+    <DisableProjectBuild>true</DisableProjectBuild>
+  </PropertyGroup>
+  <ItemGroup>
+    <Compile Include="RuntimeEventSourceTest.cs" />
+    <ProjectReference Include="../common/common.csproj" />
+  </ItemGroup>
+</Project>
index 7033605..7907530 100644 (file)
@@ -4,18 +4,13 @@
     <CLRTestKind>BuildAndRun</CLRTestKind>
     <AllowUnsafeBlocks>true</AllowUnsafeBlocks>
     <CLRTestPriority>0</CLRTestPriority>
-    <GCStressIncompatible>true</GCStressIncompatible>
     <!-- This test has a secondary thread with an infinite loop -->
     <UnloadabilityIncompatible>true</UnloadabilityIncompatible>
-    <!--
-      Test is blocking official build.
-      Related failures: #18907, #19340, #22441, #22729.
-      Issue tracking to re-enable: #22898.
-    -->
-    <DisableProjectBuild>true</DisableProjectBuild>
+    <DisableProjectBuild Condition="'$(RuntimeFlavor)' == 'mono'">true</DisableProjectBuild>
   </PropertyGroup>
   <ItemGroup>
     <Compile Include="RuntimeEventSourceTest.cs" />
     <ProjectReference Include="../common/common.csproj" />
+    <RuntimeHostConfigurationOption Include="RuntimeHostConfigSwitch" Value="true" />
   </ItemGroup>
 </Project>