From 85ac838b4df74f2ca406020feb3c22011bc2d3b0 Mon Sep 17 00:00:00 2001 From: Jan Krivanek Date: Fri, 21 Feb 2025 18:35:58 +0100 Subject: [PATCH 01/10] Integrate the initial node metrics --- src/Build.UnitTests/TelemetryTests.cs | 26 ++++ .../BackEnd/BuildManager/BuildManager.cs | 12 +- src/Build/Microsoft.Build.csproj | 1 + .../TelemetryInfra/TelemetryDataUtils.cs | 138 ++++++++++++++++++ .../Microsoft.Build.Framework.csproj | 2 +- src/Framework/Telemetry/ActivityExtensions.cs | 9 +- .../InternalTelemetryConsumingLogger.cs | 2 + src/Framework/Telemetry/TaskExecutionStats.cs | 11 ++ 8 files changed, 194 insertions(+), 7 deletions(-) create mode 100644 src/Build/TelemetryInfra/TelemetryDataUtils.cs diff --git a/src/Build.UnitTests/TelemetryTests.cs b/src/Build.UnitTests/TelemetryTests.cs index d62c003647f..8db9561a59a 100644 --- a/src/Build.UnitTests/TelemetryTests.cs +++ b/src/Build.UnitTests/TelemetryTests.cs @@ -6,6 +6,7 @@ using System.Linq; using Microsoft.Build.Execution; using Microsoft.Build.Framework; +using Microsoft.Build.Framework.Telemetry; using Microsoft.Build.UnitTests; using Shouldly; using Xunit; @@ -165,5 +166,30 @@ public void WorkerNodeTelemetryCollection_CustomTargetsAndTasks() workerNodeTelemetryData.TasksExecutionData.Keys.ShouldAllBe(k => !k.IsFromNugetCache); } + + [Fact] + public void Foo() + { + WorkerNodeTelemetryData wd = new WorkerNodeTelemetryData( + new Dictionary() + { + { + new TaskOrTargetTelemetryKey("TaskA", false, true), + new TaskExecutionStats(TimeSpan.FromSeconds(2), 5, 545) + }, + { + new TaskOrTargetTelemetryKey("TaskA", true, false), + new TaskExecutionStats(TimeSpan.FromSeconds(254548), 6, 54545451) + }, + }, + new Dictionary() + { + { new TaskOrTargetTelemetryKey("TargetA", false, true, false), false }, + { new TaskOrTargetTelemetryKey("TargetA", true, true, false), false }, + { new TaskOrTargetTelemetryKey("TargetB", false, false, true), false } + }); + + var holder = TelemetryDataUtils.AsActivityDataHolder(wd); + } } } diff --git a/src/Build/BackEnd/BuildManager/BuildManager.cs b/src/Build/BackEnd/BuildManager/BuildManager.cs index 947c7764de6..30026737b22 100644 --- a/src/Build/BackEnd/BuildManager/BuildManager.cs +++ b/src/Build/BackEnd/BuildManager/BuildManager.cs @@ -257,6 +257,11 @@ public class BuildManager : INodePacketHandler, IBuildComponentHost, IDisposable /// private BuildTelemetry? _buildTelemetry; + /// + /// Logger, that if instantiated - will receive and expose telemetry data from worker nodes. + /// + private InternalTelemetryConsumingLogger? _telemetryConsumingLogger; + private ProjectCacheService? _projectCacheService; private bool _hasProjectCacheServiceInitializedVsScenario; @@ -1134,7 +1139,8 @@ private void EndBuildTelemetry() { OpenTelemetryManager.Instance.DefaultActivitySource? .StartActivity("Build")? - .WithTags(_buildTelemetry!) + .WithTags(_buildTelemetry) + .WithTags(_telemetryConsumingLogger?.WorkerNodeTelemetryData.AsActivityDataHolder()) .WithStartTime(_buildTelemetry!.InnerStartAt) .Dispose(); OpenTelemetryManager.Instance.ForceFlush(); @@ -2986,10 +2992,10 @@ private ILoggingService CreateLoggingService( loggerSwitchParameters: null, verbosity: LoggerVerbosity.Quiet); - ILogger internalTelemetryLogger = + _telemetryConsumingLogger = new InternalTelemetryConsumingLogger(); - ForwardingLoggerRecord[] forwardingLogger = { new ForwardingLoggerRecord(internalTelemetryLogger, forwardingLoggerDescription) }; + ForwardingLoggerRecord[] forwardingLogger = { new ForwardingLoggerRecord(_telemetryConsumingLogger, forwardingLoggerDescription) }; forwardingLoggers = forwardingLoggers?.Concat(forwardingLogger) ?? forwardingLogger; } diff --git a/src/Build/Microsoft.Build.csproj b/src/Build/Microsoft.Build.csproj index eaf8eccce00..6c85f5cb0e4 100644 --- a/src/Build/Microsoft.Build.csproj +++ b/src/Build/Microsoft.Build.csproj @@ -174,6 +174,7 @@ + diff --git a/src/Build/TelemetryInfra/TelemetryDataUtils.cs b/src/Build/TelemetryInfra/TelemetryDataUtils.cs new file mode 100644 index 00000000000..72395d72782 --- /dev/null +++ b/src/Build/TelemetryInfra/TelemetryDataUtils.cs @@ -0,0 +1,138 @@ +// 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.Collections.Generic; +using System.IO; +using System.Linq; +using System.Runtime.InteropServices; +using System.Text.Json; +using System.Text.Json.Serialization; +using System.Threading; +using System.Threading.Tasks; + +namespace Microsoft.Build.Framework.Telemetry +{ + internal static class TelemetryDataUtils + { + public static IActivityTelemetryDataHolder? AsActivityDataHolder(this IWorkerNodeTelemetryData? telemetryData) + { + if (telemetryData == null) + { + return null; + } + + List telemetryItems = new(2); + + telemetryItems.Add(new TelemetryItem("Tasks", + JsonSerializer.Serialize(telemetryData.TasksExecutionData, _serializerOptions), false)); + telemetryItems.Add(new TelemetryItem("Targets", + JsonSerializer.Serialize(telemetryData.TargetsExecutionData, _serializerOptions), false)); + + return new NodeTelemetry(telemetryItems); + } + + private static JsonSerializerOptions _serializerOptions = CreateSerializerOptions(); + + private static JsonSerializerOptions CreateSerializerOptions() + { + var opt = new JsonSerializerOptions + { + WriteIndented = true, + Converters = + { + new TargetDataConverter(), + new TaskDataConverter(), + }, + // TypeInfoResolver = new PrivateConstructorContractResolver() + }; + + return opt; + } + + private class TargetDataConverter : JsonConverter?> + { + public override Dictionary? Read( + ref Utf8JsonReader reader, + Type typeToConvert, + JsonSerializerOptions options) + => + throw new NotImplementedException("Reading is not supported"); + + public override void Write( + Utf8JsonWriter writer, + Dictionary? value, + JsonSerializerOptions options) + { + if (value == null) + { + throw new NotSupportedException("TaskOrTargetTelemetryKey cannot be null in telemetry data"); + } + + // Following needed - as System.Text.Json doesn't support indexing dictionary by composite types + + writer.WriteStartArray(); + + foreach (KeyValuePair valuePair in value) + { + writer.WriteStartObject(valuePair.Key.IsCustom ? ActivityExtensions.GetHashed(valuePair.Key.Name) : valuePair.Key.Name); + writer.WriteBoolean("WasExecuted", valuePair.Value); + writer.WriteBoolean("IsCustom", valuePair.Key.IsCustom); + writer.WriteBoolean("IsFromNuget", valuePair.Key.IsFromNugetCache); + writer.WriteBoolean("IsMetaproj", valuePair.Key.IsFromMetaProject); + writer.WriteEndObject(); + } + + writer.WriteEndArray(); + } + } + + private class TaskDataConverter : JsonConverter?> + { + public override Dictionary? Read( + ref Utf8JsonReader reader, + Type typeToConvert, + JsonSerializerOptions options) + => + throw new NotImplementedException("Reading is not supported"); + + public override void Write( + Utf8JsonWriter writer, + Dictionary? value, + JsonSerializerOptions options) + { + if (value == null) + { + throw new NotSupportedException("TaskOrTargetTelemetryKey cannot be null in telemetry data"); + } + + // Following needed - as System.Text.Json doesn't support indexing dictionary by composite types + + writer.WriteStartArray(); + + foreach (KeyValuePair valuePair in value) + { + writer.WriteStartObject(valuePair.Key.IsCustom ? ActivityExtensions.GetHashed(valuePair.Key.Name) : valuePair.Key.Name); + writer.WriteNumber("ExecTimeMs", valuePair.Value.CumulativeExecutionTime.TotalMilliseconds); + writer.WriteNumber("ExecCnt", valuePair.Value.ExecutionsCount); + writer.WriteNumber("MemKBs", valuePair.Value.TotalMemoryConsumption / 1024.0); + writer.WriteBoolean("IsCustom", valuePair.Key.IsCustom); + writer.WriteBoolean("IsFromNuget", valuePair.Key.IsFromNugetCache); + writer.WriteEndObject(); + } + + writer.WriteEndArray(); + } + } + + private class NodeTelemetry : IActivityTelemetryDataHolder + { + private readonly IList _items; + + public NodeTelemetry(IList items) => _items = items; + + public IList GetActivityProperties() + => _items; + } + } +} diff --git a/src/Framework/Microsoft.Build.Framework.csproj b/src/Framework/Microsoft.Build.Framework.csproj index 95240faa44b..da61a612686 100644 --- a/src/Framework/Microsoft.Build.Framework.csproj +++ b/src/Framework/Microsoft.Build.Framework.csproj @@ -23,7 +23,7 @@ - + diff --git a/src/Framework/Telemetry/ActivityExtensions.cs b/src/Framework/Telemetry/ActivityExtensions.cs index 91648067ae2..aa10b1a6615 100644 --- a/src/Framework/Telemetry/ActivityExtensions.cs +++ b/src/Framework/Telemetry/ActivityExtensions.cs @@ -17,9 +17,12 @@ internal static class ActivityExtensions /// /// Add tags to the activity from a . /// - public static Activity WithTags(this Activity activity, IActivityTelemetryDataHolder dataHolder) + public static Activity WithTags(this Activity activity, IActivityTelemetryDataHolder? dataHolder) { - activity.WithTags(dataHolder.GetActivityProperties()); + if (dataHolder != null) + { + activity.WithTags(dataHolder.GetActivityProperties()); + } return activity; } @@ -59,7 +62,7 @@ public static Activity WithStartTime(this Activity activity, DateTime? startTime /// /// Depending on the platform, hash the value using an available mechanism. /// - private static object GetHashed(object value) + internal static string GetHashed(object value) { return Sha256Hasher.Hash(value.ToString() ?? ""); } diff --git a/src/Framework/Telemetry/InternalTelemetryConsumingLogger.cs b/src/Framework/Telemetry/InternalTelemetryConsumingLogger.cs index 4584112e7ae..67305934852 100644 --- a/src/Framework/Telemetry/InternalTelemetryConsumingLogger.cs +++ b/src/Framework/Telemetry/InternalTelemetryConsumingLogger.cs @@ -23,6 +23,8 @@ public void Initialize(IEventSource eventSource) private readonly WorkerNodeTelemetryData _workerNodeTelemetryData = new(); + public IWorkerNodeTelemetryData WorkerNodeTelemetryData => _workerNodeTelemetryData; + private void EventSource5_WorkerNodeTelemetryLogged(object? sender, WorkerNodeTelemetryEventArgs e) { _workerNodeTelemetryData.Add(e.WorkerNodeTelemetryData); diff --git a/src/Framework/Telemetry/TaskExecutionStats.cs b/src/Framework/Telemetry/TaskExecutionStats.cs index 4442d9d27ca..f1da55e59a4 100644 --- a/src/Framework/Telemetry/TaskExecutionStats.cs +++ b/src/Framework/Telemetry/TaskExecutionStats.cs @@ -7,8 +7,19 @@ namespace Microsoft.Build.Framework; internal class TaskExecutionStats(TimeSpan cumulativeExecutionTime, short executionsCount, long totalMemoryConsumption) { + /// + /// Total execution time of the task in all nodes for all projects. + /// public TimeSpan CumulativeExecutionTime { get; set; } = cumulativeExecutionTime; + + /// + /// Total memory consumption (across all executions) in bytes. + /// public long TotalMemoryConsumption { get; set; } = totalMemoryConsumption; + + /// + /// Total number of execution of the tasks in all nodes for all projects. + /// public short ExecutionsCount { get; set; } = executionsCount; // We need custom Equals for easier assertations in tests From e852270d8bd946bb188d204a2167abf03a27d514 Mon Sep 17 00:00:00 2001 From: Jan Krivanek Date: Mon, 24 Feb 2025 15:33:39 +0100 Subject: [PATCH 02/10] Add node telemetry data summarization --- src/Build.UnitTests/TelemetryTests.cs | 6 +- .../BackEnd/BuildManager/BuildManager.cs | 6 +- src/Build/Microsoft.Build.csproj | 1 + .../InternalTelemetryConsumingLogger.cs | 24 +- .../TelemetryInfra/TelemetryDataUtils.cs | 205 +++++++++++++++++- .../InternalTelemetryForwardingLogger.cs | 2 +- src/Framework/Telemetry/TaskExecutionStats.cs | 18 +- .../Telemetry/WorkerNodeTelemetryData.cs | 2 +- src/Framework/Traits.cs | 2 +- 9 files changed, 246 insertions(+), 20 deletions(-) rename src/{Framework/Telemetry => Build/TelemetryInfra}/InternalTelemetryConsumingLogger.cs (80%) diff --git a/src/Build.UnitTests/TelemetryTests.cs b/src/Build.UnitTests/TelemetryTests.cs index 8db9561a59a..d04353d7321 100644 --- a/src/Build.UnitTests/TelemetryTests.cs +++ b/src/Build.UnitTests/TelemetryTests.cs @@ -4,9 +4,11 @@ using System; using System.Collections.Generic; using System.Linq; +using System.Text.Json; using Microsoft.Build.Execution; using Microsoft.Build.Framework; using Microsoft.Build.Framework.Telemetry; +using Microsoft.Build.TelemetryInfra; using Microsoft.Build.UnitTests; using Shouldly; using Xunit; @@ -175,7 +177,7 @@ public void Foo() { { new TaskOrTargetTelemetryKey("TaskA", false, true), - new TaskExecutionStats(TimeSpan.FromSeconds(2), 5, 545) + new TaskExecutionStats(TimeSpan.FromSeconds(2.1554548), 5, 545) }, { new TaskOrTargetTelemetryKey("TaskA", true, false), @@ -189,7 +191,7 @@ public void Foo() { new TaskOrTargetTelemetryKey("TargetB", false, false, true), false } }); - var holder = TelemetryDataUtils.AsActivityDataHolder(wd); + var holder = TelemetryDataUtils.AsActivityDataHolder(wd, true, true); } } } diff --git a/src/Build/BackEnd/BuildManager/BuildManager.cs b/src/Build/BackEnd/BuildManager/BuildManager.cs index 30026737b22..cd21e2f26a8 100644 --- a/src/Build/BackEnd/BuildManager/BuildManager.cs +++ b/src/Build/BackEnd/BuildManager/BuildManager.cs @@ -36,6 +36,7 @@ using Microsoft.Build.Logging; using Microsoft.Build.Shared; using Microsoft.Build.Shared.Debugging; +using Microsoft.Build.TelemetryInfra; using Microsoft.NET.StringTools; using ExceptionHandling = Microsoft.Build.Shared.ExceptionHandling; using ForwardingLoggerRecord = Microsoft.Build.Logging.ForwardingLoggerRecord; @@ -568,6 +569,7 @@ public void BeginBuild(BuildParameters parameters) // Initialize components. _nodeManager = ((IBuildComponentHost)this).GetComponent(BuildComponentType.NodeManager) as INodeManager; + _buildParameters.IsTelemetryEnabled = OpenTelemetryManager.Instance.IsActive(); var loggingService = InitializeLoggingService(); // Log deferred messages and response files @@ -1140,7 +1142,9 @@ private void EndBuildTelemetry() OpenTelemetryManager.Instance.DefaultActivitySource? .StartActivity("Build")? .WithTags(_buildTelemetry) - .WithTags(_telemetryConsumingLogger?.WorkerNodeTelemetryData.AsActivityDataHolder()) + .WithTags(_telemetryConsumingLogger?.WorkerNodeTelemetryData.AsActivityDataHolder( + !Traits.IsEnvVarOneOrTrue("MSBUILDTELEMETRYEXCLUDETASKSDETAILS"), + !Traits.IsEnvVarOneOrTrue("MSBUILDTELEMETRYEXCLUDETARGETSDETAILS"))) .WithStartTime(_buildTelemetry!.InnerStartAt) .Dispose(); OpenTelemetryManager.Instance.ForceFlush(); diff --git a/src/Build/Microsoft.Build.csproj b/src/Build/Microsoft.Build.csproj index 6c85f5cb0e4..78183ad0551 100644 --- a/src/Build/Microsoft.Build.csproj +++ b/src/Build/Microsoft.Build.csproj @@ -173,6 +173,7 @@ + diff --git a/src/Framework/Telemetry/InternalTelemetryConsumingLogger.cs b/src/Build/TelemetryInfra/InternalTelemetryConsumingLogger.cs similarity index 80% rename from src/Framework/Telemetry/InternalTelemetryConsumingLogger.cs rename to src/Build/TelemetryInfra/InternalTelemetryConsumingLogger.cs index 67305934852..dd0bb9490ec 100644 --- a/src/Framework/Telemetry/InternalTelemetryConsumingLogger.cs +++ b/src/Build/TelemetryInfra/InternalTelemetryConsumingLogger.cs @@ -3,8 +3,12 @@ using System; using System.Linq; +using System.Text.Json; +using Microsoft.Build.Framework; +using Microsoft.Build.Framework.Telemetry; +using System.IO; -namespace Microsoft.Build.Framework; +namespace Microsoft.Build.TelemetryInfra; internal sealed class InternalTelemetryConsumingLogger : ILogger { @@ -34,11 +38,12 @@ private void EventSourceOnBuildFinished(object sender, BuildFinishedEventArgs e) { TestOnly_InternalTelemetryAggregted?.Invoke(_workerNodeTelemetryData); FlushDataIntoConsoleIfRequested(); + FlushDataIntoJsonFileIfRequested(); } private void FlushDataIntoConsoleIfRequested() { - if (Environment.GetEnvironmentVariable("MSBUILDOUTPUTNODESTELEMETRY") != "1") + if (!Traits.IsEnvVarOneOrTrue("MSBUILDOUTPUTNODESTELEMETRY")) { return; } @@ -77,6 +82,21 @@ private void FlushDataIntoConsoleIfRequested() Console.WriteLine("=========================================="); } + private void FlushDataIntoJsonFileIfRequested() + { + const string jsonFileNameVariable = "MSBUILDNODETELEMETRYFILENAME"; + if (!Traits.IsEnvVarOneOrTrue(jsonFileNameVariable)) + { + return; + } + + var telemetryTags = _workerNodeTelemetryData.AsActivityDataHolder(true, true)?.GetActivityProperties(); + + using var stream = File.OpenWrite(jsonFileNameVariable); + stream.SetLength(0); + JsonSerializer.Serialize(stream, telemetryTags, new JsonSerializerOptions() { WriteIndented = true }); + } + public void Shutdown() { } } diff --git a/src/Build/TelemetryInfra/TelemetryDataUtils.cs b/src/Build/TelemetryInfra/TelemetryDataUtils.cs index 72395d72782..73f2f665fab 100644 --- a/src/Build/TelemetryInfra/TelemetryDataUtils.cs +++ b/src/Build/TelemetryInfra/TelemetryDataUtils.cs @@ -10,24 +10,42 @@ using System.Text.Json.Serialization; using System.Threading; using System.Threading.Tasks; +using System.Xml; namespace Microsoft.Build.Framework.Telemetry { internal static class TelemetryDataUtils { - public static IActivityTelemetryDataHolder? AsActivityDataHolder(this IWorkerNodeTelemetryData? telemetryData) + public static IActivityTelemetryDataHolder? AsActivityDataHolder(this IWorkerNodeTelemetryData? telemetryData, bool includeTasksDetails, bool includeTargetDetails) { if (telemetryData == null) { return null; } - List telemetryItems = new(2); + List telemetryItems = new(4); - telemetryItems.Add(new TelemetryItem("Tasks", - JsonSerializer.Serialize(telemetryData.TasksExecutionData, _serializerOptions), false)); - telemetryItems.Add(new TelemetryItem("Targets", - JsonSerializer.Serialize(telemetryData.TargetsExecutionData, _serializerOptions), false)); + if (includeTasksDetails) + { + telemetryItems.Add(new TelemetryItem("Tasks", + JsonSerializer.Serialize(telemetryData.TasksExecutionData, _serializerOptions), false)); + } + + if (includeTargetDetails) + { + telemetryItems.Add(new TelemetryItem("Targets", + JsonSerializer.Serialize(telemetryData.TargetsExecutionData, _serializerOptions), false)); + } + + TargetsSummary targetsSummary = new(); + targetsSummary.Initialize(telemetryData.TargetsExecutionData); + telemetryItems.Add(new TelemetryItem("TargetsSummary", + JsonSerializer.Serialize(targetsSummary, _serializerOptions), false)); + + TasksSummary tasksSummary = new(); + tasksSummary.Initialize(telemetryData.TasksExecutionData); + telemetryItems.Add(new TelemetryItem("TasksSummary", + JsonSerializer.Serialize(tasksSummary, _serializerOptions), false)); return new NodeTelemetry(telemetryItems); } @@ -43,8 +61,9 @@ private static JsonSerializerOptions CreateSerializerOptions() { new TargetDataConverter(), new TaskDataConverter(), + new TargetsSummary(), + new TasksSummary(), }, - // TypeInfoResolver = new PrivateConstructorContractResolver() }; return opt; @@ -75,7 +94,7 @@ public override void Write( foreach (KeyValuePair valuePair in value) { - writer.WriteStartObject(valuePair.Key.IsCustom ? ActivityExtensions.GetHashed(valuePair.Key.Name) : valuePair.Key.Name); + writer.WriteStartObject(valuePair.Key.IsCustom || valuePair.Key.IsFromMetaProject ? ActivityExtensions.GetHashed(valuePair.Key.Name) : valuePair.Key.Name); writer.WriteBoolean("WasExecuted", valuePair.Value); writer.WriteBoolean("IsCustom", valuePair.Key.IsCustom); writer.WriteBoolean("IsFromNuget", valuePair.Key.IsFromNugetCache); @@ -113,9 +132,11 @@ public override void Write( foreach (KeyValuePair valuePair in value) { writer.WriteStartObject(valuePair.Key.IsCustom ? ActivityExtensions.GetHashed(valuePair.Key.Name) : valuePair.Key.Name); - writer.WriteNumber("ExecTimeMs", valuePair.Value.CumulativeExecutionTime.TotalMilliseconds); + // We do not want decimals + writer.WriteNumber("ExecTimeMs", valuePair.Value.CumulativeExecutionTime.TotalMilliseconds / 1); writer.WriteNumber("ExecCnt", valuePair.Value.ExecutionsCount); - writer.WriteNumber("MemKBs", valuePair.Value.TotalMemoryConsumption / 1024.0); + // We do not want decimals + writer.WriteNumber("MemKBs", valuePair.Value.TotalMemoryConsumption / 1024); writer.WriteBoolean("IsCustom", valuePair.Key.IsCustom); writer.WriteBoolean("IsFromNuget", valuePair.Key.IsFromNugetCache); writer.WriteEndObject(); @@ -125,6 +146,170 @@ public override void Write( } } + private class TargetsSummary : JsonConverter + { + public void Initialize(Dictionary targetsExecutionData) + { + foreach (var targetInfo in targetsExecutionData) + { + UpdateStatistics(LoadedBuiltinTargetInfo, LoadedCustomTargetInfo, targetInfo.Key); + if (targetInfo.Value) + { + UpdateStatistics(ExecutedBuiltinTargetInfo, ExecutedCustomTargetInfo, targetInfo.Key); + } + } + + void UpdateStatistics( + TargetInfo builtinTargetInfo, + TargetInfo customTargetInfo, + TaskOrTargetTelemetryKey key) + { + UpdateSingleStatistics(key.IsCustom ? customTargetInfo : builtinTargetInfo, key); + + void UpdateSingleStatistics(TargetInfo targetInfo, TaskOrTargetTelemetryKey kkey) + { + targetInfo.Total++; + if (kkey.IsFromNugetCache) + { + targetInfo.FromNuget++; + } + if (kkey.IsFromMetaProject) + { + targetInfo.FromMetaproj++; + } + } + } + } + + private TargetInfo LoadedBuiltinTargetInfo { get; } = new(); + private TargetInfo LoadedCustomTargetInfo { get; } = new(); + private TargetInfo ExecutedBuiltinTargetInfo { get; } = new(); + private TargetInfo ExecutedCustomTargetInfo { get; } = new(); + + private class TargetInfo + { + public int Total { get; internal set; } + public int FromNuget { get; internal set; } + public int FromMetaproj { get; internal set; } + } + + public override TargetsSummary? Read( + ref Utf8JsonReader reader, + Type typeToConvert, + JsonSerializerOptions options) => + throw new NotImplementedException("Reading is not supported"); + + public override void Write( + Utf8JsonWriter writer, + TargetsSummary value, + JsonSerializerOptions options) + { + writer.WriteStartObject("Loaded"); + WriteStat(writer, value.LoadedBuiltinTargetInfo, value.LoadedCustomTargetInfo); + writer.WriteEndObject(); + writer.WriteStartObject("Executed"); + WriteStat(writer, value.ExecutedBuiltinTargetInfo, value.ExecutedCustomTargetInfo); + writer.WriteEndObject(); + + + void WriteStat(Utf8JsonWriter writer, TargetInfo customTargetsInfo, TargetInfo builtinTargetsInfo) + { + writer.WriteNumber("Total", builtinTargetsInfo.Total + customTargetsInfo.Total); + WriteSingleStat(writer, builtinTargetsInfo, "Microsoft"); + WriteSingleStat(writer, customTargetsInfo, "Custom"); + } + + void WriteSingleStat(Utf8JsonWriter writer, TargetInfo targetInfo, string name) + { + if (targetInfo.Total > 0) + { + writer.WriteStartObject(name); + writer.WriteNumber("Total", targetInfo.Total); + writer.WriteNumber("FromNuget", targetInfo.FromNuget); + writer.WriteNumber("FromMetaproj", targetInfo.FromMetaproj); + writer.WriteEndObject(); + } + } + } + } + + + private class TasksSummary : JsonConverter + { + public void Initialize(Dictionary tasksExecutionData) + { + foreach (var taskInfo in tasksExecutionData) + { + + UpdateStatistics(BuiltinTasksInfo, CustomTasksInfo, taskInfo.Key, taskInfo.Value); + } + + void UpdateStatistics( + TasksInfo builtinTaskInfo, + TasksInfo customTaskInfo, + TaskOrTargetTelemetryKey key, + TaskExecutionStats taskExecutionStats) + { + UpdateSingleStatistics(key.IsCustom ? customTaskInfo : builtinTaskInfo, taskExecutionStats, key); + + void UpdateSingleStatistics(TasksInfo summarizedTaskInfo, TaskExecutionStats infoToAdd, TaskOrTargetTelemetryKey kkey) + { + summarizedTaskInfo.Total.AddAnother(infoToAdd); + if (kkey.IsFromNugetCache) + { + summarizedTaskInfo.FromNuget.AddAnother(infoToAdd); + } + } + } + } + + private TasksInfo BuiltinTasksInfo { get; } = new TasksInfo(); + private TasksInfo CustomTasksInfo { get; } = new TasksInfo(); + + private class TasksInfo + { + public TaskExecutionStats Total { get; } = TaskExecutionStats.CreateEmpty(); + public TaskExecutionStats FromNuget { get; } = TaskExecutionStats.CreateEmpty(); + } + + public override TasksSummary? Read( + ref Utf8JsonReader reader, + Type typeToConvert, + JsonSerializerOptions options) => + throw new NotImplementedException("Reading is not supported"); + + public override void Write( + Utf8JsonWriter writer, + TasksSummary value, + JsonSerializerOptions options) + { + WriteStat(writer, value.BuiltinTasksInfo, "Microsoft"); + WriteStat(writer, value.CustomTasksInfo, "Custom"); + + void WriteStat(Utf8JsonWriter writer, TasksInfo tasksInfo, string name) + { + writer.WriteStartObject(name); + WriteSingleStat(writer, tasksInfo.Total, "Total", true); + WriteSingleStat(writer, tasksInfo.FromNuget, "FromNuget", false); + writer.WriteEndObject(); + } + + void WriteSingleStat(Utf8JsonWriter writer, TaskExecutionStats stats, string name, bool writeIfEmpty) + { + if (stats.ExecutionsCount > 0) + { + writer.WriteStartObject(name); + writer.WriteNumber("TotalExecutionsCount", stats.ExecutionsCount); + // We do not want decimals + writer.WriteNumber("CumulativeExecutionTimeMs", stats.CumulativeExecutionTime.TotalMilliseconds / 1); + // We do not want decimals + writer.WriteNumber("CumulativeConsumedMemoryKB", stats.TotalMemoryConsumption / 1024); + writer.WriteEndObject(); + } + } + } + } + private class NodeTelemetry : IActivityTelemetryDataHolder { private readonly IList _items; diff --git a/src/Framework/Telemetry/InternalTelemetryForwardingLogger.cs b/src/Framework/Telemetry/InternalTelemetryForwardingLogger.cs index a47e0d75453..95e38567587 100644 --- a/src/Framework/Telemetry/InternalTelemetryForwardingLogger.cs +++ b/src/Framework/Telemetry/InternalTelemetryForwardingLogger.cs @@ -4,7 +4,7 @@ namespace Microsoft.Build.Framework; /// -/// Ensure that events filtering is in sync with . +/// Ensure that events filtering is in sync with InternalTelemetryConsumingLogger. /// internal class InternalTelemeteryForwardingLogger : IForwardingLogger { diff --git a/src/Framework/Telemetry/TaskExecutionStats.cs b/src/Framework/Telemetry/TaskExecutionStats.cs index f1da55e59a4..b3f1564d615 100644 --- a/src/Framework/Telemetry/TaskExecutionStats.cs +++ b/src/Framework/Telemetry/TaskExecutionStats.cs @@ -5,8 +5,15 @@ namespace Microsoft.Build.Framework; -internal class TaskExecutionStats(TimeSpan cumulativeExecutionTime, short executionsCount, long totalMemoryConsumption) +internal class TaskExecutionStats(TimeSpan cumulativeExecutionTime, int executionsCount, long totalMemoryConsumption) { + private TaskExecutionStats() + : this(TimeSpan.Zero, 0, 0) + { } + + internal static TaskExecutionStats CreateEmpty() + => new(); + /// /// Total execution time of the task in all nodes for all projects. /// @@ -20,7 +27,14 @@ internal class TaskExecutionStats(TimeSpan cumulativeExecutionTime, short execut /// /// Total number of execution of the tasks in all nodes for all projects. /// - public short ExecutionsCount { get; set; } = executionsCount; + public int ExecutionsCount { get; set; } = executionsCount; + + internal void AddAnother(TaskExecutionStats another) + { + this.CumulativeExecutionTime += another.CumulativeExecutionTime; + this.TotalMemoryConsumption += another.TotalMemoryConsumption; + this.ExecutionsCount += another.ExecutionsCount; + } // We need custom Equals for easier assertations in tests public override bool Equals(object? obj) diff --git a/src/Framework/Telemetry/WorkerNodeTelemetryData.cs b/src/Framework/Telemetry/WorkerNodeTelemetryData.cs index 7bafb3a13e6..4b5afad229f 100644 --- a/src/Framework/Telemetry/WorkerNodeTelemetryData.cs +++ b/src/Framework/Telemetry/WorkerNodeTelemetryData.cs @@ -27,7 +27,7 @@ public void Add(IWorkerNodeTelemetryData other) } } - public void AddTask(TaskOrTargetTelemetryKey task, TimeSpan cumulativeExectionTime, short executionsCount, long totalMemoryConsumption) + public void AddTask(TaskOrTargetTelemetryKey task, TimeSpan cumulativeExectionTime, int executionsCount, long totalMemoryConsumption) { TaskExecutionStats? taskExecutionStats; if (!TasksExecutionData.TryGetValue(task, out taskExecutionStats)) diff --git a/src/Framework/Traits.cs b/src/Framework/Traits.cs index 4dd997eefed..2b4dceb2d67 100644 --- a/src/Framework/Traits.cs +++ b/src/Framework/Traits.cs @@ -168,7 +168,7 @@ private static int ParseIntFromEnvironmentVariableOrDefault(string environmentVa : null; } - private static bool IsEnvVarOneOrTrue(string name) + internal static bool IsEnvVarOneOrTrue(string name) { string? value = Environment.GetEnvironmentVariable(name); return value != null && From c74c63f25065f4c9efa10f3232661490ecd94e23 Mon Sep 17 00:00:00 2001 From: Jan Provaznik Date: Mon, 24 Feb 2025 17:38:47 +0100 Subject: [PATCH 03/10] fix flushing node data to json --- src/Build/TelemetryInfra/InternalTelemetryConsumingLogger.cs | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/src/Build/TelemetryInfra/InternalTelemetryConsumingLogger.cs b/src/Build/TelemetryInfra/InternalTelemetryConsumingLogger.cs index dd0bb9490ec..24cd5b9ed0e 100644 --- a/src/Build/TelemetryInfra/InternalTelemetryConsumingLogger.cs +++ b/src/Build/TelemetryInfra/InternalTelemetryConsumingLogger.cs @@ -85,14 +85,15 @@ private void FlushDataIntoConsoleIfRequested() private void FlushDataIntoJsonFileIfRequested() { const string jsonFileNameVariable = "MSBUILDNODETELEMETRYFILENAME"; - if (!Traits.IsEnvVarOneOrTrue(jsonFileNameVariable)) + var jsonFilePath = Environment.GetEnvironmentVariable(jsonFileNameVariable); + if (string.IsNullOrEmpty(jsonFilePath)) { return; } var telemetryTags = _workerNodeTelemetryData.AsActivityDataHolder(true, true)?.GetActivityProperties(); - using var stream = File.OpenWrite(jsonFileNameVariable); + using var stream = File.OpenWrite(jsonFilePath); stream.SetLength(0); JsonSerializer.Serialize(stream, telemetryTags, new JsonSerializerOptions() { WriteIndented = true }); } From 4fb8a4a29ade93cc3e35175f0c5deaa5c06ff3cf Mon Sep 17 00:00:00 2001 From: Jan Provaznik Date: Mon, 24 Feb 2025 17:48:16 +0100 Subject: [PATCH 04/10] Refactor telemetry task details exclusion logic in BuildManager and Traits --- src/Build/BackEnd/BuildManager/BuildManager.cs | 5 +++-- src/Framework/Traits.cs | 3 ++- 2 files changed, 5 insertions(+), 3 deletions(-) diff --git a/src/Build/BackEnd/BuildManager/BuildManager.cs b/src/Build/BackEnd/BuildManager/BuildManager.cs index cd21e2f26a8..25bb791ceb7 100644 --- a/src/Build/BackEnd/BuildManager/BuildManager.cs +++ b/src/Build/BackEnd/BuildManager/BuildManager.cs @@ -1143,8 +1143,9 @@ private void EndBuildTelemetry() .StartActivity("Build")? .WithTags(_buildTelemetry) .WithTags(_telemetryConsumingLogger?.WorkerNodeTelemetryData.AsActivityDataHolder( - !Traits.IsEnvVarOneOrTrue("MSBUILDTELEMETRYEXCLUDETASKSDETAILS"), - !Traits.IsEnvVarOneOrTrue("MSBUILDTELEMETRYEXCLUDETARGETSDETAILS"))) + includeTasksDetails: !Traits.ExcludeTasksDetailsFromTelemetry + includeTargetDetails: false + )) .WithStartTime(_buildTelemetry!.InnerStartAt) .Dispose(); OpenTelemetryManager.Instance.ForceFlush(); diff --git a/src/Framework/Traits.cs b/src/Framework/Traits.cs index 2b4dceb2d67..e79515c2365 100644 --- a/src/Framework/Traits.cs +++ b/src/Framework/Traits.cs @@ -141,7 +141,8 @@ public Traits() public bool SdkTelemetryOptOut = IsEnvVarOneOrTrue("DOTNET_CLI_TELEMETRY_OPTOUT"); public bool FrameworkTelemetryOptOut = IsEnvVarOneOrTrue("MSBUILD_TELEMETRY_OPTOUT"); public double? TelemetrySampleRateOverride = ParseDoubleFromEnvironmentVariable("MSBUILD_TELEMETRY_SAMPLE_RATE"); - + public bool ExcludeTasksDetailsFromTelemetry = IsEnvVarOneOrTrue("MSBUILDTELEMETRYEXCLUDETASKSDETAILS"); + // for VS17.14 public readonly bool TelemetryOptIn = Environment.GetEnvironmentVariable("MSBUILD_TELEMETRY_OPTIN") == "1"; From ed558963d606231bc2944e25c678e037c1af9e0d Mon Sep 17 00:00:00 2001 From: Jan Provaznik Date: Mon, 24 Feb 2025 18:02:16 +0100 Subject: [PATCH 05/10] syntax --- src/Build/BackEnd/BuildManager/BuildManager.cs | 2 +- src/Framework/Traits.cs | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/src/Build/BackEnd/BuildManager/BuildManager.cs b/src/Build/BackEnd/BuildManager/BuildManager.cs index 25bb791ceb7..4f0e2978c4b 100644 --- a/src/Build/BackEnd/BuildManager/BuildManager.cs +++ b/src/Build/BackEnd/BuildManager/BuildManager.cs @@ -1143,7 +1143,7 @@ private void EndBuildTelemetry() .StartActivity("Build")? .WithTags(_buildTelemetry) .WithTags(_telemetryConsumingLogger?.WorkerNodeTelemetryData.AsActivityDataHolder( - includeTasksDetails: !Traits.ExcludeTasksDetailsFromTelemetry + includeTasksDetails: !Traits.ExcludeTasksDetailsFromTelemetry, includeTargetDetails: false )) .WithStartTime(_buildTelemetry!.InnerStartAt) diff --git a/src/Framework/Traits.cs b/src/Framework/Traits.cs index e79515c2365..8fe957a315f 100644 --- a/src/Framework/Traits.cs +++ b/src/Framework/Traits.cs @@ -144,7 +144,7 @@ public Traits() public bool ExcludeTasksDetailsFromTelemetry = IsEnvVarOneOrTrue("MSBUILDTELEMETRYEXCLUDETASKSDETAILS"); // for VS17.14 - public readonly bool TelemetryOptIn = Environment.GetEnvironmentVariable("MSBUILD_TELEMETRY_OPTIN") == "1"; + public readonly bool TelemetryOptIn = IsEnvVarOneOrTrue("MSBUILD_TELEMETRY_OPTIN"); public static void UpdateFromEnvironment() { From 2c91c4e9d8211d57be782d78166b39b9f4102832 Mon Sep 17 00:00:00 2001 From: Jan Provaznik Date: Tue, 25 Feb 2025 13:37:10 +0100 Subject: [PATCH 06/10] fix --- src/Build/BackEnd/BuildManager/BuildManager.cs | 5 ++--- src/Build/TelemetryInfra/TelemetryDataUtils.cs | 8 -------- 2 files changed, 2 insertions(+), 11 deletions(-) diff --git a/src/Build/BackEnd/BuildManager/BuildManager.cs b/src/Build/BackEnd/BuildManager/BuildManager.cs index 4f0e2978c4b..9cbdbd6d8d6 100644 --- a/src/Build/BackEnd/BuildManager/BuildManager.cs +++ b/src/Build/BackEnd/BuildManager/BuildManager.cs @@ -1143,9 +1143,8 @@ private void EndBuildTelemetry() .StartActivity("Build")? .WithTags(_buildTelemetry) .WithTags(_telemetryConsumingLogger?.WorkerNodeTelemetryData.AsActivityDataHolder( - includeTasksDetails: !Traits.ExcludeTasksDetailsFromTelemetry, - includeTargetDetails: false - )) + includeTasksDetails: !Traits.Instance.ExcludeTasksDetailsFromTelemetry, + includeTargetDetails: false)) .WithStartTime(_buildTelemetry!.InnerStartAt) .Dispose(); OpenTelemetryManager.Instance.ForceFlush(); diff --git a/src/Build/TelemetryInfra/TelemetryDataUtils.cs b/src/Build/TelemetryInfra/TelemetryDataUtils.cs index 73f2f665fab..e22ba147df6 100644 --- a/src/Build/TelemetryInfra/TelemetryDataUtils.cs +++ b/src/Build/TelemetryInfra/TelemetryDataUtils.cs @@ -3,15 +3,8 @@ using System; using System.Collections.Generic; -using System.IO; -using System.Linq; -using System.Runtime.InteropServices; using System.Text.Json; using System.Text.Json.Serialization; -using System.Threading; -using System.Threading.Tasks; -using System.Xml; - namespace Microsoft.Build.Framework.Telemetry { internal static class TelemetryDataUtils @@ -240,7 +233,6 @@ public void Initialize(Dictionary { foreach (var taskInfo in tasksExecutionData) { - UpdateStatistics(BuiltinTasksInfo, CustomTasksInfo, taskInfo.Key, taskInfo.Value); } From ed45e8ae564e6dab56fa462265f1a67007c0e890 Mon Sep 17 00:00:00 2001 From: Jan Provaznik Date: Tue, 25 Feb 2025 18:17:36 +0100 Subject: [PATCH 07/10] fix schema for summaries --- src/Build/TelemetryInfra/TelemetryDataUtils.cs | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/src/Build/TelemetryInfra/TelemetryDataUtils.cs b/src/Build/TelemetryInfra/TelemetryDataUtils.cs index e22ba147df6..c33d1fce17d 100644 --- a/src/Build/TelemetryInfra/TelemetryDataUtils.cs +++ b/src/Build/TelemetryInfra/TelemetryDataUtils.cs @@ -275,8 +275,10 @@ public override void Write( TasksSummary value, JsonSerializerOptions options) { + writer.WriteStartObject(); WriteStat(writer, value.BuiltinTasksInfo, "Microsoft"); WriteStat(writer, value.CustomTasksInfo, "Custom"); + writer.WriteEndObject(); void WriteStat(Utf8JsonWriter writer, TasksInfo tasksInfo, string name) { @@ -293,7 +295,7 @@ void WriteSingleStat(Utf8JsonWriter writer, TaskExecutionStats stats, string nam writer.WriteStartObject(name); writer.WriteNumber("TotalExecutionsCount", stats.ExecutionsCount); // We do not want decimals - writer.WriteNumber("CumulativeExecutionTimeMs", stats.CumulativeExecutionTime.TotalMilliseconds / 1); + writer.WriteNumber("CumulativeExecutionTimeMs", (long)stats.CumulativeExecutionTime.TotalMilliseconds); // We do not want decimals writer.WriteNumber("CumulativeConsumedMemoryKB", stats.TotalMemoryConsumption / 1024); writer.WriteEndObject(); From c3cea1944275a1e35833c4e60224c5214de6bb5c Mon Sep 17 00:00:00 2001 From: Jan Provaznik Date: Tue, 25 Feb 2025 18:44:38 +0100 Subject: [PATCH 08/10] more wrapping objects --- src/Build/TelemetryInfra/TelemetryDataUtils.cs | 2 ++ 1 file changed, 2 insertions(+) diff --git a/src/Build/TelemetryInfra/TelemetryDataUtils.cs b/src/Build/TelemetryInfra/TelemetryDataUtils.cs index c33d1fce17d..07e5f2968e2 100644 --- a/src/Build/TelemetryInfra/TelemetryDataUtils.cs +++ b/src/Build/TelemetryInfra/TelemetryDataUtils.cs @@ -197,12 +197,14 @@ public override void Write( TargetsSummary value, JsonSerializerOptions options) { + writer.WriteStartObject(); writer.WriteStartObject("Loaded"); WriteStat(writer, value.LoadedBuiltinTargetInfo, value.LoadedCustomTargetInfo); writer.WriteEndObject(); writer.WriteStartObject("Executed"); WriteStat(writer, value.ExecutedBuiltinTargetInfo, value.ExecutedCustomTargetInfo); writer.WriteEndObject(); + writer.WriteEndObject(); void WriteStat(Utf8JsonWriter writer, TargetInfo customTargetsInfo, TargetInfo builtinTargetsInfo) From 51aaf20b890476bef3a2426555ac3ffde68efa75 Mon Sep 17 00:00:00 2001 From: Jan Krivanek Date: Wed, 26 Feb 2025 12:47:28 +0100 Subject: [PATCH 09/10] Fix failing tests --- src/Build/BackEnd/BuildManager/BuildManager.cs | 2 +- src/Framework/Telemetry/WorkerNodeTelemetryEventArgs.cs | 5 ++++- 2 files changed, 5 insertions(+), 2 deletions(-) diff --git a/src/Build/BackEnd/BuildManager/BuildManager.cs b/src/Build/BackEnd/BuildManager/BuildManager.cs index 9cbdbd6d8d6..4dbf79918ac 100644 --- a/src/Build/BackEnd/BuildManager/BuildManager.cs +++ b/src/Build/BackEnd/BuildManager/BuildManager.cs @@ -569,7 +569,7 @@ public void BeginBuild(BuildParameters parameters) // Initialize components. _nodeManager = ((IBuildComponentHost)this).GetComponent(BuildComponentType.NodeManager) as INodeManager; - _buildParameters.IsTelemetryEnabled = OpenTelemetryManager.Instance.IsActive(); + _buildParameters.IsTelemetryEnabled |= OpenTelemetryManager.Instance.IsActive(); var loggingService = InitializeLoggingService(); // Log deferred messages and response files diff --git a/src/Framework/Telemetry/WorkerNodeTelemetryEventArgs.cs b/src/Framework/Telemetry/WorkerNodeTelemetryEventArgs.cs index d0206cf1892..a416f4245ad 100644 --- a/src/Framework/Telemetry/WorkerNodeTelemetryEventArgs.cs +++ b/src/Framework/Telemetry/WorkerNodeTelemetryEventArgs.cs @@ -42,7 +42,10 @@ internal override void CreateFromStream(BinaryReader reader, int version) for (int i = 0; i < count; i++) { tasksExecutionData.Add(ReadFromStream(reader), - new TaskExecutionStats(TimeSpan.FromTicks(reader.ReadInt64()), reader.ReadInt16(), reader.ReadInt64())); + new TaskExecutionStats( + TimeSpan.FromTicks(reader.ReadInt64()), + reader.ReadInt32(), + reader.ReadInt64())); } count = reader.Read7BitEncodedInt(); From aa2d584808bf9ae6ee75e52dce48b8839c872570 Mon Sep 17 00:00:00 2001 From: Jan Krivanek Date: Wed, 26 Feb 2025 12:49:15 +0100 Subject: [PATCH 10/10] Remove indentation --- src/Build/TelemetryInfra/TelemetryDataUtils.cs | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/src/Build/TelemetryInfra/TelemetryDataUtils.cs b/src/Build/TelemetryInfra/TelemetryDataUtils.cs index 07e5f2968e2..ed91dcdbaa9 100644 --- a/src/Build/TelemetryInfra/TelemetryDataUtils.cs +++ b/src/Build/TelemetryInfra/TelemetryDataUtils.cs @@ -49,7 +49,8 @@ private static JsonSerializerOptions CreateSerializerOptions() { var opt = new JsonSerializerOptions { - WriteIndented = true, + // Add following if user-friendly indentation would be needed + // WriteIndented = true, Converters = { new TargetDataConverter(),