From 2ddda1936444f72df7f803ba58f6825fdce49cfa Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jan=20Provazn=C3=ADk?= Date: Tue, 4 Mar 2025 16:19:39 +0100 Subject: [PATCH 01/10] typo, namespaces, remove flushing intermediate data, rename --- .../BackEnd/BuildManager/BuildManager.cs | 4 ++-- .../Components/Logging/EventSourceSink.cs | 1 + .../InternalTelemetryConsumingLogger.cs | 21 ++----------------- .../TelemetryInfra/TelemetryDataUtils.cs | 9 ++++---- .../TelemetryForwarderProvider.cs | 1 + src/Framework/IEventSource5.cs | 1 + .../Telemetry/IWorkerNodeTelemetryData.cs | 2 +- .../InternalTelemetryForwardingLogger.cs | 4 ++-- src/Framework/Telemetry/TaskExecutionStats.cs | 18 ++++++++++++---- .../Telemetry/WorkerNodeTelemetryData.cs | 2 +- .../Telemetry/WorkerNodeTelemetryEventArgs.cs | 2 +- src/Framework/Traits.cs | 1 + src/Shared/LogMessagePacketBase.cs | 1 + 13 files changed, 33 insertions(+), 34 deletions(-) diff --git a/src/Build/BackEnd/BuildManager/BuildManager.cs b/src/Build/BackEnd/BuildManager/BuildManager.cs index 4dbf79918ac..bafe972c446 100644 --- a/src/Build/BackEnd/BuildManager/BuildManager.cs +++ b/src/Build/BackEnd/BuildManager/BuildManager.cs @@ -2990,8 +2990,8 @@ private ILoggingService CreateLoggingService( // We do want to dictate our own forwarding logger (otherwise CentralForwardingLogger with minimum transferred importance MessageImportance.Low is used) // In the future we might optimize for single, in-node build scenario - where forwarding logger is not needed (but it's just quick pass-through) LoggerDescription forwardingLoggerDescription = new LoggerDescription( - loggerClassName: typeof(InternalTelemeteryForwardingLogger).FullName, - loggerAssemblyName: typeof(InternalTelemeteryForwardingLogger).GetTypeInfo().Assembly.GetName().FullName, + loggerClassName: typeof(InternalTelemetryForwardingLogger).FullName, + loggerAssemblyName: typeof(InternalTelemetryForwardingLogger).GetTypeInfo().Assembly.GetName().FullName, loggerAssemblyFile: null, loggerSwitchParameters: null, verbosity: LoggerVerbosity.Quiet); diff --git a/src/Build/BackEnd/Components/Logging/EventSourceSink.cs b/src/Build/BackEnd/Components/Logging/EventSourceSink.cs index e61db2b91b2..995370003eb 100644 --- a/src/Build/BackEnd/Components/Logging/EventSourceSink.cs +++ b/src/Build/BackEnd/Components/Logging/EventSourceSink.cs @@ -5,6 +5,7 @@ using Microsoft.Build.Experimental.BuildCheck.Infrastructure; using Microsoft.Build.Experimental.BuildCheck; using Microsoft.Build.Framework; +using Microsoft.Build.Framework.Telemetry; using Microsoft.Build.Shared; using InternalLoggerException = Microsoft.Build.Exceptions.InternalLoggerException; diff --git a/src/Build/TelemetryInfra/InternalTelemetryConsumingLogger.cs b/src/Build/TelemetryInfra/InternalTelemetryConsumingLogger.cs index 24cd5b9ed0e..8b509b477a0 100644 --- a/src/Build/TelemetryInfra/InternalTelemetryConsumingLogger.cs +++ b/src/Build/TelemetryInfra/InternalTelemetryConsumingLogger.cs @@ -14,7 +14,7 @@ internal sealed class InternalTelemetryConsumingLogger : ILogger { public LoggerVerbosity Verbosity { get; set; } public string? Parameters { get; set; } - internal static event Action? TestOnly_InternalTelemetryAggregted; + internal static event Action? TestOnly_InternalTelemetryAggregted; public void Initialize(IEventSource eventSource) { @@ -38,12 +38,11 @@ private void EventSourceOnBuildFinished(object sender, BuildFinishedEventArgs e) { TestOnly_InternalTelemetryAggregted?.Invoke(_workerNodeTelemetryData); FlushDataIntoConsoleIfRequested(); - FlushDataIntoJsonFileIfRequested(); } private void FlushDataIntoConsoleIfRequested() { - if (!Traits.IsEnvVarOneOrTrue("MSBUILDOUTPUTNODESTELEMETRY")) + if (!Traits.Instance.FlushNodesTelemetryIntoConsole) { return; } @@ -82,22 +81,6 @@ private void FlushDataIntoConsoleIfRequested() Console.WriteLine("=========================================="); } - private void FlushDataIntoJsonFileIfRequested() - { - const string jsonFileNameVariable = "MSBUILDNODETELEMETRYFILENAME"; - var jsonFilePath = Environment.GetEnvironmentVariable(jsonFileNameVariable); - if (string.IsNullOrEmpty(jsonFilePath)) - { - return; - } - - var telemetryTags = _workerNodeTelemetryData.AsActivityDataHolder(true, true)?.GetActivityProperties(); - - using var stream = File.OpenWrite(jsonFilePath); - 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 ed91dcdbaa9..e81ad32eaff 100644 --- a/src/Build/TelemetryInfra/TelemetryDataUtils.cs +++ b/src/Build/TelemetryInfra/TelemetryDataUtils.cs @@ -5,6 +5,7 @@ using System.Collections.Generic; using System.Text.Json; using System.Text.Json.Serialization; + namespace Microsoft.Build.Framework.Telemetry { internal static class TelemetryDataUtils @@ -247,12 +248,12 @@ void UpdateStatistics( { UpdateSingleStatistics(key.IsCustom ? customTaskInfo : builtinTaskInfo, taskExecutionStats, key); - void UpdateSingleStatistics(TasksInfo summarizedTaskInfo, TaskExecutionStats infoToAdd, TaskOrTargetTelemetryKey kkey) + void UpdateSingleStatistics(TasksInfo summarizedTaskInfo, TaskExecutionStats infoToAdd, TaskOrTargetTelemetryKey key) { - summarizedTaskInfo.Total.AddAnother(infoToAdd); - if (kkey.IsFromNugetCache) + summarizedTaskInfo.Total.Accumulate(infoToAdd); + if (key.IsFromNugetCache) { - summarizedTaskInfo.FromNuget.AddAnother(infoToAdd); + summarizedTaskInfo.FromNuget.Accumulate(infoToAdd); } } } diff --git a/src/Build/TelemetryInfra/TelemetryForwarderProvider.cs b/src/Build/TelemetryInfra/TelemetryForwarderProvider.cs index b3522dbf64a..58ea242088b 100644 --- a/src/Build/TelemetryInfra/TelemetryForwarderProvider.cs +++ b/src/Build/TelemetryInfra/TelemetryForwarderProvider.cs @@ -5,6 +5,7 @@ using Microsoft.Build.BackEnd; using Microsoft.Build.BackEnd.Logging; using Microsoft.Build.Framework; +using Microsoft.Build.Framework.Telemetry; using Microsoft.Build.Shared; namespace Microsoft.Build.TelemetryInfra; diff --git a/src/Framework/IEventSource5.cs b/src/Framework/IEventSource5.cs index 6ce4f300c30..cd56c63fb40 100644 --- a/src/Framework/IEventSource5.cs +++ b/src/Framework/IEventSource5.cs @@ -1,5 +1,6 @@ // Licensed to the .NET Foundation under one or more agreements. // The .NET Foundation licenses this file to you under the MIT license. +using Microsoft.Build.Framework.Telemetry; namespace Microsoft.Build.Framework { diff --git a/src/Framework/Telemetry/IWorkerNodeTelemetryData.cs b/src/Framework/Telemetry/IWorkerNodeTelemetryData.cs index 7f439252482..a0303e4a4e2 100644 --- a/src/Framework/Telemetry/IWorkerNodeTelemetryData.cs +++ b/src/Framework/Telemetry/IWorkerNodeTelemetryData.cs @@ -3,7 +3,7 @@ using System.Collections.Generic; -namespace Microsoft.Build.Framework; +namespace Microsoft.Build.Framework.Telemetry; internal interface IWorkerNodeTelemetryData { diff --git a/src/Framework/Telemetry/InternalTelemetryForwardingLogger.cs b/src/Framework/Telemetry/InternalTelemetryForwardingLogger.cs index 95e38567587..2208f4f2f5b 100644 --- a/src/Framework/Telemetry/InternalTelemetryForwardingLogger.cs +++ b/src/Framework/Telemetry/InternalTelemetryForwardingLogger.cs @@ -1,12 +1,12 @@ // Licensed to the .NET Foundation under one or more agreements. // The .NET Foundation licenses this file to you under the MIT license. -namespace Microsoft.Build.Framework; +namespace Microsoft.Build.Framework.Telemetry; /// /// Ensure that events filtering is in sync with InternalTelemetryConsumingLogger. /// -internal class InternalTelemeteryForwardingLogger : IForwardingLogger +internal class InternalTelemetryForwardingLogger : IForwardingLogger { public IEventRedirector? BuildEventRedirector { get; set; } diff --git a/src/Framework/Telemetry/TaskExecutionStats.cs b/src/Framework/Telemetry/TaskExecutionStats.cs index b3f1564d615..cd549607c7e 100644 --- a/src/Framework/Telemetry/TaskExecutionStats.cs +++ b/src/Framework/Telemetry/TaskExecutionStats.cs @@ -3,14 +3,20 @@ using System; -namespace Microsoft.Build.Framework; +namespace Microsoft.Build.Framework.Telemetry; +/// +/// Represents the stats of tasks executed on a node. +/// internal class TaskExecutionStats(TimeSpan cumulativeExecutionTime, int executionsCount, long totalMemoryConsumption) { private TaskExecutionStats() : this(TimeSpan.Zero, 0, 0) { } - + /// + /// Creates an empty instance of . + /// + /// Empty stats. internal static TaskExecutionStats CreateEmpty() => new(); @@ -29,14 +35,18 @@ internal static TaskExecutionStats CreateEmpty() /// public int ExecutionsCount { get; set; } = executionsCount; - internal void AddAnother(TaskExecutionStats another) + /// + /// Merges stats from another node to this instance. + /// + /// Stats from another node. + internal void Accumulate(TaskExecutionStats another) { this.CumulativeExecutionTime += another.CumulativeExecutionTime; this.TotalMemoryConsumption += another.TotalMemoryConsumption; this.ExecutionsCount += another.ExecutionsCount; } - // We need custom Equals for easier assertations in tests + // We need custom Equals for easier assertions in tests public override bool Equals(object? obj) { if (obj is TaskExecutionStats other) diff --git a/src/Framework/Telemetry/WorkerNodeTelemetryData.cs b/src/Framework/Telemetry/WorkerNodeTelemetryData.cs index 4b5afad229f..aa36448c533 100644 --- a/src/Framework/Telemetry/WorkerNodeTelemetryData.cs +++ b/src/Framework/Telemetry/WorkerNodeTelemetryData.cs @@ -4,7 +4,7 @@ using System; using System.Collections.Generic; -namespace Microsoft.Build.Framework; +namespace Microsoft.Build.Framework.Telemetry; internal class WorkerNodeTelemetryData : IWorkerNodeTelemetryData { diff --git a/src/Framework/Telemetry/WorkerNodeTelemetryEventArgs.cs b/src/Framework/Telemetry/WorkerNodeTelemetryEventArgs.cs index a416f4245ad..31bcef0238c 100644 --- a/src/Framework/Telemetry/WorkerNodeTelemetryEventArgs.cs +++ b/src/Framework/Telemetry/WorkerNodeTelemetryEventArgs.cs @@ -6,7 +6,7 @@ using System.IO; using Microsoft.Build.Shared; -namespace Microsoft.Build.Framework; +namespace Microsoft.Build.Framework.Telemetry; internal sealed class WorkerNodeTelemetryEventArgs(IWorkerNodeTelemetryData workerNodeTelemetryData) : BuildEventArgs { diff --git a/src/Framework/Traits.cs b/src/Framework/Traits.cs index 046933f38f0..a19ff522759 100644 --- a/src/Framework/Traits.cs +++ b/src/Framework/Traits.cs @@ -142,6 +142,7 @@ public Traits() public bool FrameworkTelemetryOptOut = IsEnvVarOneOrTrue("MSBUILD_TELEMETRY_OPTOUT"); public double? TelemetrySampleRateOverride = ParseDoubleFromEnvironmentVariable("MSBUILD_TELEMETRY_SAMPLE_RATE"); public bool ExcludeTasksDetailsFromTelemetry = IsEnvVarOneOrTrue("MSBUILDTELEMETRYEXCLUDETASKSDETAILS"); + public bool FlushNodesTelemetryIntoConsole = IsEnvVarOneOrTrue("MSBUILDFLUSHNODESTELEMETRYINTOCONSOLE"); // for VS17.14 public readonly bool TelemetryOptIn = IsEnvVarOneOrTrue("MSBUILD_TELEMETRY_OPTIN"); diff --git a/src/Shared/LogMessagePacketBase.cs b/src/Shared/LogMessagePacketBase.cs index 36e8e9db0df..123d102440d 100644 --- a/src/Shared/LogMessagePacketBase.cs +++ b/src/Shared/LogMessagePacketBase.cs @@ -10,6 +10,7 @@ using Microsoft.Build.Framework; #if !TASKHOST +using Microsoft.Build.Framework.Telemetry; using Microsoft.Build.Experimental.BuildCheck; #endif From 257968d1690387dca8e1d7c10b77246203d39173 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jan=20Provazn=C3=ADk?= Date: Mon, 10 Mar 2025 17:16:27 +0100 Subject: [PATCH 02/10] address review comments pt1, implement e2e node telemetry test --- .../BackEnd/NodePackets_Tests.cs | 1 + .../OpenTelemetryActivities_Tests.cs | 3 +- .../OpenTelemetryManager_Tests.cs | 52 ++---- .../{ => Telemetry}/TelemetryTests.cs | 173 +++++++++++++++--- .../TelemetryInfra/TelemetryDataUtils.cs | 86 +++++---- src/Framework/Telemetry/TaskExecutionStats.cs | 2 +- .../Telemetry/TaskOrTargetTelemetryKey.cs | 37 ++-- .../Telemetry/WorkerNodeTelemetryEventArgs.cs | 4 +- 8 files changed, 235 insertions(+), 123 deletions(-) rename src/Build.UnitTests/{BackEnd => Telemetry}/OpenTelemetryActivities_Tests.cs (98%) rename src/Build.UnitTests/{BackEnd => Telemetry}/OpenTelemetryManager_Tests.cs (66%) rename src/Build.UnitTests/{ => Telemetry}/TelemetryTests.cs (55%) diff --git a/src/Build.UnitTests/BackEnd/NodePackets_Tests.cs b/src/Build.UnitTests/BackEnd/NodePackets_Tests.cs index 3da36a531ab..48a375147d6 100644 --- a/src/Build.UnitTests/BackEnd/NodePackets_Tests.cs +++ b/src/Build.UnitTests/BackEnd/NodePackets_Tests.cs @@ -10,6 +10,7 @@ using Microsoft.Build.Execution; using Microsoft.Build.Experimental.BuildCheck; using Microsoft.Build.Framework; +using Microsoft.Build.Framework.Telemetry; using Microsoft.Build.Shared; using Xunit; using TaskItem = Microsoft.Build.Execution.ProjectItemInstance.TaskItem; diff --git a/src/Build.UnitTests/BackEnd/OpenTelemetryActivities_Tests.cs b/src/Build.UnitTests/Telemetry/OpenTelemetryActivities_Tests.cs similarity index 98% rename from src/Build.UnitTests/BackEnd/OpenTelemetryActivities_Tests.cs rename to src/Build.UnitTests/Telemetry/OpenTelemetryActivities_Tests.cs index cd041632de2..5616f614530 100644 --- a/src/Build.UnitTests/BackEnd/OpenTelemetryActivities_Tests.cs +++ b/src/Build.UnitTests/Telemetry/OpenTelemetryActivities_Tests.cs @@ -8,8 +8,9 @@ using System.Text; using Xunit; using Shouldly; +using Microsoft.Build.Framework.Telemetry; -namespace Microsoft.Build.Framework.Telemetry.Tests +namespace Microsoft.Build.Engine.UnitTests.Telemetry { public class ActivityExtensionsTests { diff --git a/src/Build.UnitTests/BackEnd/OpenTelemetryManager_Tests.cs b/src/Build.UnitTests/Telemetry/OpenTelemetryManager_Tests.cs similarity index 66% rename from src/Build.UnitTests/BackEnd/OpenTelemetryManager_Tests.cs rename to src/Build.UnitTests/Telemetry/OpenTelemetryManager_Tests.cs index a2ec5161797..38f3a27b859 100644 --- a/src/Build.UnitTests/BackEnd/OpenTelemetryManager_Tests.cs +++ b/src/Build.UnitTests/Telemetry/OpenTelemetryManager_Tests.cs @@ -8,8 +8,9 @@ using Xunit.Abstractions; using Microsoft.Build.UnitTests.Shared; using Microsoft.Build.UnitTests; +using Microsoft.Build.Framework.Telemetry; -namespace Microsoft.Build.Framework.Telemetry.Tests +namespace Microsoft.Build.Engine.UnitTests.Telemetry { /// /// Ensures tests run serially so environment variables and the singleton do not interfere with parallel test runs. @@ -23,46 +24,13 @@ public class OpenTelemetryManagerTests : IDisposable private const string TelemetrySampleRateOverrideEnvVarName = "MSBUILD_TELEMETRY_SAMPLE_RATE"; private const string VS1714TelemetryOptInEnvVarName = "MSBUILD_TELEMETRY_OPTIN"; - private string? preTestFxOptout; - private string? preTestDotnetOptout; - private string? preTestSampleRate; - private string? preTestVS1714TelemetryOptIn; - public OpenTelemetryManagerTests() { - // control environment state before each test - SaveEnvVars(); ResetManagerState(); - ResetEnvVars(); - } - - private void SaveEnvVars() - { - preTestFxOptout = Environment.GetEnvironmentVariable(TelemetryFxOptoutEnvVarName); - preTestDotnetOptout = Environment.GetEnvironmentVariable(DotnetOptOut); - preTestSampleRate = Environment.GetEnvironmentVariable(TelemetrySampleRateOverrideEnvVarName); - preTestVS1714TelemetryOptIn = Environment.GetEnvironmentVariable(VS1714TelemetryOptInEnvVarName); - } - - private void RestoreEnvVars() - { - Environment.SetEnvironmentVariable(TelemetryFxOptoutEnvVarName, preTestFxOptout); - Environment.SetEnvironmentVariable(DotnetOptOut, preTestDotnetOptout); - Environment.SetEnvironmentVariable(TelemetrySampleRateOverrideEnvVarName, preTestSampleRate); - Environment.SetEnvironmentVariable(VS1714TelemetryOptInEnvVarName, preTestVS1714TelemetryOptIn); - } - - private void ResetEnvVars() - { - Environment.SetEnvironmentVariable(DotnetOptOut, null); - Environment.SetEnvironmentVariable(TelemetryFxOptoutEnvVarName, null); - Environment.SetEnvironmentVariable(TelemetrySampleRateOverrideEnvVarName, null); - Environment.SetEnvironmentVariable(VS1714TelemetryOptInEnvVarName, null); } public void Dispose() { - RestoreEnvVars(); } [Theory] @@ -73,7 +41,8 @@ public void Dispose() public void Initialize_ShouldSetStateToOptOut_WhenOptOutEnvVarIsTrue(string optoutVar, string value) { // Arrange - Environment.SetEnvironmentVariable(optoutVar, value); + using TestEnvironment environment = TestEnvironment.Create(); + environment.SetEnvironmentVariable(optoutVar, value); // Act OpenTelemetryManager.Instance.Initialize(isStandalone: false); @@ -86,7 +55,8 @@ public void Initialize_ShouldSetStateToOptOut_WhenOptOutEnvVarIsTrue(string opto [Fact] public void Initialize_ShouldSetStateToUnsampled_WhenNoOverrideOnNetCore() { - Environment.SetEnvironmentVariable(TelemetrySampleRateOverrideEnvVarName, null); + using TestEnvironment environment = TestEnvironment.Create(); + environment.SetEnvironmentVariable(TelemetrySampleRateOverrideEnvVarName, null); OpenTelemetryManager.Instance.Initialize(isStandalone: false); @@ -101,8 +71,9 @@ public void Initialize_ShouldSetStateToUnsampled_WhenNoOverrideOnNetCore() public void Initialize_ShouldSetSampleRateOverride_AndCreateActivitySource_WhenRandomBelowOverride(bool standalone) { // Arrange - Environment.SetEnvironmentVariable(VS1714TelemetryOptInEnvVarName, "1"); - Environment.SetEnvironmentVariable(TelemetrySampleRateOverrideEnvVarName, "1.0"); + using TestEnvironment environment = TestEnvironment.Create(); + environment.SetEnvironmentVariable(VS1714TelemetryOptInEnvVarName, "1"); + environment.SetEnvironmentVariable(TelemetrySampleRateOverrideEnvVarName, "1.0"); // Act OpenTelemetryManager.Instance.Initialize(isStandalone: standalone); @@ -115,11 +86,12 @@ public void Initialize_ShouldSetSampleRateOverride_AndCreateActivitySource_WhenR [Fact] public void Initialize_ShouldNoOp_WhenCalledMultipleTimes() { - Environment.SetEnvironmentVariable(DotnetOptOut, "true"); + using TestEnvironment environment = TestEnvironment.Create(); + environment.SetEnvironmentVariable(DotnetOptOut, "true"); OpenTelemetryManager.Instance.Initialize(isStandalone: true); var state1 = OpenTelemetryManager.Instance.IsActive(); - Environment.SetEnvironmentVariable(DotnetOptOut, null); + environment.SetEnvironmentVariable(DotnetOptOut, null); OpenTelemetryManager.Instance.Initialize(isStandalone: true); var state2 = OpenTelemetryManager.Instance.IsActive(); diff --git a/src/Build.UnitTests/TelemetryTests.cs b/src/Build.UnitTests/Telemetry/TelemetryTests.cs similarity index 55% rename from src/Build.UnitTests/TelemetryTests.cs rename to src/Build.UnitTests/Telemetry/TelemetryTests.cs index d04353d7321..4b9074b2bb5 100644 --- a/src/Build.UnitTests/TelemetryTests.cs +++ b/src/Build.UnitTests/Telemetry/TelemetryTests.cs @@ -3,6 +3,7 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.Linq; using System.Text.Json; using Microsoft.Build.Execution; @@ -82,7 +83,7 @@ public void WorkerNodeTelemetryCollection_BasicTarget() ((int)workerNodeTelemetryData.TasksExecutionData[(TaskOrTargetTelemetryKey)"Microsoft.Build.Tasks.CreateItem"].ExecutionsCount).ShouldBe(1); workerNodeTelemetryData.TasksExecutionData[(TaskOrTargetTelemetryKey)"Microsoft.Build.Tasks.CreateItem"].CumulativeExecutionTime.ShouldBeGreaterThan(TimeSpan.Zero); - workerNodeTelemetryData.TasksExecutionData.Keys.ShouldAllBe(k => !k.IsCustom && !k.IsFromNugetCache); + workerNodeTelemetryData.TasksExecutionData.Keys.ShouldAllBe(k => !k.IsCustom && !k.IsNuget); workerNodeTelemetryData.TasksExecutionData.Values .Count(v => v.CumulativeExecutionTime > TimeSpan.Zero || v.ExecutionsCount > 0).ShouldBe(2); } @@ -106,7 +107,7 @@ public void WorkerNodeTelemetryCollection_CustomTargetsAndTasks() - + - + @@ -127,12 +128,12 @@ public void WorkerNodeTelemetryCollection_CustomTargetsAndTasks() - + - + @@ -166,32 +167,150 @@ public void WorkerNodeTelemetryCollection_CustomTargetsAndTasks() workerNodeTelemetryData.TasksExecutionData.Values .Count(v => v.CumulativeExecutionTime > TimeSpan.Zero || v.ExecutionsCount > 0).ShouldBe(3); - workerNodeTelemetryData.TasksExecutionData.Keys.ShouldAllBe(k => !k.IsFromNugetCache); + workerNodeTelemetryData.TasksExecutionData.Keys.ShouldAllBe(k => !k.IsNuget); } +#if NET [Fact] - public void Foo() + public void NodeTelemetryE2E() { - WorkerNodeTelemetryData wd = new WorkerNodeTelemetryData( - new Dictionary() - { - { - new TaskOrTargetTelemetryKey("TaskA", false, true), - new TaskExecutionStats(TimeSpan.FromSeconds(2.1554548), 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, true, true); + using TestEnvironment env = TestEnvironment.Create(); + env.SetEnvironmentVariable("MSBUILD_TELEMETRY_OPTIN", "1"); + env.SetEnvironmentVariable("MSBUILD_TELEMETRY_SAMPLE_RATE", "1.0"); + env.SetEnvironmentVariable("MSBUILD_TELEMETRY_OPTOUT", null); + env.SetEnvironmentVariable("DOTNET_CLI_TELEMETRY_OPTOUT", null); + + // Reset the OpenTelemetryManager state to ensure clean test + var instance = OpenTelemetryManager.Instance; + typeof(OpenTelemetryManager) + .GetField("_telemetryState", System.Reflection.BindingFlags.NonPublic | System.Reflection.BindingFlags.Instance) + ?.SetValue(instance, OpenTelemetryManager.TelemetryState.Uninitialized); + + typeof(OpenTelemetryManager) + .GetProperty("DefaultActivitySource", + System.Reflection.BindingFlags.Public | System.Reflection.BindingFlags.NonPublic | System.Reflection.BindingFlags.Instance) + ?.SetValue(instance, null); + + // track activities through an ActivityListener + var capturedActivities = new List(); + using var listener = new ActivityListener + { + ShouldListenTo = source => source.Name.StartsWith(TelemetryConstants.DefaultActivitySourceNamespace), + Sample = (ref ActivityCreationOptions _) => ActivitySamplingResult.AllData, + ActivityStarted = capturedActivities.Add, + ActivityStopped = _ => { } + }; + ActivitySource.AddActivityListener(listener); + + var testProject = @" + + + + + + + + + + + + "; + + using var testEnv = TestEnvironment.Create(_output); + var projectFile = testEnv.CreateFile("test.proj", testProject).Path; + + // Set up loggers + var projectFinishedLogger = new ProjectFinishedCapturingLogger(); + var buildParameters = new BuildParameters + { + Loggers = new ILogger[] { projectFinishedLogger }, + IsTelemetryEnabled = true + }; + + // Act + using (var buildManager = new BuildManager()) + { + // Phase 1: Begin Build - This initializes telemetry infrastructure + buildManager.BeginBuild(buildParameters); + + // Phase 2: Execute build requests + var buildRequestData1 = new BuildRequestData( + projectFile, + new Dictionary(), + null, + new[] { "Build" }, + null); + + buildManager.BuildRequest(buildRequestData1); + + var buildRequestData2 = new BuildRequestData( + projectFile, + new Dictionary(), + null, + new[] { "Clean" }, + null); + + buildManager.BuildRequest(buildRequestData2); + + // Phase 3: End Build - This puts telemetry to an system.diagnostics activity + buildManager.EndBuild(); + + // Verify build activity were captured by the listener and contain task and target info + capturedActivities.ShouldNotBeEmpty(); + var activity = capturedActivities.FindLast(a => a.DisplayName == "VS/MSBuild/Build").ShouldNotBeNull(); + var tags = activity.Tags.ToDictionary(t => t.Key, t => t.Value); + tags.ShouldNotBeNull(); + + tags.ShouldContainKey("VS.MSBuild.BuildTarget"); + tags["VS.MSBuild.BuildTarget"].ShouldNotBeNullOrEmpty(); + + // Verify task data + tags.ShouldContainKey("VS.MSBuild.Tasks"); + var tasksJson = tags["VS.MSBuild.Tasks"]; + tasksJson.ShouldContain("Microsoft.Build.Tasks.Message"); + tasksJson.ShouldContain("Microsoft.Build.Tasks.CreateItem"); + + // Parse tasks data for detailed assertions + var tasksData = JsonSerializer.Deserialize(tasksJson); + + // Verify Message task execution metrics - updated for object structure + tasksData.TryGetProperty("Microsoft.Build.Tasks.Message", out var messageTask).ShouldBeTrue(); + // Map JSON property names to TaskExecutionStats properties - they may differ + messageTask.GetProperty("ExecCnt").GetInt32().ShouldBe(3); // Maps to ExecutionsCount + messageTask.GetProperty("ExecTimeMs").GetDouble().ShouldBeGreaterThan(0); // Maps to CumulativeExecutionTime in ms + messageTask.GetProperty("MemKBs").GetInt32().ShouldBeGreaterThan(0); // Maps to TotalMemoryConsumption in KB + messageTask.GetProperty(nameof(TaskOrTargetTelemetryKey.IsCustom)).GetBoolean().ShouldBeFalse(); + messageTask.GetProperty(nameof(TaskOrTargetTelemetryKey.IsNuget)).GetBoolean().ShouldBeFalse(); + + // Verify CreateItem task execution metrics - updated for object structure + tasksData.TryGetProperty("Microsoft.Build.Tasks.CreateItem", out var createItemTask).ShouldBeTrue(); + createItemTask.GetProperty("ExecCnt").GetInt32().ShouldBe(1); // Maps to ExecutionsCount + createItemTask.GetProperty("ExecTimeMs").GetDouble().ShouldBeGreaterThan(0); // Maps to CumulativeExecutionTime in ms + createItemTask.GetProperty("MemKBs").GetInt32().ShouldBeGreaterThan(0); // Maps to TotalMemoryConsumption in KB + + // Verify Targets summary information + tags.ShouldContainKey("VS.MSBuild.TargetsSummary"); + var targetsSummaryJson = tags["VS.MSBuild.TargetsSummary"]; + var targetsSummary = JsonSerializer.Deserialize(targetsSummaryJson); + + // Verify loaded and executed targets counts + targetsSummary.GetProperty("Loaded").GetProperty("Total").GetInt32().ShouldBe(2); + targetsSummary.GetProperty("Executed").GetProperty("Total").GetInt32().ShouldBe(2); + targetsSummary.GetProperty("Loaded").GetProperty("Microsoft").GetProperty("Total").GetInt32().ShouldBe(2); + targetsSummary.GetProperty("Executed").GetProperty("Microsoft").GetProperty("Total").GetInt32().ShouldBe(2); + + // Verify Tasks summary information + tags.ShouldContainKey("VS.MSBuild.TasksSummary"); + var tasksSummaryJson = tags["VS.MSBuild.TasksSummary"]; + var tasksSummary = JsonSerializer.Deserialize(tasksSummaryJson); + + // Verify task execution summary metrics + tasksSummary.GetProperty("Microsoft").GetProperty("Total").GetProperty("TotalExecutionsCount").GetInt32().ShouldBe(4); + tasksSummary.GetProperty("Microsoft").GetProperty("Total").GetProperty("CumulativeExecutionTimeMs").GetInt32().ShouldBeGreaterThan(0); + tasksSummary.GetProperty("Microsoft").GetProperty("Total").GetProperty("CumulativeConsumedMemoryKB").GetInt32().ShouldBeGreaterThan(0); + } } + +#endif } } diff --git a/src/Build/TelemetryInfra/TelemetryDataUtils.cs b/src/Build/TelemetryInfra/TelemetryDataUtils.cs index e81ad32eaff..356a8ec933e 100644 --- a/src/Build/TelemetryInfra/TelemetryDataUtils.cs +++ b/src/Build/TelemetryInfra/TelemetryDataUtils.cs @@ -10,6 +10,13 @@ namespace Microsoft.Build.Framework.Telemetry { internal static class TelemetryDataUtils { + /// + /// Transforms collected telemetry data to format recognized by the telemetry infrastructure. + /// + /// Data about tasks and target forwarded from nodes. + /// Controls whether Task details should attached to the telemetry event. + /// Controls whether Target details should be attached to the telemetry event. + /// public static IActivityTelemetryDataHolder? AsActivityDataHolder(this IWorkerNodeTelemetryData? telemetryData, bool includeTasksDetails, bool includeTargetDetails) { if (telemetryData == null) @@ -50,8 +57,6 @@ private static JsonSerializerOptions CreateSerializerOptions() { var opt = new JsonSerializerOptions { - // Add following if user-friendly indentation would be needed - // WriteIndented = true, Converters = { new TargetDataConverter(), @@ -85,19 +90,19 @@ public override void Write( // Following needed - as System.Text.Json doesn't support indexing dictionary by composite types - writer.WriteStartArray(); + writer.WriteStartObject(); foreach (KeyValuePair valuePair in value) { - writer.WriteStartObject(valuePair.Key.IsCustom || valuePair.Key.IsFromMetaProject ? ActivityExtensions.GetHashed(valuePair.Key.Name) : valuePair.Key.Name); + writer.WriteStartObject(valuePair.Key.IsCustom || valuePair.Key.IsMetaProj ? 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.WriteBoolean(nameof(valuePair.Key.IsCustom), valuePair.Key.IsCustom); + writer.WriteBoolean(nameof(valuePair.Key.IsNuget), valuePair.Key.IsNuget); + writer.WriteBoolean(nameof(valuePair.Key.IsMetaProj), valuePair.Key.IsMetaProj); writer.WriteEndObject(); } - writer.WriteEndArray(); + writer.WriteEndObject(); } } @@ -122,7 +127,7 @@ public override void Write( // Following needed - as System.Text.Json doesn't support indexing dictionary by composite types - writer.WriteStartArray(); + writer.WriteStartObject(); foreach (KeyValuePair valuePair in value) { @@ -132,12 +137,12 @@ public override void Write( writer.WriteNumber("ExecCnt", valuePair.Value.ExecutionsCount); // 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.WriteBoolean(nameof(valuePair.Key.IsCustom), valuePair.Key.IsCustom); + writer.WriteBoolean(nameof(valuePair.Key.IsNuget), valuePair.Key.IsNuget); writer.WriteEndObject(); } - writer.WriteEndArray(); + writer.WriteEndObject(); } } @@ -145,34 +150,39 @@ private class TargetsSummary : JsonConverter { public void Initialize(Dictionary targetsExecutionData) { - foreach (var targetInfo in targetsExecutionData) + foreach (var targetPair in targetsExecutionData) { - UpdateStatistics(LoadedBuiltinTargetInfo, LoadedCustomTargetInfo, targetInfo.Key); - if (targetInfo.Value) + var key = targetPair.Key; + var wasExecuted = targetPair.Value; + + // Update loaded targets statistics (all targets are loaded) + UpdateTargetStatistics(key, isExecuted: false); + + // Update executed targets statistics (only targets that were actually executed) + if (wasExecuted) { - UpdateStatistics(ExecutedBuiltinTargetInfo, ExecutedCustomTargetInfo, targetInfo.Key); + UpdateTargetStatistics(key, isExecuted: true); } } + } - void UpdateStatistics( - TargetInfo builtinTargetInfo, - TargetInfo customTargetInfo, - TaskOrTargetTelemetryKey key) - { - UpdateSingleStatistics(key.IsCustom ? customTargetInfo : builtinTargetInfo, key); + private void UpdateTargetStatistics(TaskOrTargetTelemetryKey key, bool isExecuted) + { + // Select the appropriate target info collections based on execution state + var builtinTargetInfo = isExecuted ? ExecutedBuiltinTargetInfo : LoadedBuiltinTargetInfo; + var customTargetInfo = isExecuted ? ExecutedCustomTargetInfo : LoadedCustomTargetInfo; - void UpdateSingleStatistics(TargetInfo targetInfo, TaskOrTargetTelemetryKey kkey) - { - targetInfo.Total++; - if (kkey.IsFromNugetCache) - { - targetInfo.FromNuget++; - } - if (kkey.IsFromMetaProject) - { - targetInfo.FromMetaproj++; - } - } + // Update either custom or builtin target info based on target type + var targetInfo = key.IsCustom ? customTargetInfo : builtinTargetInfo; + + targetInfo.Total++; + if (key.IsNuget) + { + targetInfo.FromNuget++; + } + if (key.IsMetaProj) + { + targetInfo.FromMetaproj++; } } @@ -251,7 +261,7 @@ void UpdateStatistics( void UpdateSingleStatistics(TasksInfo summarizedTaskInfo, TaskExecutionStats infoToAdd, TaskOrTargetTelemetryKey key) { summarizedTaskInfo.Total.Accumulate(infoToAdd); - if (key.IsFromNugetCache) + if (key.IsNuget) { summarizedTaskInfo.FromNuget.Accumulate(infoToAdd); } @@ -287,12 +297,12 @@ public override void Write( void WriteStat(Utf8JsonWriter writer, TasksInfo tasksInfo, string name) { writer.WriteStartObject(name); - WriteSingleStat(writer, tasksInfo.Total, "Total", true); - WriteSingleStat(writer, tasksInfo.FromNuget, "FromNuget", false); + WriteSingleStat(writer, tasksInfo.Total, "Total"); + WriteSingleStat(writer, tasksInfo.FromNuget, "FromNuget"); writer.WriteEndObject(); } - void WriteSingleStat(Utf8JsonWriter writer, TaskExecutionStats stats, string name, bool writeIfEmpty) + void WriteSingleStat(Utf8JsonWriter writer, TaskExecutionStats stats, string name) { if (stats.ExecutionsCount > 0) { diff --git a/src/Framework/Telemetry/TaskExecutionStats.cs b/src/Framework/Telemetry/TaskExecutionStats.cs index cd549607c7e..06e75f68224 100644 --- a/src/Framework/Telemetry/TaskExecutionStats.cs +++ b/src/Framework/Telemetry/TaskExecutionStats.cs @@ -14,7 +14,7 @@ private TaskExecutionStats() : this(TimeSpan.Zero, 0, 0) { } /// - /// Creates an empty instance of . + /// Creates an instance of initialized to 0s. /// /// Empty stats. internal static TaskExecutionStats CreateEmpty() diff --git a/src/Framework/Telemetry/TaskOrTargetTelemetryKey.cs b/src/Framework/Telemetry/TaskOrTargetTelemetryKey.cs index 864ce31e7a9..e687ac79402 100644 --- a/src/Framework/Telemetry/TaskOrTargetTelemetryKey.cs +++ b/src/Framework/Telemetry/TaskOrTargetTelemetryKey.cs @@ -3,7 +3,7 @@ using System; -namespace Microsoft.Build.Framework; +namespace Microsoft.Build.Framework.Telemetry; internal struct TaskOrTargetTelemetryKey : IEquatable { @@ -11,15 +11,15 @@ public TaskOrTargetTelemetryKey(string name, bool isCustom, bool isFromNugetCach { Name = name; IsCustom = isCustom; - IsFromNugetCache = isFromNugetCache; - IsFromMetaProject = isFromMetaProject; + IsNuget = isFromNugetCache; + IsMetaProj = isFromMetaProject; } public TaskOrTargetTelemetryKey(string name, bool isCustom, bool isFromNugetCache) { Name = name; IsCustom = isCustom; - IsFromNugetCache = isFromNugetCache; + IsNuget = isFromNugetCache; } public TaskOrTargetTelemetryKey(string name) => Name = name; @@ -27,12 +27,21 @@ public TaskOrTargetTelemetryKey(string name, bool isCustom, bool isFromNugetCach public static explicit operator TaskOrTargetTelemetryKey(string key) => new(key); public string Name { get; } - // Indicate custom targets/task - those must be hashed. + + /// + /// Indicate custom targets/task - those must be hashed. + /// public bool IsCustom { get; } - // Indicate targets/tasks sourced from nuget cache - those can be custom or MSFT provided ones. - public bool IsFromNugetCache { get; } - // Indicate targets/tasks generated during build - those must be hashed (as they contain paths). - public bool IsFromMetaProject { get; } + + /// + /// Indicate targets/tasks sourced from NuGet cache - those can be custom or MSFT provided ones. + /// + public bool IsNuget { get; } + + /// + /// Indicate targets/tasks generated during build - those must be hashed (as they contain paths). + /// + public bool IsMetaProj { get; } public override bool Equals(object? obj) { @@ -46,8 +55,8 @@ public override bool Equals(object? obj) public bool Equals(TaskOrTargetTelemetryKey other) => string.Equals(Name, other.Name, StringComparison.OrdinalIgnoreCase) && IsCustom == other.IsCustom && - IsFromNugetCache == other.IsFromNugetCache && - IsFromMetaProject == other.IsFromMetaProject; + IsNuget == other.IsNuget && + IsMetaProj == other.IsMetaProj; // We need hash code and equals - so that we can stuff data into dictionaries public override int GetHashCode() @@ -56,11 +65,11 @@ public override int GetHashCode() { var hashCode = Name.GetHashCode(); hashCode = (hashCode * 397) ^ IsCustom.GetHashCode(); - hashCode = (hashCode * 397) ^ IsFromNugetCache.GetHashCode(); - hashCode = (hashCode * 397) ^ IsFromMetaProject.GetHashCode(); + hashCode = (hashCode * 397) ^ IsNuget.GetHashCode(); + hashCode = (hashCode * 397) ^ IsMetaProj.GetHashCode(); return hashCode; } } - public override string ToString() => $"{Name},Custom:{IsCustom},IsFromNugetCache:{IsFromNugetCache},IsFromMetaProject:{IsFromMetaProject}"; + public override string ToString() => $"{Name},Custom:{IsCustom},IsFromNugetCache:{IsNuget},IsFromMetaProject:{IsMetaProj}"; } diff --git a/src/Framework/Telemetry/WorkerNodeTelemetryEventArgs.cs b/src/Framework/Telemetry/WorkerNodeTelemetryEventArgs.cs index 31bcef0238c..7fd80fa4ea8 100644 --- a/src/Framework/Telemetry/WorkerNodeTelemetryEventArgs.cs +++ b/src/Framework/Telemetry/WorkerNodeTelemetryEventArgs.cs @@ -62,8 +62,8 @@ private static void WriteToStream(BinaryWriter writer, TaskOrTargetTelemetryKey { writer.Write(key.Name); writer.Write(key.IsCustom); - writer.Write(key.IsFromNugetCache); - writer.Write(key.IsFromMetaProject); + writer.Write(key.IsNuget); + writer.Write(key.IsMetaProj); } private static TaskOrTargetTelemetryKey ReadFromStream(BinaryReader reader) From d7b7d3eea360f83fd3782f3991cef7dafaecca70 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jan=20Provazn=C3=ADk?= Date: Tue, 11 Mar 2025 15:36:33 +0100 Subject: [PATCH 03/10] rename telemetrytests file --- .../{TelemetryTests.cs => Telemetry_Tests.cs} | 10 +++++++--- 1 file changed, 7 insertions(+), 3 deletions(-) rename src/Build.UnitTests/Telemetry/{TelemetryTests.cs => Telemetry_Tests.cs} (97%) diff --git a/src/Build.UnitTests/Telemetry/TelemetryTests.cs b/src/Build.UnitTests/Telemetry/Telemetry_Tests.cs similarity index 97% rename from src/Build.UnitTests/Telemetry/TelemetryTests.cs rename to src/Build.UnitTests/Telemetry/Telemetry_Tests.cs index 4b9074b2bb5..d71d954b512 100644 --- a/src/Build.UnitTests/Telemetry/TelemetryTests.cs +++ b/src/Build.UnitTests/Telemetry/Telemetry_Tests.cs @@ -17,11 +17,11 @@ namespace Microsoft.Build.Engine.UnitTests { - public class TelemetryTests + public class Telemetry_Tests { private readonly ITestOutputHelper _output; - public TelemetryTests(ITestOutputHelper output) + public Telemetry_Tests(ITestOutputHelper output) { _output = output; } @@ -171,6 +171,7 @@ public void WorkerNodeTelemetryCollection_CustomTargetsAndTasks() } #if NET + // test in .net core with opentelemetry opted in to avoid sending it but enable listening to it [Fact] public void NodeTelemetryE2E() { @@ -252,7 +253,7 @@ public void NodeTelemetryE2E() buildManager.BuildRequest(buildRequestData2); - // Phase 3: End Build - This puts telemetry to an system.diagnostics activity + // Phase 3: End Build - This puts telemetry to an system.diagnostics activity buildManager.EndBuild(); // Verify build activity were captured by the listener and contain task and target info @@ -267,6 +268,7 @@ public void NodeTelemetryE2E() // Verify task data tags.ShouldContainKey("VS.MSBuild.Tasks"); var tasksJson = tags["VS.MSBuild.Tasks"]; + tasksJson.ShouldNotBeNullOrEmpty(); tasksJson.ShouldContain("Microsoft.Build.Tasks.Message"); tasksJson.ShouldContain("Microsoft.Build.Tasks.CreateItem"); @@ -291,6 +293,7 @@ public void NodeTelemetryE2E() // Verify Targets summary information tags.ShouldContainKey("VS.MSBuild.TargetsSummary"); var targetsSummaryJson = tags["VS.MSBuild.TargetsSummary"]; + targetsSummaryJson.ShouldNotBeNullOrEmpty(); var targetsSummary = JsonSerializer.Deserialize(targetsSummaryJson); // Verify loaded and executed targets counts @@ -302,6 +305,7 @@ public void NodeTelemetryE2E() // Verify Tasks summary information tags.ShouldContainKey("VS.MSBuild.TasksSummary"); var tasksSummaryJson = tags["VS.MSBuild.TasksSummary"]; + tasksSummaryJson.ShouldNotBeNullOrEmpty(); var tasksSummary = JsonSerializer.Deserialize(tasksSummaryJson); // Verify task execution summary metrics From 84045698d12b6c09a7b4e242edd77aea8d67064d Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jan=20Provazn=C3=ADk?= Date: Mon, 17 Mar 2025 13:09:13 +0100 Subject: [PATCH 04/10] descriptive names and docs --- .../Telemetry/Telemetry_Tests.cs | 33 ++-- .../InternalTelemetryConsumingLogger.cs | 6 +- .../TelemetryInfra/TelemetryDataUtils.cs | 150 +++++++++--------- .../WorkerNodeTelemetryEventArgs_Tests.cs | 1 + src/Framework/Telemetry/TaskExecutionStats.cs | 27 ++-- .../Telemetry/TaskOrTargetTelemetryKey.cs | 40 ++++- src/Framework/Telemetry/TelemetryConstants.cs | 9 ++ .../Telemetry/WorkerNodeTelemetryData.cs | 4 +- .../Telemetry/WorkerNodeTelemetryEventArgs.cs | 2 +- 9 files changed, 162 insertions(+), 110 deletions(-) diff --git a/src/Build.UnitTests/Telemetry/Telemetry_Tests.cs b/src/Build.UnitTests/Telemetry/Telemetry_Tests.cs index d71d954b512..49f1782aa7c 100644 --- a/src/Build.UnitTests/Telemetry/Telemetry_Tests.cs +++ b/src/Build.UnitTests/Telemetry/Telemetry_Tests.cs @@ -276,19 +276,18 @@ public void NodeTelemetryE2E() var tasksData = JsonSerializer.Deserialize(tasksJson); // Verify Message task execution metrics - updated for object structure - tasksData.TryGetProperty("Microsoft.Build.Tasks.Message", out var messageTask).ShouldBeTrue(); - // Map JSON property names to TaskExecutionStats properties - they may differ - messageTask.GetProperty("ExecCnt").GetInt32().ShouldBe(3); // Maps to ExecutionsCount - messageTask.GetProperty("ExecTimeMs").GetDouble().ShouldBeGreaterThan(0); // Maps to CumulativeExecutionTime in ms - messageTask.GetProperty("MemKBs").GetInt32().ShouldBeGreaterThan(0); // Maps to TotalMemoryConsumption in KB - messageTask.GetProperty(nameof(TaskOrTargetTelemetryKey.IsCustom)).GetBoolean().ShouldBeFalse(); - messageTask.GetProperty(nameof(TaskOrTargetTelemetryKey.IsNuget)).GetBoolean().ShouldBeFalse(); + tasksData.TryGetProperty("Microsoft.Build.Tasks.Message", out var messageTask).ShouldBe(true); + messageTask.GetProperty("ExecutionsCount").GetInt32().ShouldBe(3); + messageTask.GetProperty("TotalMilliseconds").GetDouble().ShouldBeGreaterThan(0); + messageTask.GetProperty("TotalMemoryBytes").GetInt64().ShouldBeGreaterThan(0); + messageTask.GetProperty(nameof(TaskOrTargetTelemetryKey.IsCustom)).GetBoolean().ShouldBe(false); + messageTask.GetProperty(nameof(TaskOrTargetTelemetryKey.IsCustom)).GetBoolean().ShouldBe(false); // Verify CreateItem task execution metrics - updated for object structure - tasksData.TryGetProperty("Microsoft.Build.Tasks.CreateItem", out var createItemTask).ShouldBeTrue(); - createItemTask.GetProperty("ExecCnt").GetInt32().ShouldBe(1); // Maps to ExecutionsCount - createItemTask.GetProperty("ExecTimeMs").GetDouble().ShouldBeGreaterThan(0); // Maps to CumulativeExecutionTime in ms - createItemTask.GetProperty("MemKBs").GetInt32().ShouldBeGreaterThan(0); // Maps to TotalMemoryConsumption in KB + tasksData.TryGetProperty("Microsoft.Build.Tasks.CreateItem", out var createItemTask).ShouldBe(true); + createItemTask.GetProperty("ExecutionsCount").GetInt32().ShouldBe(1); + createItemTask.GetProperty("TotalMilliseconds").GetDouble().ShouldBeGreaterThan(0); + createItemTask.GetProperty("TotalMemoryBytes").GetInt64().ShouldBeGreaterThan(0); // Verify Targets summary information tags.ShouldContainKey("VS.MSBuild.TargetsSummary"); @@ -296,11 +295,9 @@ public void NodeTelemetryE2E() targetsSummaryJson.ShouldNotBeNullOrEmpty(); var targetsSummary = JsonSerializer.Deserialize(targetsSummaryJson); - // Verify loaded and executed targets counts + // Verify loaded and executed targets counts - match structure in TargetsSummaryConverter.Write targetsSummary.GetProperty("Loaded").GetProperty("Total").GetInt32().ShouldBe(2); targetsSummary.GetProperty("Executed").GetProperty("Total").GetInt32().ShouldBe(2); - targetsSummary.GetProperty("Loaded").GetProperty("Microsoft").GetProperty("Total").GetInt32().ShouldBe(2); - targetsSummary.GetProperty("Executed").GetProperty("Microsoft").GetProperty("Total").GetInt32().ShouldBe(2); // Verify Tasks summary information tags.ShouldContainKey("VS.MSBuild.TasksSummary"); @@ -308,10 +305,10 @@ public void NodeTelemetryE2E() tasksSummaryJson.ShouldNotBeNullOrEmpty(); var tasksSummary = JsonSerializer.Deserialize(tasksSummaryJson); - // Verify task execution summary metrics - tasksSummary.GetProperty("Microsoft").GetProperty("Total").GetProperty("TotalExecutionsCount").GetInt32().ShouldBe(4); - tasksSummary.GetProperty("Microsoft").GetProperty("Total").GetProperty("CumulativeExecutionTimeMs").GetInt32().ShouldBeGreaterThan(0); - tasksSummary.GetProperty("Microsoft").GetProperty("Total").GetProperty("CumulativeConsumedMemoryKB").GetInt32().ShouldBeGreaterThan(0); + // Verify task execution summary metrics based on TasksSummaryConverter.Write structure + tasksSummary.GetProperty("Microsoft").GetProperty("Total").GetProperty("ExecutionsCount").GetInt32().ShouldBe(4); + tasksSummary.GetProperty("Microsoft").GetProperty("Total").GetProperty("TotalMilliseconds").GetDouble().ShouldBeGreaterThan(0); + tasksSummary.GetProperty("Microsoft").GetProperty("Total").GetProperty("TotalMemoryBytes").GetInt64().ShouldBeGreaterThan(0); } } diff --git a/src/Build/TelemetryInfra/InternalTelemetryConsumingLogger.cs b/src/Build/TelemetryInfra/InternalTelemetryConsumingLogger.cs index 8b509b477a0..8d4832cd374 100644 --- a/src/Build/TelemetryInfra/InternalTelemetryConsumingLogger.cs +++ b/src/Build/TelemetryInfra/InternalTelemetryConsumingLogger.cs @@ -62,15 +62,15 @@ private void FlushDataIntoConsoleIfRequested() } Console.WriteLine("=========================================="); Console.WriteLine("Tasks by time:"); - foreach (var task in _workerNodeTelemetryData.TasksExecutionData.OrderByDescending(t => t.Value.CumulativeExecutionTime).Take(20)) + foreach (var task in _workerNodeTelemetryData.TasksExecutionData.OrderByDescending(t => t.Value.CumulativeExecutionTime)) { Console.WriteLine($"{task.Key} - {task.Value.CumulativeExecutionTime}"); } Console.WriteLine("=========================================="); Console.WriteLine("Tasks by memory consumption:"); - foreach (var task in _workerNodeTelemetryData.TasksExecutionData.OrderByDescending(t => t.Value.TotalMemoryConsumption).Take(20)) + foreach (var task in _workerNodeTelemetryData.TasksExecutionData.OrderByDescending(t => t.Value.TotalMemoryBytes)) { - Console.WriteLine($"{task.Key} - {task.Value.TotalMemoryConsumption / 1024.0:0.00}kB"); + Console.WriteLine($"{task.Key} - {task.Value.TotalMemoryBytes / 1024.0:0.00}kB"); } Console.WriteLine("=========================================="); Console.WriteLine("Tasks by Executions count:"); diff --git a/src/Build/TelemetryInfra/TelemetryDataUtils.cs b/src/Build/TelemetryInfra/TelemetryDataUtils.cs index 356a8ec933e..e2759bec030 100644 --- a/src/Build/TelemetryInfra/TelemetryDataUtils.cs +++ b/src/Build/TelemetryInfra/TelemetryDataUtils.cs @@ -14,9 +14,9 @@ internal static class TelemetryDataUtils /// Transforms collected telemetry data to format recognized by the telemetry infrastructure. /// /// Data about tasks and target forwarded from nodes. - /// Controls whether Task details should attached to the telemetry event. - /// Controls whether Target details should be attached to the telemetry event. - /// + /// Controls whether Task details should attached to the telemetry. + /// Controls whether Target details should be attached to the telemetry. + /// Node Telemetry data wrapped in a list of properties that can be attached as tags to a . public static IActivityTelemetryDataHolder? AsActivityDataHolder(this IWorkerNodeTelemetryData? telemetryData, bool includeTasksDetails, bool includeTargetDetails) { if (telemetryData == null) @@ -28,24 +28,24 @@ internal static class TelemetryDataUtils if (includeTasksDetails) { - telemetryItems.Add(new TelemetryItem("Tasks", + telemetryItems.Add(new TelemetryItem(NodeTelemetryTags.Tasks, JsonSerializer.Serialize(telemetryData.TasksExecutionData, _serializerOptions), false)); } if (includeTargetDetails) { - telemetryItems.Add(new TelemetryItem("Targets", + telemetryItems.Add(new TelemetryItem(NodeTelemetryTags.Targets, JsonSerializer.Serialize(telemetryData.TargetsExecutionData, _serializerOptions), false)); } - TargetsSummary targetsSummary = new(); - targetsSummary.Initialize(telemetryData.TargetsExecutionData); - telemetryItems.Add(new TelemetryItem("TargetsSummary", + TargetsSummaryConverter targetsSummary = new(); + targetsSummary.Process(telemetryData.TargetsExecutionData); + telemetryItems.Add(new TelemetryItem(NodeTelemetryTags.TargetsSummary, JsonSerializer.Serialize(targetsSummary, _serializerOptions), false)); - TasksSummary tasksSummary = new(); - tasksSummary.Initialize(telemetryData.TasksExecutionData); - telemetryItems.Add(new TelemetryItem("TasksSummary", + TasksSummaryConverter tasksSummary = new(); + tasksSummary.Process(telemetryData.TasksExecutionData); + telemetryItems.Add(new TelemetryItem(NodeTelemetryTags.TasksSummary, JsonSerializer.Serialize(tasksSummary, _serializerOptions), false)); return new NodeTelemetry(telemetryItems); @@ -59,17 +59,17 @@ private static JsonSerializerOptions CreateSerializerOptions() { Converters = { - new TargetDataConverter(), - new TaskDataConverter(), - new TargetsSummary(), - new TasksSummary(), + new TargetsDetailsConverter(), + new TasksDetailsConverter(), + new TargetsSummaryConverter(), + new TasksSummaryConverter(), }, }; return opt; } - private class TargetDataConverter : JsonConverter?> + private class TargetsDetailsConverter : JsonConverter?> { public override Dictionary? Read( ref Utf8JsonReader reader, @@ -89,12 +89,15 @@ public override void Write( } // Following needed - as System.Text.Json doesn't support indexing dictionary by composite types - writer.WriteStartObject(); foreach (KeyValuePair valuePair in value) { - writer.WriteStartObject(valuePair.Key.IsCustom || valuePair.Key.IsMetaProj ? ActivityExtensions.GetHashed(valuePair.Key.Name) : valuePair.Key.Name); + string keyName = ShouldHashKey(valuePair.Key) ? + ActivityExtensions.GetHashed(valuePair.Key.Name) : + valuePair.Key.Name; + + writer.WriteStartObject(keyName); writer.WriteBoolean("WasExecuted", valuePair.Value); writer.WriteBoolean(nameof(valuePair.Key.IsCustom), valuePair.Key.IsCustom); writer.WriteBoolean(nameof(valuePair.Key.IsNuget), valuePair.Key.IsNuget); @@ -104,9 +107,11 @@ public override void Write( writer.WriteEndObject(); } + + private bool ShouldHashKey(TaskOrTargetTelemetryKey key) => key.IsCustom || key.IsMetaProj; } - private class TaskDataConverter : JsonConverter?> + private class TasksDetailsConverter : JsonConverter?> { public override Dictionary? Read( ref Utf8JsonReader reader, @@ -126,17 +131,17 @@ public override void Write( } // Following needed - as System.Text.Json doesn't support indexing dictionary by composite types - writer.WriteStartObject(); foreach (KeyValuePair valuePair in value) { - writer.WriteStartObject(valuePair.Key.IsCustom ? ActivityExtensions.GetHashed(valuePair.Key.Name) : valuePair.Key.Name); - // We do not want decimals - writer.WriteNumber("ExecTimeMs", valuePair.Value.CumulativeExecutionTime.TotalMilliseconds / 1); - writer.WriteNumber("ExecCnt", valuePair.Value.ExecutionsCount); - // We do not want decimals - writer.WriteNumber("MemKBs", valuePair.Value.TotalMemoryConsumption / 1024); + string keyName = valuePair.Key.IsCustom ? + ActivityExtensions.GetHashed(valuePair.Key.Name) : + valuePair.Key.Name; + writer.WriteStartObject(keyName); + writer.WriteNumber(nameof(valuePair.Value.CumulativeExecutionTime.TotalMilliseconds), valuePair.Value.CumulativeExecutionTime.TotalMilliseconds); + writer.WriteNumber(nameof(valuePair.Value.ExecutionsCount), valuePair.Value.ExecutionsCount); + writer.WriteNumber(nameof(valuePair.Value.TotalMemoryBytes), valuePair.Value.TotalMemoryBytes); writer.WriteBoolean(nameof(valuePair.Key.IsCustom), valuePair.Key.IsCustom); writer.WriteBoolean(nameof(valuePair.Key.IsNuget), valuePair.Key.IsNuget); writer.WriteEndObject(); @@ -146,14 +151,18 @@ public override void Write( } } - private class TargetsSummary : JsonConverter + private class TargetsSummaryConverter : JsonConverter { - public void Initialize(Dictionary targetsExecutionData) + /// + /// Processes target execution data to compile summary statistics for both built-in and custom targets. + /// + /// Dictionary containing target execution data keyed by task identifiers. + public void Process(Dictionary targetsExecutionData) { - foreach (var targetPair in targetsExecutionData) + foreach (KeyValuePair targetPair in targetsExecutionData) { - var key = targetPair.Key; - var wasExecuted = targetPair.Value; + TaskOrTargetTelemetryKey key = targetPair.Key; + bool wasExecuted = targetPair.Value; // Update loaded targets statistics (all targets are loaded) UpdateTargetStatistics(key, isExecuted: false); @@ -169,11 +178,11 @@ public void Initialize(Dictionary targetsExecuti private void UpdateTargetStatistics(TaskOrTargetTelemetryKey key, bool isExecuted) { // Select the appropriate target info collections based on execution state - var builtinTargetInfo = isExecuted ? ExecutedBuiltinTargetInfo : LoadedBuiltinTargetInfo; - var customTargetInfo = isExecuted ? ExecutedCustomTargetInfo : LoadedCustomTargetInfo; + TargetInfo builtinTargetInfo = isExecuted ? ExecutedBuiltinTargetInfo : LoadedBuiltinTargetInfo; + TargetInfo customTargetInfo = isExecuted ? ExecutedCustomTargetInfo : LoadedCustomTargetInfo; // Update either custom or builtin target info based on target type - var targetInfo = key.IsCustom ? customTargetInfo : builtinTargetInfo; + TargetInfo targetInfo = key.IsCustom ? customTargetInfo : builtinTargetInfo; targetInfo.Total++; if (key.IsNuget) @@ -198,7 +207,7 @@ private class TargetInfo public int FromMetaproj { get; internal set; } } - public override TargetsSummary? Read( + public override TargetsSummaryConverter? Read( ref Utf8JsonReader reader, Type typeToConvert, JsonSerializerOptions options) => @@ -206,7 +215,7 @@ private class TargetInfo public override void Write( Utf8JsonWriter writer, - TargetsSummary value, + TargetsSummaryConverter value, JsonSerializerOptions options) { writer.WriteStartObject(); @@ -218,10 +227,9 @@ public override void Write( writer.WriteEndObject(); writer.WriteEndObject(); - - void WriteStat(Utf8JsonWriter writer, TargetInfo customTargetsInfo, TargetInfo builtinTargetsInfo) + void WriteStat(Utf8JsonWriter writer, TargetInfo builtinTargetsInfo, TargetInfo customTargetsInfo) { - writer.WriteNumber("Total", builtinTargetsInfo.Total + customTargetsInfo.Total); + writer.WriteNumber(nameof(builtinTargetsInfo.Total), builtinTargetsInfo.Total + customTargetsInfo.Total); WriteSingleStat(writer, builtinTargetsInfo, "Microsoft"); WriteSingleStat(writer, customTargetsInfo, "Custom"); } @@ -231,54 +239,56 @@ 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.WriteNumber(nameof(targetInfo.Total), targetInfo.Total); + writer.WriteNumber(nameof(targetInfo.FromNuget), targetInfo.FromNuget); + writer.WriteNumber(nameof(targetInfo.FromMetaproj), targetInfo.FromMetaproj); writer.WriteEndObject(); } } } } - - private class TasksSummary : JsonConverter + private class TasksSummaryConverter : JsonConverter { - public void Initialize(Dictionary tasksExecutionData) + /// + /// Processes task execution data to compile summary statistics for both built-in and custom tasks. + /// + /// Dictionary containing task execution data keyed by task identifiers. + public void Process(Dictionary tasksExecutionData) { - foreach (var taskInfo in tasksExecutionData) + foreach (KeyValuePair taskInfo in tasksExecutionData) { - UpdateStatistics(BuiltinTasksInfo, CustomTasksInfo, taskInfo.Key, taskInfo.Value); + UpdateTaskStatistics(BuiltinTasksInfo, CustomTasksInfo, taskInfo.Key, taskInfo.Value); } + } - void UpdateStatistics( - TasksInfo builtinTaskInfo, - TasksInfo customTaskInfo, - TaskOrTargetTelemetryKey key, - TaskExecutionStats taskExecutionStats) - { - UpdateSingleStatistics(key.IsCustom ? customTaskInfo : builtinTaskInfo, taskExecutionStats, key); + private void UpdateTaskStatistics( + TasksInfo builtinTaskInfo, + TasksInfo customTaskInfo, + TaskOrTargetTelemetryKey key, + TaskExecutionStats taskExecutionStats) + { + TasksInfo taskInfo = key.IsCustom ? customTaskInfo : builtinTaskInfo; + taskInfo.Total.Accumulate(taskExecutionStats); - void UpdateSingleStatistics(TasksInfo summarizedTaskInfo, TaskExecutionStats infoToAdd, TaskOrTargetTelemetryKey key) - { - summarizedTaskInfo.Total.Accumulate(infoToAdd); - if (key.IsNuget) - { - summarizedTaskInfo.FromNuget.Accumulate(infoToAdd); - } - } + if (key.IsNuget) + { + taskInfo.FromNuget.Accumulate(taskExecutionStats); } } 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( + public override TasksSummaryConverter? Read( ref Utf8JsonReader reader, Type typeToConvert, JsonSerializerOptions options) => @@ -286,7 +296,7 @@ private class TasksInfo public override void Write( Utf8JsonWriter writer, - TasksSummary value, + TasksSummaryConverter value, JsonSerializerOptions options) { writer.WriteStartObject(); @@ -297,8 +307,8 @@ public override void Write( void WriteStat(Utf8JsonWriter writer, TasksInfo tasksInfo, string name) { writer.WriteStartObject(name); - WriteSingleStat(writer, tasksInfo.Total, "Total"); - WriteSingleStat(writer, tasksInfo.FromNuget, "FromNuget"); + WriteSingleStat(writer, tasksInfo.Total, nameof(tasksInfo.Total)); + WriteSingleStat(writer, tasksInfo.FromNuget, nameof(tasksInfo.FromNuget)); writer.WriteEndObject(); } @@ -307,11 +317,9 @@ void WriteSingleStat(Utf8JsonWriter writer, TaskExecutionStats stats, string nam if (stats.ExecutionsCount > 0) { writer.WriteStartObject(name); - writer.WriteNumber("TotalExecutionsCount", stats.ExecutionsCount); - // We do not want decimals - writer.WriteNumber("CumulativeExecutionTimeMs", (long)stats.CumulativeExecutionTime.TotalMilliseconds); - // We do not want decimals - writer.WriteNumber("CumulativeConsumedMemoryKB", stats.TotalMemoryConsumption / 1024); + writer.WriteNumber(nameof(stats.ExecutionsCount), stats.ExecutionsCount); + writer.WriteNumber(nameof(stats.CumulativeExecutionTime.TotalMilliseconds), stats.CumulativeExecutionTime.TotalMilliseconds); + writer.WriteNumber(nameof(stats.TotalMemoryBytes), stats.TotalMemoryBytes); writer.WriteEndObject(); } } diff --git a/src/Framework.UnitTests/WorkerNodeTelemetryEventArgs_Tests.cs b/src/Framework.UnitTests/WorkerNodeTelemetryEventArgs_Tests.cs index 57d822d7194..bf5303e2c09 100644 --- a/src/Framework.UnitTests/WorkerNodeTelemetryEventArgs_Tests.cs +++ b/src/Framework.UnitTests/WorkerNodeTelemetryEventArgs_Tests.cs @@ -9,6 +9,7 @@ using System.Threading.Tasks; using Shouldly; using Xunit; +using Microsoft.Build.Framework.Telemetry; namespace Microsoft.Build.Framework.UnitTests { diff --git a/src/Framework/Telemetry/TaskExecutionStats.cs b/src/Framework/Telemetry/TaskExecutionStats.cs index 06e75f68224..533599734fd 100644 --- a/src/Framework/Telemetry/TaskExecutionStats.cs +++ b/src/Framework/Telemetry/TaskExecutionStats.cs @@ -6,17 +6,18 @@ namespace Microsoft.Build.Framework.Telemetry; /// -/// Represents the stats of tasks executed on a node. +/// Represents the execution statistics of tasks executed on a node. /// internal class TaskExecutionStats(TimeSpan cumulativeExecutionTime, int executionsCount, long totalMemoryConsumption) { private TaskExecutionStats() : this(TimeSpan.Zero, 0, 0) { } + /// - /// Creates an instance of initialized to 0s. + /// Creates an instance of initialized to zero values. /// - /// Empty stats. + /// Empty task execution statistics. internal static TaskExecutionStats CreateEmpty() => new(); @@ -28,22 +29,22 @@ internal static TaskExecutionStats CreateEmpty() /// /// Total memory consumption (across all executions) in bytes. /// - public long TotalMemoryConsumption { get; set; } = totalMemoryConsumption; + public long TotalMemoryBytes { get; set; } = totalMemoryConsumption; /// - /// Total number of execution of the tasks in all nodes for all projects. + /// Total number of executions of the task. /// public int ExecutionsCount { get; set; } = executionsCount; /// - /// Merges stats from another node to this instance. + /// Accumulates statistics from another instance into this one. /// - /// Stats from another node. - internal void Accumulate(TaskExecutionStats another) + /// Statistics to add to this instance. + internal void Accumulate(TaskExecutionStats other) { - this.CumulativeExecutionTime += another.CumulativeExecutionTime; - this.TotalMemoryConsumption += another.TotalMemoryConsumption; - this.ExecutionsCount += another.ExecutionsCount; + this.CumulativeExecutionTime += other.CumulativeExecutionTime; + this.TotalMemoryBytes += other.TotalMemoryBytes; + this.ExecutionsCount += other.ExecutionsCount; } // We need custom Equals for easier assertions in tests @@ -58,7 +59,7 @@ public override bool Equals(object? obj) protected bool Equals(TaskExecutionStats other) => CumulativeExecutionTime.Equals(other.CumulativeExecutionTime) && - TotalMemoryConsumption == other.TotalMemoryConsumption && + TotalMemoryBytes == other.TotalMemoryBytes && ExecutionsCount == other.ExecutionsCount; // Needed since we override Equals @@ -67,7 +68,7 @@ public override int GetHashCode() unchecked { var hashCode = CumulativeExecutionTime.GetHashCode(); - hashCode = (hashCode * 397) ^ TotalMemoryConsumption.GetHashCode(); + hashCode = (hashCode * 397) ^ TotalMemoryBytes.GetHashCode(); hashCode = (hashCode * 397) ^ ExecutionsCount.GetHashCode(); return hashCode; } diff --git a/src/Framework/Telemetry/TaskOrTargetTelemetryKey.cs b/src/Framework/Telemetry/TaskOrTargetTelemetryKey.cs index e687ac79402..cc46591dc2d 100644 --- a/src/Framework/Telemetry/TaskOrTargetTelemetryKey.cs +++ b/src/Framework/Telemetry/TaskOrTargetTelemetryKey.cs @@ -5,8 +5,21 @@ namespace Microsoft.Build.Framework.Telemetry; +/// +/// Represents a unique key for task or target telemetry data. +/// +/// +/// Used as a dictionary key for tracking execution metrics of tasks and targets. +/// internal struct TaskOrTargetTelemetryKey : IEquatable { + /// + /// Initializes a new instance of the struct with all properties. + /// + /// The name of the task or target. + /// Indicates whether the task/target is custom. + /// Indicates whether the task/target is from NuGet cache. + /// Indicates whether the task/target is from a meta project. public TaskOrTargetTelemetryKey(string name, bool isCustom, bool isFromNugetCache, bool isFromMetaProject) { Name = name; @@ -15,21 +28,44 @@ public TaskOrTargetTelemetryKey(string name, bool isCustom, bool isFromNugetCach IsMetaProj = isFromMetaProject; } + /// + /// Initializes a new instance of the struct without meta project flag. + /// + /// The name of the task or target. + /// Indicates whether the task/target is custom. + /// Indicates whether the task/target is from NuGet cache. public TaskOrTargetTelemetryKey(string name, bool isCustom, bool isFromNugetCache) { Name = name; IsCustom = isCustom; IsNuget = isFromNugetCache; + IsMetaProj = false; } - public TaskOrTargetTelemetryKey(string name) => Name = name; + /// + /// Initializes a new instance of the struct with name only. + /// + /// The name of the task or target. + public TaskOrTargetTelemetryKey(string name) : this(name, false, false, false) { } + /// + /// Enables explicit casting from string to . + /// + /// The string name to convert to a telemetry key. + /// A telemetry key with the given name. public static explicit operator TaskOrTargetTelemetryKey(string key) => new(key); + /// + /// Gets the name of the task or target. + /// + /// + /// This name is used as the primary key in serialized JSON data. + /// It is hashed when the task/target is custom or from a meta project. + /// public string Name { get; } /// - /// Indicate custom targets/task - those must be hashed. + /// Gets a value indicating whether this task/target is custom. /// public bool IsCustom { get; } diff --git a/src/Framework/Telemetry/TelemetryConstants.cs b/src/Framework/Telemetry/TelemetryConstants.cs index 87df7c68e1c..f373760de7c 100644 --- a/src/Framework/Telemetry/TelemetryConstants.cs +++ b/src/Framework/Telemetry/TelemetryConstants.cs @@ -48,3 +48,12 @@ internal static class TelemetryConstants /// public const string InnerBuildDurationPropertyName = "InnerBuildDurationInMilliseconds"; } + +internal static class NodeTelemetryTags +{ + // These properties can't use nameof since they're not tied to a specific class property + public const string Tasks = "Tasks"; + public const string Targets = "Targets"; + public const string TargetsSummary = "TargetsSummary"; + public const string TasksSummary = "TasksSummary"; +} diff --git a/src/Framework/Telemetry/WorkerNodeTelemetryData.cs b/src/Framework/Telemetry/WorkerNodeTelemetryData.cs index aa36448c533..d643045ffe6 100644 --- a/src/Framework/Telemetry/WorkerNodeTelemetryData.cs +++ b/src/Framework/Telemetry/WorkerNodeTelemetryData.cs @@ -18,7 +18,7 @@ public void Add(IWorkerNodeTelemetryData other) { foreach (var task in other.TasksExecutionData) { - AddTask(task.Key, task.Value.CumulativeExecutionTime, task.Value.ExecutionsCount, task.Value.TotalMemoryConsumption); + AddTask(task.Key, task.Value.CumulativeExecutionTime, task.Value.ExecutionsCount, task.Value.TotalMemoryBytes); } foreach (var target in other.TargetsExecutionData) @@ -39,7 +39,7 @@ public void AddTask(TaskOrTargetTelemetryKey task, TimeSpan cumulativeExectionTi { taskExecutionStats.CumulativeExecutionTime += cumulativeExectionTime; taskExecutionStats.ExecutionsCount += executionsCount; - taskExecutionStats.TotalMemoryConsumption += totalMemoryConsumption; + taskExecutionStats.TotalMemoryBytes += totalMemoryConsumption; } } diff --git a/src/Framework/Telemetry/WorkerNodeTelemetryEventArgs.cs b/src/Framework/Telemetry/WorkerNodeTelemetryEventArgs.cs index 7fd80fa4ea8..a2a11f16e82 100644 --- a/src/Framework/Telemetry/WorkerNodeTelemetryEventArgs.cs +++ b/src/Framework/Telemetry/WorkerNodeTelemetryEventArgs.cs @@ -24,7 +24,7 @@ internal override void WriteToStream(BinaryWriter writer) WriteToStream(writer, entry.Key); writer.Write(entry.Value.CumulativeExecutionTime.Ticks); writer.Write(entry.Value.ExecutionsCount); - writer.Write(entry.Value.TotalMemoryConsumption); + writer.Write(entry.Value.TotalMemoryBytes); } writer.Write7BitEncodedInt(WorkerNodeTelemetryData.TargetsExecutionData.Count); From f54f033294b817fea96c42b749d26d987961d954 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jan=20Provazn=C3=ADk?= Date: Mon, 17 Mar 2025 14:10:56 +0100 Subject: [PATCH 05/10] fix env setup in test --- src/Build.UnitTests/Telemetry/OpenTelemetryManager_Tests.cs | 4 +++- src/Build.UnitTests/Telemetry/Telemetry_Tests.cs | 1 + 2 files changed, 4 insertions(+), 1 deletion(-) diff --git a/src/Build.UnitTests/Telemetry/OpenTelemetryManager_Tests.cs b/src/Build.UnitTests/Telemetry/OpenTelemetryManager_Tests.cs index 38f3a27b859..8b470b602fa 100644 --- a/src/Build.UnitTests/Telemetry/OpenTelemetryManager_Tests.cs +++ b/src/Build.UnitTests/Telemetry/OpenTelemetryManager_Tests.cs @@ -51,12 +51,13 @@ public void Initialize_ShouldSetStateToOptOut_WhenOptOutEnvVarIsTrue(string opto OpenTelemetryManager.Instance.IsActive().ShouldBeFalse(); } -#if NET +#if NETCOREAPP [Fact] public void Initialize_ShouldSetStateToUnsampled_WhenNoOverrideOnNetCore() { using TestEnvironment environment = TestEnvironment.Create(); environment.SetEnvironmentVariable(TelemetrySampleRateOverrideEnvVarName, null); + environment.SetEnvironmentVariable(DotnetOptOut, null); OpenTelemetryManager.Instance.Initialize(isStandalone: false); @@ -74,6 +75,7 @@ public void Initialize_ShouldSetSampleRateOverride_AndCreateActivitySource_WhenR using TestEnvironment environment = TestEnvironment.Create(); environment.SetEnvironmentVariable(VS1714TelemetryOptInEnvVarName, "1"); environment.SetEnvironmentVariable(TelemetrySampleRateOverrideEnvVarName, "1.0"); + environment.SetEnvironmentVariable(DotnetOptOut, null); // Act OpenTelemetryManager.Instance.Initialize(isStandalone: standalone); diff --git a/src/Build.UnitTests/Telemetry/Telemetry_Tests.cs b/src/Build.UnitTests/Telemetry/Telemetry_Tests.cs index 49f1782aa7c..6939eda86e5 100644 --- a/src/Build.UnitTests/Telemetry/Telemetry_Tests.cs +++ b/src/Build.UnitTests/Telemetry/Telemetry_Tests.cs @@ -17,6 +17,7 @@ namespace Microsoft.Build.Engine.UnitTests { + [Collection("OpenTelemetryManagerTests")] public class Telemetry_Tests { private readonly ITestOutputHelper _output; From 3bd4402342630648bcd6828f68ba6e108b7ead0a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jan=20Provazn=C3=ADk?= Date: Thu, 20 Mar 2025 16:44:01 +0100 Subject: [PATCH 06/10] when parsing env variable force . as a decimal separator --- src/Framework/Traits.cs | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) diff --git a/src/Framework/Traits.cs b/src/Framework/Traits.cs index a19ff522759..32557ee22d7 100644 --- a/src/Framework/Traits.cs +++ b/src/Framework/Traits.cs @@ -163,9 +163,15 @@ private static int ParseIntFromEnvironmentVariableOrDefault(string environmentVa : defaultValue; } + /// + /// Parse a double from an environment variable with invariant culture. + /// private static double? ParseDoubleFromEnvironmentVariable(string environmentVariable) { - return double.TryParse(Environment.GetEnvironmentVariable(environmentVariable), out double result) + return double.TryParse(Environment.GetEnvironmentVariable(environmentVariable), + NumberStyles.Float, + CultureInfo.InvariantCulture, + out double result) ? result : null; } From def77c1773af55b01beed0e47744935645c0e34f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jan=20Provazn=C3=ADk?= Date: Thu, 20 Mar 2025 18:33:39 +0100 Subject: [PATCH 07/10] log telemetry load failure --- .../Telemetry/OpenTelemetryManager_Tests.cs | 22 +++++++++++++++++++ .../BackEnd/BuildManager/BuildManager.cs | 22 ++++++++++++++++++- src/Build/Resources/Strings.resx | 3 +++ src/Build/Resources/xlf/Strings.cs.xlf | 5 +++++ src/Build/Resources/xlf/Strings.de.xlf | 5 +++++ src/Build/Resources/xlf/Strings.es.xlf | 5 +++++ src/Build/Resources/xlf/Strings.fr.xlf | 5 +++++ src/Build/Resources/xlf/Strings.it.xlf | 5 +++++ src/Build/Resources/xlf/Strings.ja.xlf | 5 +++++ src/Build/Resources/xlf/Strings.ko.xlf | 5 +++++ src/Build/Resources/xlf/Strings.pl.xlf | 5 +++++ src/Build/Resources/xlf/Strings.pt-BR.xlf | 5 +++++ src/Build/Resources/xlf/Strings.ru.xlf | 5 +++++ src/Build/Resources/xlf/Strings.tr.xlf | 5 +++++ src/Build/Resources/xlf/Strings.zh-Hans.xlf | 5 +++++ src/Build/Resources/xlf/Strings.zh-Hant.xlf | 5 +++++ .../Telemetry/OpenTelemetryManager.cs | 3 +++ 17 files changed, 114 insertions(+), 1 deletion(-) diff --git a/src/Build.UnitTests/Telemetry/OpenTelemetryManager_Tests.cs b/src/Build.UnitTests/Telemetry/OpenTelemetryManager_Tests.cs index 8b470b602fa..66e5f4e7013 100644 --- a/src/Build.UnitTests/Telemetry/OpenTelemetryManager_Tests.cs +++ b/src/Build.UnitTests/Telemetry/OpenTelemetryManager_Tests.cs @@ -9,6 +9,10 @@ using Microsoft.Build.UnitTests.Shared; using Microsoft.Build.UnitTests; using Microsoft.Build.Framework.Telemetry; +using Microsoft.Build.Execution; +using Microsoft.Build.Framework; +using System.Collections.Generic; +using System.Linq; namespace Microsoft.Build.Engine.UnitTests.Telemetry { @@ -102,6 +106,24 @@ public void Initialize_ShouldNoOp_WhenCalledMultipleTimes() state2.ShouldBe(false); } + [Fact] + public void TelemetryLoadFailureIsLoggedOnce() + { + OpenTelemetryManager.Instance.Initialize(isStandalone: false); + OpenTelemetryManager.Instance.LoadFailureExceptionMessage = new System.IO.FileNotFoundException().ToString(); + BuildManager bm = BuildManager.DefaultBuildManager; + var deferredMessages = new List(); + bm.BeginBuild(new BuildParameters(), deferredMessages); + deferredMessages.ShouldContain(x => x.Text.Contains("FileNotFound")); + bm.EndBuild(); + bm.BeginBuild(new BuildParameters()); + + // should not add message twice + int count = deferredMessages.Count(x => x.Text.Contains("FileNotFound")); + count.ShouldBe(1); + } + + /* Helper methods */ /// diff --git a/src/Build/BackEnd/BuildManager/BuildManager.cs b/src/Build/BackEnd/BuildManager/BuildManager.cs index bafe972c446..1c922ef9fdd 100644 --- a/src/Build/BackEnd/BuildManager/BuildManager.cs +++ b/src/Build/BackEnd/BuildManager/BuildManager.cs @@ -459,7 +459,8 @@ private void UpdatePriority(Process p, ProcessPriorityClass priority) /// Thrown if a build is already in progress. public void BeginBuild(BuildParameters parameters) { - OpenTelemetryManager.Instance.Initialize(isStandalone: false); + InitializeTelemetry(); + if (_previousLowPriority != null) { if (parameters.LowPriority != _previousLowPriority) @@ -723,6 +724,25 @@ void InitializeCaches() } } + private void InitializeTelemetry() + { + OpenTelemetryManager.Instance.Initialize(isStandalone: false); + if (_deferredBuildMessages != null && + OpenTelemetryManager.Instance.LoadFailureExceptionMessage != null && + _deferredBuildMessages is ICollection deferredBuildMessagesCollection) + { + deferredBuildMessagesCollection.Add( + new DeferredBuildMessage( + ResourceUtilities.FormatResourceStringIgnoreCodeAndKeyword( + "OpenTelemetryLoadFailed", + OpenTelemetryManager.Instance.LoadFailureExceptionMessage), + MessageImportance.Low)); + + // clean up the message from OpenTelemetryManager to avoid double logging it + OpenTelemetryManager.Instance.LoadFailureExceptionMessage = null; + } + } + #if FEATURE_REPORTFILEACCESSES /// /// Configure the build to use I/O tracking for nodes. diff --git a/src/Build/Resources/Strings.resx b/src/Build/Resources/Strings.resx index 128cf7283c0..5c1da33c2e6 100644 --- a/src/Build/Resources/Strings.resx +++ b/src/Build/Resources/Strings.resx @@ -2386,6 +2386,9 @@ Utilization: {0} Average Utilization: {1:###.0} succeeded: {0} {0} whole number + + Loading telemetry libraries failed with exception: {0}. +