Add more logging for sidecar tests

src/Build.UnitTests/BackEnd/TaskHostFactory_Tests.cs

@@ -2,6 +2,7 @@
 // The .NET Foundation licenses this file to you under the MIT license.
 
 using System;
+using System.Collections.Generic;
 using System.Diagnostics;
 using System.Globalization;
 using Microsoft.Build.Execution;
@@ -17,6 +18,10 @@
 
 namespace Microsoft.Build.Engine.UnitTests.BackEnd
 {
+    /// <summary>
+    /// Tests for the TaskHostFactory functionality, which manages task host processes
+    /// for executing MSBuild tasks in separate processes.
+    /// </summary>
     public sealed class TaskHostFactory_Tests
     {
         private ITestOutputHelper _output;
@@ -26,6 +31,13 @@ public TaskHostFactory_Tests(ITestOutputHelper testOutputHelper)
             _output = testOutputHelper;
         }
 
+        /// <summary>
+        /// Verifies that task host nodes properly terminate after a build completes.
+        /// Tests both transient (TaskHostFactory) and sidecar (AssemblyTaskFactory) task hosts
+        /// with different configuration combinations.
+        /// </summary>
+        /// <param name="taskHostFactorySpecified">Whether to use TaskHostFactory (transient) or AssemblyTaskFactory (sidecar)</param>
+        /// <param name="envVariableSpecified">Whether to set MSBUILDFORCEALLTASKSOUTOFPROC environment variable</param>
         [Theory]
         [InlineData(true, false)]
         [InlineData(false, true)]
@@ -34,7 +46,7 @@ public void TaskNodesDieAfterBuild(bool taskHostFactorySpecified, bool envVariab
         {
             using (TestEnvironment env = TestEnvironment.Create())
             {
-
+                using ProcessTracker processTracker = new();
                 string taskFactory = taskHostFactorySpecified ? "TaskHostFactory" : "AssemblyTaskFactory";
                 string pidTaskProject = $@"
 <Project>
@@ -46,11 +58,12 @@ public void TaskNodesDieAfterBuild(bool taskHostFactorySpecified, bool envVariab
     </Target>
 </Project>";
                 TransientTestFile project = env.CreateFile("testProject.csproj", pidTaskProject);
-                    
+
                 if (envVariableSpecified)
                 {
                     env.SetEnvironmentVariable("MSBUILDFORCEALLTASKSOUTOFPROC", "1");
                 }
+
                 ProjectInstance projectInstance = new(project.Path);
 
                 projectInstance.Build().ShouldBeTrue();
@@ -64,8 +77,9 @@ public void TaskNodesDieAfterBuild(bool taskHostFactorySpecified, bool envVariab
                     try
                     {
                         Process taskHostNode = Process.GetProcessById(pid);
-                        taskHostNode.WaitForExit(3000).ShouldBeTrue($"The executed MSBuild Version: {projectInstance.GetProperty("MSBuildVersion")}");
+                        taskHostNode.WaitForExit(3000).ShouldBeTrue("The process with taskHostNode is still running.");
                     }
+
                     // We expect the TaskHostNode to exit quickly. If it exits before Process.GetProcessById, it will throw an ArgumentException.
                     catch (ArgumentException e)
                     {
@@ -74,20 +88,40 @@ public void TaskNodesDieAfterBuild(bool taskHostFactorySpecified, bool envVariab
                 }
                 else
                 {
-                    // This is the sidecar TaskHost case - it should persist after build is done. So we need to clean up and kill it ourselves.
-                    Process taskHostNode = Process.GetProcessById(pid);
-                    taskHostNode.WaitForExit(3000).ShouldBeFalse($"The executed MSBuild Version: {projectInstance.GetProperty("MSBuildVersion")}");
-                    taskHostNode.Kill();
+                    try
+                    {
+                        // This is the sidecar TaskHost case - it should persist after build is done. So we need to clean up and kill it ourselves.
+                        Process taskHostNode = Process.GetProcessById(pid);
+                        using var taskHostNodeTracker = processTracker.AttachToProcess(pid, "Sidecar", _output);
+                        bool processExited = taskHostNode.WaitForExit(3000);
+                        if (processExited)
+                        {
+                            processTracker.PrintSummary(_output);
+                        }
+
+                        processExited.ShouldBeFalse();
+                        taskHostNode.Kill();
+                    }
+                    catch
+                    {
+                        processTracker.PrintSummary(_output);
+                    }
                 }
             }
         }
 
+        /// <summary>
+        /// Verifies that transient (TaskHostFactory) and sidecar (AssemblyTaskFactory) task hosts
+        /// can coexist in the same build and operate independently.
+        /// </summary>
         [Fact]
         public void TransientandSidecarNodeCanCoexist()
         {
-            using (TestEnvironment env = TestEnvironment.Create())
+            using (TestEnvironment env = TestEnvironment.Create(_output))
             {
-                string pidTaskProject = $@"
+                using ProcessTracker processTracker = new();
+                {
+                    string pidTaskProject = $@"
 <Project>
 <UsingTask TaskName=""ProcessIdTask"" AssemblyName=""Microsoft.Build.Engine.UnitTests"" TaskFactory=""TaskHostFactory"" />
 <UsingTask TaskName=""ProcessIdTaskSidecar"" AssemblyName=""Microsoft.Build.Engine.UnitTests"" TaskFactory=""AssemblyTaskFactory"" />
@@ -102,43 +136,59 @@ public void TransientandSidecarNodeCanCoexist()
 </Target>
 </Project>";
 
-                TransientTestFile project = env.CreateFile("testProject.csproj", pidTaskProject);
+                    TransientTestFile project = env.CreateFile("testProject.csproj", pidTaskProject);
 
+                    env.SetEnvironmentVariable("MSBUILDFORCEALLTASKSOUTOFPROC", "1");
+                    ProjectInstance projectInstance = new(project.Path);
 
-                env.SetEnvironmentVariable("MSBUILDFORCEALLTASKSOUTOFPROC", "1");
-                ProjectInstance projectInstance = new(project.Path);
+                    projectInstance.Build().ShouldBeTrue();
 
-                projectInstance.Build().ShouldBeTrue();
-                string processId = projectInstance.GetPropertyValue("PID");
-                string processIdSidecar = projectInstance.GetPropertyValue("PID2");
-                processIdSidecar.ShouldNotBe(processId, "Each task should have it's own TaskHost node.");
+                    string transientPid = projectInstance.GetPropertyValue("PID");
+                    string sidecarPid = projectInstance.GetPropertyValue("PID2");
+                    sidecarPid.ShouldNotBe(transientPid, "Each task should have it's own TaskHost node.");
 
-                string.IsNullOrEmpty(processId).ShouldBeFalse();
-                Int32.TryParse(processId, out int pid).ShouldBeTrue();
-                Int32.TryParse(processIdSidecar, out int pidSidecar).ShouldBeTrue();
+                    using var sidecarTracker = processTracker.AttachToProcess(int.Parse(sidecarPid), "Sidecar", _output);
 
-                Process.GetCurrentProcess().Id.ShouldNotBe(pid);
+                    string.IsNullOrEmpty(transientPid).ShouldBeFalse();
+                    Int32.TryParse(transientPid, out int pid).ShouldBeTrue();
+                    Int32.TryParse(sidecarPid, out int pidSidecar).ShouldBeTrue();
 
+                    Process.GetCurrentProcess().Id.ShouldNotBe(pid);
 
-                try
-                {
-                    Process taskHostNode1 = Process.GetProcessById(pid);
-                    taskHostNode1.WaitForExit(3000).ShouldBeTrue("The node should be dead since this is the transient case.");
-                }
-                catch (ArgumentException e)
-                {
-                    // We expect the TaskHostNode to exit quickly. If it exits before Process.GetProcessById, it will throw an ArgumentException.
-                    e.Message.ShouldBe($"Process with an Id of {pid} is not running.");
+                    try
+                    {
+                        Process transientTaskHostNode = Process.GetProcessById(pid);
+                        transientTaskHostNode.WaitForExit(3000).ShouldBeTrue("The node should be dead since this is the transient case.");
+                    }
+                    catch (ArgumentException e)
+                    {
+                        // We expect the TaskHostNode to exit quickly. If it exits before Process.GetProcessById, it will throw an ArgumentException.
+                        e.Message.ShouldBe($"Process with an Id of {pid} is not running.");
+                    }
+
+                    try
+                    {
+                        // This is the sidecar TaskHost case - it should persist after build is done. So we need to clean up and kill it ourselves.
+                        Process sidecarTaskHostNode = Process.GetProcessById(pidSidecar);
+                        sidecarTaskHostNode.WaitForExit(3000).ShouldBeFalse($"The node should be alive since it is the sidecar node.");
+                        sidecarTaskHostNode.Kill();
+                    }
+                    catch (Exception e)
+                    {
+                        processTracker.PrintSummary(_output);
+                        e.Message.ShouldNotBe($"Process with an Id of {pidSidecar} is not running");
+                    }
                 }
-                // This is the sidecar TaskHost case - it should persist after build is done. So we need to clean up and kill it ourselves.
-                Process taskHostNode2 = Process.GetProcessById(pidSidecar);
-                taskHostNode2.WaitForExit(3000).ShouldBeFalse($"The node should be alive since it is the sidecar node.");
-                taskHostNode2.Kill();
             }
         }
 
+        /// <summary>
+        /// Verifies that various parameter types can be correctly transmitted to and received from
+        /// a task host process, ensuring proper serialization/deserialization of all supported types.
+        /// Tests include primitive types, arrays, strings, dates, enums, and custom structures.
+        /// </summary>
         [Fact]
-        private void VariousParameterTypesCanBeTransmittedToAndReceivedFromTaskHost()
+        public void VariousParameterTypesCanBeTransmittedToAndReceivedFromTaskHost()
         {
             using TestEnvironment env = TestEnvironment.Create(_output);
 
@@ -282,5 +332,177 @@ private void VariousParameterTypesCanBeTransmittedToAndReceivedFromTaskHost()
             projectInstance.GetPropertyValue("CustomStructOutput").ShouldBe(TaskBuilderTestTask.s_customStruct.ToString(CultureInfo.InvariantCulture));
             projectInstance.GetPropertyValue("EnumOutput").ShouldBe(TargetBuiltReason.BeforeTargets.ToString());
         }
+
+        /// <summary>
+        /// Helper class for tracking external processes during tests.
+        /// Monitors process lifecycle and provides diagnostic information for debugging.
+        /// </summary>
+        internal sealed class ProcessTracker : IDisposable
+        {
+            private readonly List<TrackedProcess> _trackedProcesses = new();
+
+            /// <summary>
+            /// Attaches to an existing process for monitoring.
+            /// </summary>
+            /// <param name="pid">Process ID to attach to</param>
+            /// <param name="name">Friendly name for the process</param>
+            /// <param name="output">Test output helper for logging</param>
+            /// <returns>TrackedProcess instance for the attached process</returns>
+            public TrackedProcess AttachToProcess(int pid, string name, ITestOutputHelper output)
+            {
+                try
+                {
+                    var process = Process.GetProcessById(pid);
+                    var tracked = new TrackedProcess(process, name);
+
+                    // Enable event notifications
+                    process.EnableRaisingEvents = true;
+
+                    // Subscribe to exit event
+                    process.Exited += (sender, e) =>
+                    {
+                        var proc = sender as Process;
+                        tracked.ExitTime = DateTime.Now;
+                        tracked.ExitCode = proc?.ExitCode ?? -999;
+                        tracked.HasExited = true;
+
+                        output.WriteLine($"[{DateTime.Now:HH:mm:ss.fff}] {tracked.Name} (PID {tracked.ProcessId}) EXITED with code {tracked.ExitCode}");
+                    };
+
+                    _trackedProcesses.Add(tracked);
+                    output.WriteLine($"[{DateTime.Now:HH:mm:ss.fff}] Attached to {name} (PID {pid})");
+
+                    return tracked;
+                }
+                catch (ArgumentException)
+                {
+                    output.WriteLine($"[{DateTime.Now:HH:mm:ss.fff}] Could not attach to {name} (PID {pid}) - process not found");
+                    return new TrackedProcess(null, name) { ProcessId = pid, NotFound = true };
+                }
+            }
+
+            /// <summary>
+            /// Prints a summary of all tracked processes for diagnostic purposes.
+            /// </summary>
+            /// <param name="output">Test output helper for logging</param>
+            public void PrintSummary(ITestOutputHelper output)
+            {
+                output.WriteLine("\n=== PROCESS TRACKING SUMMARY ===");
+                foreach (var tracked in _trackedProcesses)
+                {
+                    tracked.PrintStatus(output);
+                }
+            }
+
+            public void Dispose()
+            {
+                foreach (var tracked in _trackedProcesses)
+                {
+                    tracked.Dispose();
+                }
+            }
+        }
+
+        /// <summary>
+        /// Represents a tracked process with lifecycle monitoring capabilities.
+        /// </summary>
+        internal sealed class TrackedProcess : IDisposable
+        {
+            /// <summary>
+            /// The underlying Process object being tracked.
+            /// </summary>
+            public Process Process { get; }
+
+            /// <summary>
+            /// Friendly name for the tracked process.
+            /// </summary>
+            public string Name { get; }
+
+            /// <summary>
+            /// Process ID of the tracked process.
+            /// </summary>
+            public int ProcessId { get; set; }
+
+            /// <summary>
+            /// Time when tracking began for this process.
+            /// </summary>
+            public DateTime AttachTime { get; }
+
+            /// <summary>
+            /// Time when the process exited, if applicable.
+            /// </summary>
+            public DateTime? ExitTime { get; set; }
+
+            /// <summary>
+            /// Exit code of the process, if it has exited.
+            /// </summary>
+            public int? ExitCode { get; set; }
+
+            /// <summary>
+            /// Whether the process has exited.
+            /// </summary>
+            public bool HasExited { get; set; }
+
+            /// <summary>
+            /// Whether the process was not found when attempting to attach.
+            /// </summary>
+            public bool NotFound { get; set; }
+
+            public TrackedProcess(Process process, string name)
+            {
+                Process = process;
+                Name = name;
+                ProcessId = process?.Id ?? -1;
+                AttachTime = DateTime.Now;
+            }
+
+            /// <summary>
+            /// Prints detailed status information about the tracked process.
+            /// </summary>
+            /// <param name="output">Test output helper for logging</param>
+            public void PrintStatus(ITestOutputHelper output)
+            {
+                output.WriteLine($"\n{Name} (PID {ProcessId}):");
+                output.WriteLine($"  Attached at: {AttachTime:HH:mm:ss.fff}");
+
+                if (NotFound)
+                {
+                    output.WriteLine("  Status: Not found when trying to attach");
+                }
+                else if (HasExited)
+                {
+                    var duration = (ExitTime.Value - AttachTime).TotalMilliseconds;
+                    output.WriteLine($"  Status: Exited with code {ExitCode}");
+                    output.WriteLine($"  Exit time: {ExitTime:HH:mm:ss.fff}");
+                    output.WriteLine($"  Duration: {duration:F0}ms");
+                }
+                else
+                {
+                    try
+                    {
+                        if (Process != null && !Process.HasExited)
+                        {
+                            output.WriteLine("  Status: Still running");
+                            output.WriteLine($"  Start time: {Process.StartTime:HH:mm:ss.fff}");
+                            output.WriteLine($"  CPU time: {Process.TotalProcessorTime.TotalMilliseconds:F0}ms");
+                        }
+                        else
+                        {
+                            output.WriteLine("  Status: Exited (detected during status check)");
+                            if (Process != null)
+                            {
+                                output.WriteLine($"  Exit code: {Process.ExitCode}");
+                            }
+                        }
+                    }
+                    catch (Exception ex)
+                    {
+                        output.WriteLine($"  Status: Error checking process - {ex.Message}");
+                    }
+                }
+            }
+
+            public void Dispose() => Process?.Dispose();
+        }
     }
 }