Add event tracing to NuGet.Common and write events for the NuGet-based MSBuid project SDK resolver

src/NuGet.Core/Microsoft.Build.NuGetSdkResolver/GlobalJsonReader.cs

@@ -4,11 +4,13 @@
 using System;
 using System.Collections.Concurrent;
 using System.Collections.Generic;
+using System.Diagnostics.Tracing;
 using System.Globalization;
 using System.IO;
 using System.Runtime.CompilerServices;
 using Microsoft.Build.Framework;
 using Newtonsoft.Json;
+using NuGet.Common;
 
 namespace Microsoft.Build.NuGetSdkResolver
 {
@@ -28,6 +30,11 @@ internal sealed class GlobalJsonReader : IGlobalJsonReader
         /// </summary>
         public const string MSBuildSdksPropertyName = "msbuild-sdks";
 
+        /// <summary>
+        /// A trace event name for when a global.json file is read.
+        /// </summary>
+        private const string EventNameGlobalJsonRead = nameof(SdkResolver) + "/GlobalJsonRead";
+
         /// <summary>
         /// Represents a thread-safe cache for files based on their full path and last write time.
         /// </summary>
@@ -238,37 +245,69 @@ private Dictionary<string, string> ParseMSBuildSdkVersions(string globalJsonPath
             // Load the file as a string and check if it has an msbuild-sdks section.  Parsing the contents requires Newtonsoft.Json.dll to be loaded which can be expensive
             string json;
 
-            try
+            var eventData = new
             {
-                json = File.ReadAllText(globalJsonPath);
-            }
-            catch (Exception e)
+                Path = globalJsonPath,
+                ProjectFullPath = sdkResolverContext.ProjectFilePath,
+                SolutionFullPath = sdkResolverContext.SolutionFilePath
+            };
+
+            NuGetEventSource.Instance.Write(
+                EventNameGlobalJsonRead,
+                new EventSourceOptions
+                {
+                    ActivityOptions = EventActivityOptions.Detachable,
+                    Keywords = NuGetEventSource.Keywords.SdkResolver | NuGetEventSource.Keywords.Performance,
+                    Opcode = EventOpcode.Start
+                },
+                eventData);
+
+            try
             {
-                // Failed to read file "{0}". {1}
-                sdkResolverContext.Logger.LogMessage(string.Format(CultureInfo.CurrentCulture, Strings.FailedToReadGlobalJson, globalJsonPath, e.Message));
+                try
+                {
+                    json = File.ReadAllText(globalJsonPath);
+                }
+                catch (Exception e)
+                {
+                    // Failed to read file "{0}". {1}
+                    sdkResolverContext.Logger.LogMessage(string.Format(CultureInfo.CurrentCulture, Strings.FailedToReadGlobalJson, globalJsonPath, e.Message));
 
-                return null;
-            }
+                    return null;
+                }
 
-            OnFileRead(globalJsonPath);
+                OnFileRead(globalJsonPath);
 
-            // Look ahead in the contents to see if there is an msbuild-sdks section.  Deserializing the file requires us to load
-            // Newtonsoft.Json which is 500 KB while a global.json is usually ~100 bytes of text.
-            if (json.IndexOf(MSBuildSdksPropertyName, StringComparison.Ordinal) == -1)
-            {
-                return null;
-            }
+                // Look ahead in the contents to see if there is an msbuild-sdks section.  Deserializing the file requires us to load
+                // Newtonsoft.Json which is 500 KB while a global.json is usually ~100 bytes of text.
+                if (json.IndexOf(MSBuildSdksPropertyName, StringComparison.Ordinal) == -1)
+                {
+                    return null;
+                }
 
-            try
-            {
-                return ParseMSBuildSdkVersionsFromJson(json);
+                try
+                {
+                    return ParseMSBuildSdkVersionsFromJson(json);
+                }
+                catch (Exception e)
+                {
+                    // Failed to parse "{0}". {1}
+                    sdkResolverContext.Logger.LogMessage(string.Format(CultureInfo.CurrentCulture, Strings.FailedToParseGlobalJson, globalJsonPath, e.Message));
+
+                    return null;
+                }
             }
-            catch (Exception e)
+            finally
             {
-                // Failed to parse "{0}". {1}
-                sdkResolverContext.Logger.LogMessage(string.Format(CultureInfo.CurrentCulture, Strings.FailedToParseGlobalJson, globalJsonPath, e.Message));
-
-                return null;
+                NuGetEventSource.Instance.Write(
+                EventNameGlobalJsonRead,
+                new EventSourceOptions
+                {
+                    ActivityOptions = EventActivityOptions.Detachable,
+                    Keywords = NuGetEventSource.Keywords.SdkResolver | NuGetEventSource.Keywords.Performance,
+                    Opcode = EventOpcode.Stop
+                },
+                eventData);
             }
         }
     }

src/NuGet.Core/Microsoft.Build.NuGetSdkResolver/NuGetSdkLogger.cs

@@ -3,6 +3,7 @@
 
 using System;
 using System.Collections.Generic;
+using System.Diagnostics.Tracing;
 using System.Threading.Tasks;
 using Microsoft.Build.Framework;
 using NuGet.Common;
@@ -55,32 +56,57 @@ public NuGetSdkLogger(SdkLogger sdkLogger)
         /// <inheritdoc cref="ILogger.Log(NuGet.Common.LogLevel, string)" />
         public void Log(LogLevel level, string data)
         {
+            EventLevel eventLevel = EventLevel.LogAlways;
+
             switch (level)
             {
                 case LogLevel.Debug:
                 case LogLevel.Verbose:
                     // Debug and Verbose verbosity in NuGet maps to a low importance message in MSBuild
                     _sdkLogger.LogMessage(data, MessageImportance.Low);
+
+                    eventLevel = EventLevel.Verbose;
                     break;
 
                 case LogLevel.Information:
                     // Information verbosity in NuGet maps to a normal importance message in MSBuild
                     _sdkLogger.LogMessage(data, MessageImportance.Normal);
+
+                    eventLevel = EventLevel.Informational;
                     break;
 
                 case LogLevel.Minimal:
                     // Minimal verbosity in NuGet maps to a high importance message in MSBuild
                     _sdkLogger.LogMessage(data, MessageImportance.High);
+
+                    eventLevel = EventLevel.LogAlways;
                     break;
 
                 case LogLevel.Warning:
                     _warnings.Add(data);
+
+                    eventLevel = EventLevel.Warning;
                     break;
 
                 case LogLevel.Error:
                     _errors.Add(data);
+
+                    eventLevel = EventLevel.Error;
                     break;
             }
+
+            NuGetEventSource.Instance.Write(
+                "SdkResolver/LogMessage",
+                new EventSourceOptions
+                {
+                    Level = eventLevel,
+                    Keywords = NuGetEventSource.Keywords.Logging,
+                },
+                new
+                {
+                    Level = level,
+                    Message = data
+                });
         }
 
         /// <inheritdoc cref="ILogger.LogAsync(ILogMessage)" />