Collecting some build data for tasks/targets telemetry

src/Build.UnitTests/BackEnd/MockLoggingService.cs

@@ -586,6 +586,10 @@ public void LogProjectFinished(BuildEventContext projectBuildEventContext, strin
         {
         }
 
+        public void LogProjectFinished(BuildEventContext projectBuildEventContext, ProjectBuildStats projectBuildStats, string projectFile, bool success)
+        {
+        }
+
         /// <summary>
         /// Logs a target started event
         /// </summary>

src/Build.UnitTests/TelemetryTests.cs

@@ -0,0 +1,167 @@
+// 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.Linq;
+using Microsoft.Build.Execution;
+using Microsoft.Build.Experimental.BuildCheck;
+using Microsoft.Build.Framework;
+using Microsoft.Build.UnitTests;
+using Shouldly;
+using Xunit;
+
+namespace Microsoft.Build.Engine.UnitTests
+{
+    public class TelemetryTests
+    {
+        public TelemetryTests()
+        {
+            ProjectBuildStats.DurationThresholdForTopN = TimeSpan.Zero;
+        }
+
+        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()
+        {
+            var tstLogger = new ProjectFinishedCapturingLogger();
+            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>
+                """;
+            Helpers.BuildProjectContentUsingBuildManager(testProject, tstLogger,
+                new BuildParameters() { IsTelemetryEnabled = true }).OverallResult.ShouldBe(BuildResultCode.Success);
+
+            tstLogger.ProjectFinishedEventArgsReceived.Count.ShouldBe(1);
+            ProjectBuildStats? stats = tstLogger.ProjectFinishedEventArgsReceived[0].ProjectBuildStats;
+            stats.ShouldNotBeNull();
+            ((int)stats.CustomTargetsCount).ShouldBe(1);
+            ((int)stats.ExecutedCustomTargetsCount).ShouldBe(1);
+            ((int)stats.TotalTargetsCount).ShouldBe(1);
+            ((int)stats.ExecutedCustomTargetsCount).ShouldBe(1);
+
+            ((int)stats.TotalTasksCount).ShouldBeGreaterThan(2);
+            ((int)stats.TotalTasksExecutionsCount).ShouldBe(3);
+            ((int)stats.TotalExecutedTasksCount).ShouldBe(2);
+            ((int)stats.CustomTasksCount).ShouldBe(0);
+            ((int)stats.CustomTasksExecutionsCount).ShouldBe(0);
+            ((int)stats.ExecutedCustomTasksCount).ShouldBe(0);
+            stats.TotalTasksExecution.ShouldBeGreaterThan(TimeSpan.Zero);
+            stats.TotalCustomTasksExecution.ShouldBe(TimeSpan.Zero);
+
+            stats.TopTasksByCumulativeExecution.Count.ShouldNotBe(0);
+            foreach (var st in stats.TopTasksByCumulativeExecution)
+            {
+                st.Key.ShouldBeGreaterThan(TimeSpan.Zero);
+                (st.Value.EndsWith("Message") || st.Value.EndsWith("CreateItem")).ShouldBeTrue($"Only specified tasks expected. Encountered: {st.Value}");
+            }
+        }
+
+        [Fact]
+        public void WorkerNodeTelemetryCollection_CustomTargetsAndTasks()
+        {
+            var tstLogger = new ProjectFinishedCapturingLogger();
+            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>
+                              """;
+            Helpers.BuildProjectContentUsingBuildManager(testProject, tstLogger,
+                new BuildParameters() { IsTelemetryEnabled = true }).OverallResult.ShouldBe(BuildResultCode.Success);
+
+            tstLogger.ProjectFinishedEventArgsReceived.Count.ShouldBe(1);
+            ProjectBuildStats? stats = tstLogger.ProjectFinishedEventArgsReceived[0].ProjectBuildStats;
+            stats.ShouldNotBeNull();
+            ((int)stats.CustomTargetsCount).ShouldBe(3);
+            ((int)stats.ExecutedCustomTargetsCount).ShouldBe(2);
+            ((int)stats.TotalTargetsCount).ShouldBe(3);
+            ((int)stats.ExecutedCustomTargetsCount).ShouldBe(2);
+
+            ((int)stats.TotalTasksCount).ShouldBeGreaterThan(2);
+            ((int)stats.TotalTasksExecutionsCount).ShouldBe(6);
+            ((int)stats.TotalExecutedTasksCount).ShouldBe(3);
+            ((int)stats.CustomTasksCount).ShouldBe(2);
+            ((int)stats.CustomTasksExecutionsCount).ShouldBe(2);
+            ((int)stats.ExecutedCustomTasksCount).ShouldBe(1);
+            stats.TotalTasksExecution.ShouldBeGreaterThan(TimeSpan.Zero);
+            stats.TotalCustomTasksExecution.ShouldBeGreaterThan(TimeSpan.Zero);
+
+            stats.TopTasksByCumulativeExecution.Count.ShouldNotBe(0);
+            foreach (var st in stats.TopTasksByCumulativeExecution)
+            {
+                st.Key.ShouldBeGreaterThan(TimeSpan.Zero);
+                (st.Value.EndsWith("Message") || st.Value.EndsWith("CreateItem") || st.Value.EndsWith("Task01")).ShouldBeTrue($"Only specified tasks expected. Encountered: {st.Value}");
+            }
+            stats.TopTasksByCumulativeExecution.Any(t => t.Value.Equals("Custom:Task01")).ShouldBeTrue($"Expected to encounter custom task. Tasks: {stats.TopTasksByCumulativeExecution.Select(t => t.Value).ToCsvString()}");
+        }
+    }
+}

src/Build/BackEnd/BuildManager/BuildParameters.cs

@@ -211,6 +211,8 @@ public class BuildParameters : ITranslatable
 
         private bool _isBuildCheckEnabled;
 
+        private bool _isTelemetryEnabled;
+
         /// <summary>
         /// The settings used to load the project under build
         /// </summary>
@@ -314,6 +316,7 @@ internal BuildParameters(BuildParameters other, bool resetEnvironment = false)
             LowPriority = other.LowPriority;
             Question = other.Question;
             IsBuildCheckEnabled = other.IsBuildCheckEnabled;
+            IsTelemetryEnabled = other.IsTelemetryEnabled;
             ProjectCacheDescriptor = other.ProjectCacheDescriptor;
         }
 
@@ -848,6 +851,17 @@ public bool IsBuildCheckEnabled
             set => _isBuildCheckEnabled = value;
         }
 
+        /// <summary>
+        /// Gets or sets an indication if telemetry is enabled.
+        /// This is reserved for future usage - we will likely add a whole dictionary of enablement per telemetry namespace
+        ///  as we plan to have variable sampling rate per various sources.
+        /// </summary>
+        internal bool IsTelemetryEnabled
+        {
+            get => _isTelemetryEnabled;
+            set => _isTelemetryEnabled = value;
+        }
+
         /// <summary>
         /// Gets or sets the project cache description to use for all <see cref="BuildSubmission"/> or <see cref="GraphBuildSubmission"/>
         /// in addition to any potential project caches described in each project.
@@ -913,6 +927,7 @@ void ITranslatable.Translate(ITranslator translator)
             translator.Translate(ref _interactive);
             translator.Translate(ref _question);
             translator.Translate(ref _isBuildCheckEnabled);
+            translator.Translate(ref _isTelemetryEnabled);
             translator.TranslateEnum(ref _projectIsolationMode, (int)_projectIsolationMode);
             translator.Translate(ref _reportFileAccesses);
 

src/Build/BackEnd/Components/Logging/ILoggingService.cs

@@ -577,6 +577,8 @@ ProjectStartedEventArgs CreateProjectStarted(
         /// <param name="success">Did the build succeede or not</param>
         void LogProjectFinished(BuildEventContext projectBuildEventContext, string projectFile, bool success);
 
+        void LogProjectFinished(BuildEventContext projectBuildEventContext, ProjectBuildStats projectBuildStats, string projectFile, bool success);
+
         /// <summary>
         /// Log that a target has started
         /// </summary>

src/Build/BackEnd/Components/Logging/LoggingServiceLogMethods.cs

@@ -604,6 +604,17 @@ public ProjectStartedEventArgs CreateProjectStarted(
         /// <param name="success">Did the project pass or fail</param>
         /// <exception cref="InternalErrorException">BuildEventContext is null</exception>
         public void LogProjectFinished(BuildEventContext projectBuildEventContext, string projectFile, bool success)
+            => LogProjectFinished(projectBuildEventContext, null, projectFile, success);
+
+        /// <summary>
+        /// Logs that a project has finished
+        /// </summary>
+        /// <param name="projectBuildEventContext">Event context for the project.</param>
+        /// <param name="projectBuildStats"></param>
+        /// <param name="projectFile">Project file being built</param>
+        /// <param name="success">Did the project pass or fail</param>
+        /// <exception cref="InternalErrorException">BuildEventContext is null</exception>
+        public void LogProjectFinished(BuildEventContext projectBuildEventContext, ProjectBuildStats projectBuildStats, string projectFile, bool success)
         {
             ErrorUtilities.VerifyThrow(projectBuildEventContext != null, "projectBuildEventContext");
 
@@ -613,6 +624,7 @@ public void LogProjectFinished(BuildEventContext projectBuildEventContext, strin
                     projectFile,
                     success);
             buildEvent.BuildEventContext = projectBuildEventContext;
+            buildEvent.ProjectBuildStats = projectBuildStats;
             ProcessLoggingEvent(buildEvent);
 
             // PERF: Not using VerifyThrow to avoid boxing of projectBuildEventContext.ProjectContextId in the non-error case.

src/Build/BackEnd/Components/Logging/ProjectLoggingContext.cs

@@ -258,10 +258,11 @@ private static ProjectStartedEventArgs CreateProjectStarted(
         /// Log that the project has finished
         /// </summary>
         /// <param name="success">Did the build succeede or not</param>
-        internal void LogProjectFinished(bool success)
+        /// <param name="projectBuildStats"></param>
+        internal void LogProjectFinished(bool success, ProjectBuildStats projectBuildStats = null)
         {
             ErrorUtilities.VerifyThrow(this.IsValid, "invalid");
-            LoggingService.LogProjectFinished(BuildEventContext, _projectFullPath, success);
+            LoggingService.LogProjectFinished(BuildEventContext, projectBuildStats, _projectFullPath, success);
             this.IsValid = false;
         }