File: Telemetry\Telemetry_Tests.cs
Web Access
Project: ..\..\..\src\Build.UnitTests\Microsoft.Build.Engine.UnitTests.csproj (Microsoft.Build.Engine.UnitTests)
// 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.Diagnostics;
using System.Linq;
#if NET
using System.Text.Json;
#endif
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;
using Xunit.Abstractions;
 
namespace Microsoft.Build.Engine.UnitTests
{
    [Collection("OpenTelemetryManagerTests")]
    public class Telemetry_Tests
    {
        private readonly ITestOutputHelper _output;
 
        public Telemetry_Tests(ITestOutputHelper output)
        {
            _output = output;
        }
 
        private sealed class ProjectFinishedCapturingLogger : ILogger
        {
            private readonly List<ProjectFinishedEventArgs> _projectFinishedEventArgs = [];
            public LoggerVerbosity Verbosity { get; set; }
            public string? Parameters { get; set; }
 
            public IReadOnlyList<ProjectFinishedEventArgs> ProjectFinishedEventArgsReceived =>
                _projectFinishedEventArgs;
 
            public void Initialize(IEventSource eventSource)
            {
                eventSource.ProjectFinished += EventSource_ProjectFinished;
            }
 
            private void EventSource_ProjectFinished(object sender, ProjectFinishedEventArgs e)
            {
                _projectFinishedEventArgs.Add(e);
            }
 
            public void Shutdown()
            { }
        }
 
        [Fact]
        public void WorkerNodeTelemetryCollection_BasicTarget()
        {
            WorkerNodeTelemetryData? workerNodeTelemetryData = null;
            InternalTelemetryConsumingLogger.TestOnly_InternalTelemetryAggregted += dt => workerNodeTelemetryData = dt;
 
            var testProject = """
                                      <Project>
                                          <Target Name="Build">
                                              <Message Text="Hello World"/>
                                              <CreateItem Include="foo.bar">
                                                  <Output TaskParameter="Include" ItemName="I" />
                                              </CreateItem>
                                              <Message Text="Bye World"/>
                                          </Target>
                                      </Project>
                              """;
 
            MockLogger logger = new MockLogger(_output);
            Helpers.BuildProjectContentUsingBuildManager(testProject, logger,
                new BuildParameters() { IsTelemetryEnabled = true }).OverallResult.ShouldBe(BuildResultCode.Success);
 
            workerNodeTelemetryData!.ShouldNotBeNull();
            var buildTargetKey = new TaskOrTargetTelemetryKey("Build", true, false);
            workerNodeTelemetryData.TargetsExecutionData.ShouldContainKey(buildTargetKey);
            workerNodeTelemetryData.TargetsExecutionData[buildTargetKey].ShouldBeTrue();
            workerNodeTelemetryData.TargetsExecutionData.Keys.Count.ShouldBe(1);
 
            workerNodeTelemetryData.TasksExecutionData.Keys.Count.ShouldBeGreaterThan(2);
            ((int)workerNodeTelemetryData.TasksExecutionData[(TaskOrTargetTelemetryKey)"Microsoft.Build.Tasks.Message"].ExecutionsCount).ShouldBe(2);
            workerNodeTelemetryData.TasksExecutionData[(TaskOrTargetTelemetryKey)"Microsoft.Build.Tasks.Message"].CumulativeExecutionTime.ShouldBeGreaterThan(TimeSpan.Zero);
            ((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.IsNuget);
            workerNodeTelemetryData.TasksExecutionData.Values
                .Count(v => v.CumulativeExecutionTime > TimeSpan.Zero || v.ExecutionsCount > 0).ShouldBe(2);
        }
 
        [Fact]
        public void WorkerNodeTelemetryCollection_CustomTargetsAndTasks()
        {
            WorkerNodeTelemetryData? workerNodeTelemetryData = null;
            InternalTelemetryConsumingLogger.TestOnly_InternalTelemetryAggregted += dt => workerNodeTelemetryData = dt;
 
            var testProject = """
                                      <Project>
                                      <UsingTask
                                          TaskName="Task01"
                                          TaskFactory="RoslynCodeTaskFactory"
                                          AssemblyFile="$(MSBuildToolsPath)\Microsoft.Build.Tasks.Core.dll" >
                                          <ParameterGroup />
                                          <Task>
                                            <Code Type="Fragment" Language="cs">
                                              Log.LogMessage(MessageImportance.Low, "Hello, world!");
                                            </Code>
                                          </Task>
                                       </UsingTask>
 
                                       <UsingTask
                                         TaskName="Task02"
                                         TaskFactory="RoslynCodeTaskFactory"
                                         AssemblyFile="$(MSBuildToolsPath)\Microsoft.Build.Tasks.Core.dll" >
                                         <ParameterGroup />
                                         <Task>
                                           <Code Type="Fragment" Language="cs">
                                             Log.LogMessage(MessageImportance.High, "Hello, world!");
                                           </Code>
                                         </Task>
                                      </UsingTask>
 
                                          <Target Name="Build" DependsOnTargets="BeforeBuild">
                                              <Message Text="Hello World"/>
                                              <CreateItem Include="foo.bar">
                                                  <Output TaskParameter="Include" ItemName="I" />
                                              </CreateItem>
                                              <Task01 />
                                              <Message Text="Bye World"/>
                                          </Target>
 
                                          <Target Name="BeforeBuild">
                                              <Message Text="Hello World"/>
                                              <Task01 />
                                          </Target>
 
                                          <Target Name="NotExecuted">
                                              <Message Text="Hello World"/>
                                          </Target>
                                      </Project>
                              """;
            MockLogger logger = new MockLogger(_output);
            Helpers.BuildProjectContentUsingBuildManager(testProject, logger,
                new BuildParameters() { IsTelemetryEnabled = true }).OverallResult.ShouldBe(BuildResultCode.Success);
 
            workerNodeTelemetryData!.ShouldNotBeNull();
            workerNodeTelemetryData.TargetsExecutionData.ShouldContainKey(new TaskOrTargetTelemetryKey("Build", true, false));
            workerNodeTelemetryData.TargetsExecutionData[new TaskOrTargetTelemetryKey("Build", true, false)].ShouldBeTrue();
            workerNodeTelemetryData.TargetsExecutionData.ShouldContainKey(new TaskOrTargetTelemetryKey("BeforeBuild", true, false));
            workerNodeTelemetryData.TargetsExecutionData[new TaskOrTargetTelemetryKey("BeforeBuild", true, false)].ShouldBeTrue();
            workerNodeTelemetryData.TargetsExecutionData.ShouldContainKey(new TaskOrTargetTelemetryKey("NotExecuted", true, false));
            workerNodeTelemetryData.TargetsExecutionData[new TaskOrTargetTelemetryKey("NotExecuted", true, false)].ShouldBeFalse();
            workerNodeTelemetryData.TargetsExecutionData.Keys.Count.ShouldBe(3);
 
            workerNodeTelemetryData.TasksExecutionData.Keys.Count.ShouldBeGreaterThan(2);
            ((int)workerNodeTelemetryData.TasksExecutionData[(TaskOrTargetTelemetryKey)"Microsoft.Build.Tasks.Message"].ExecutionsCount).ShouldBe(3);
            workerNodeTelemetryData.TasksExecutionData[(TaskOrTargetTelemetryKey)"Microsoft.Build.Tasks.Message"].CumulativeExecutionTime.ShouldBeGreaterThan(TimeSpan.Zero);
            ((int)workerNodeTelemetryData.TasksExecutionData[(TaskOrTargetTelemetryKey)"Microsoft.Build.Tasks.CreateItem"].ExecutionsCount).ShouldBe(1);
            workerNodeTelemetryData.TasksExecutionData[(TaskOrTargetTelemetryKey)"Microsoft.Build.Tasks.CreateItem"].CumulativeExecutionTime.ShouldBeGreaterThan(TimeSpan.Zero);
 
            ((int)workerNodeTelemetryData.TasksExecutionData[new TaskOrTargetTelemetryKey("Task01", true, false)].ExecutionsCount).ShouldBe(2);
            workerNodeTelemetryData.TasksExecutionData[new TaskOrTargetTelemetryKey("Task01", true, false)].CumulativeExecutionTime.ShouldBeGreaterThan(TimeSpan.Zero);
 
            ((int)workerNodeTelemetryData.TasksExecutionData[new TaskOrTargetTelemetryKey("Task02", true, false)].ExecutionsCount).ShouldBe(0);
            workerNodeTelemetryData.TasksExecutionData[new TaskOrTargetTelemetryKey("Task02", true, false)].CumulativeExecutionTime.ShouldBe(TimeSpan.Zero);
 
            workerNodeTelemetryData.TasksExecutionData.Values
                .Count(v => v.CumulativeExecutionTime > TimeSpan.Zero || v.ExecutionsCount > 0).ShouldBe(3);
 
            workerNodeTelemetryData.TasksExecutionData.Keys.ShouldAllBe(k => !k.IsNuget);
        }
 
#if NET
        // test in .net core with opentelemetry opted in to avoid sending it but enable listening to it
        [Fact]
        public void NodeTelemetryE2E()
        {
            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<Activity>();
            using var listener = new ActivityListener
            {
                ShouldListenTo = source => source.Name.StartsWith(TelemetryConstants.DefaultActivitySourceNamespace),
                Sample = (ref ActivityCreationOptions<ActivityContext> _) => ActivitySamplingResult.AllData,
                ActivityStarted = capturedActivities.Add,
                ActivityStopped = _ => { }
            };
            ActivitySource.AddActivityListener(listener);
 
            var testProject = @"
            <Project>
                <Target Name='Build'>
                    <Message Text='Start'/>
                    <CreateItem Include='test.txt'>
                        <Output TaskParameter='Include' ItemName='TestItem' />
                    </CreateItem>
                    <Message Text='End'/>
                </Target>
                <Target Name='Clean'>
                    <Message Text='Cleaning...'/>
                </Target>
            </Project>";
 
            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<string, string?>(),
                    null,
                    new[] { "Build" },
                    null);
 
                buildManager.BuildRequest(buildRequestData1);
 
                var buildRequestData2 = new BuildRequestData(
                    projectFile,
                    new Dictionary<string, string?>(),
                    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.ShouldNotBeNullOrEmpty();
                tasksJson.ShouldContain("Microsoft.Build.Tasks.Message");
                tasksJson.ShouldContain("Microsoft.Build.Tasks.CreateItem");
 
                // Parse tasks data for detailed assertions
                var tasksData = JsonSerializer.Deserialize<JsonElement>(tasksJson);
 
                // Verify Message task execution metrics - updated for object structure
                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).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");
                var targetsSummaryJson = tags["VS.MSBuild.TargetsSummary"];
                targetsSummaryJson.ShouldNotBeNullOrEmpty();
                var targetsSummary = JsonSerializer.Deserialize<JsonElement>(targetsSummaryJson);
 
                // 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);
 
                // Verify Tasks summary information
                tags.ShouldContainKey("VS.MSBuild.TasksSummary");
                var tasksSummaryJson = tags["VS.MSBuild.TasksSummary"];
                tasksSummaryJson.ShouldNotBeNullOrEmpty();
                var tasksSummary = JsonSerializer.Deserialize<JsonElement>(tasksSummaryJson);
 
                // 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);
            }
        }
 
#endif
    }
}