Improve diagnostic logging across MTP crash and IPC paths

src/Platform/Microsoft.Testing.Platform/Configurations/ConfigurationManager.cs

@@ -63,9 +63,18 @@ internal async Task<IConfiguration> BuildAsync(IFileLoggerProvider? syncFileLogg
             ILogger logger = syncFileLoggerProvider.CreateLogger(nameof(ConfigurationManager));
             if (logger.IsEnabled(LogLevel.Trace))
             {
-                using IFileStream configFileStream = _fileSystem.NewFileStream(defaultJsonConfiguration.ConfigurationFile, FileMode.Open, FileAccess.Read);
-                StreamReader streamReader = new(configFileStream.Stream);
-                await logger.LogTraceAsync($"Configuration file ('{defaultJsonConfiguration.ConfigurationFile}') content:\n{await streamReader.ReadToEndAsync().ConfigureAwait(false)}").ConfigureAwait(false);
+                try
+                {
+                    using IFileStream configFileStream = _fileSystem.NewFileStream(defaultJsonConfiguration.ConfigurationFile, FileMode.Open, FileAccess.Read);
+                    StreamReader streamReader = new(configFileStream.Stream);
+                    await logger.LogTraceAsync($"Configuration file ('{defaultJsonConfiguration.ConfigurationFile}') content:\n{await streamReader.ReadToEndAsync().ConfigureAwait(false)}").ConfigureAwait(false);
+                }
+                catch (Exception ex)
+                {
+                    // The trace-level dump is a diagnostic aid only; never let an I/O failure here
+                    // break the configuration pipeline.
+                    await logger.LogTraceAsync($"Failed to dump configuration file ('{defaultJsonConfiguration.ConfigurationFile}') content: {ex.GetType().FullName}: {ex.Message}").ConfigureAwait(false);
+                }
             }
         }
 

src/Platform/Microsoft.Testing.Platform/Configurations/JsonConfigurationProvider.cs

@@ -34,6 +34,22 @@ private async Task LogInformationAsync(string message)
             }
         }
 
+        private async Task LogDebugAsync(string message)
+        {
+            if (_logger is not null)
+            {
+                await _logger.LogDebugAsync(message).ConfigureAwait(false);
+            }
+        }
+
+        private async Task LogErrorAsync(string message, Exception exception)
+        {
+            if (_logger is not null)
+            {
+                await _logger.LogErrorAsync(message, exception).ConfigureAwait(false);
+            }
+        }
+
         public async Task LoadAsync()
         {
             string configFileName;
@@ -48,8 +64,11 @@ public async Task LoadAsync()
                         // As this is only for the purpose of throwing an exception, ignore any exceptions during the GetFullPath call.
                         configFileName = Path.GetFullPath(configFileName);
                     }
-                    catch
+                    catch (Exception ex)
                     {
+                        // Best-effort path resolution; surface the failure at Debug so logs explain why the
+                        // error message may show a relative path instead of an absolute one.
+                        await LogDebugAsync($"Path.GetFullPath('{configFileName}') failed while preparing FileNotFoundException: {ex.GetType().FullName}: {ex.Message}").ConfigureAwait(false);
                     }
 
                     throw new FileNotFoundException(string.Format(CultureInfo.InvariantCulture, PlatformResources.ConfigurationFileNotFound, configFileName), configFileName);
@@ -65,6 +84,7 @@ public async Task LoadAsync()
 
                 if (!_fileSystem.ExistFile(configFileName))
                 {
+                    await LogDebugAsync($"Default JSON config file '{configFileName}' not found; skipping load.").ConfigureAwait(false);
                     return;
                 }
             }
@@ -74,7 +94,15 @@ public async Task LoadAsync()
             ConfigurationFile = configFileName;
 
             using IFileStream fileStream = _fileSystem.NewFileStream(configFileName, FileMode.Open, FileAccess.Read);
-            (_singleValueData, _propertyToAllChildren) = JsonConfigurationFileParser.Parse(fileStream.Stream);
+            try
+            {
+                (_singleValueData, _propertyToAllChildren) = JsonConfigurationFileParser.Parse(fileStream.Stream);
+            }
+            catch (Exception ex)
+            {
+                await LogErrorAsync($"Failed to parse configuration file '{configFileName}'", ex).ConfigureAwait(false);
+                throw;
+            }
         }
 
         public bool TryGet(string key, out string? value)

src/Platform/Microsoft.Testing.Platform/Helpers/UnhandledExceptionHandler.cs

@@ -23,23 +23,54 @@ public void SetLogger(ILogger logger)
 
     private void OnCurrentDomainUnhandledException(object sender, UnhandledExceptionEventArgs e)
     {
-        string error = $"[UnhandledExceptionHandler.OnCurrentDomainUnhandledException{(_isTestController ? "(testhost controller workflow)" : "(testhost workflow)")}] {e.ExceptionObject}{_environment.NewLine}IsTerminating: {e.IsTerminating}";
-        LogErrorAndExit(error, !e.IsTerminating);
+        string prefix = $"[UnhandledExceptionHandler.OnCurrentDomainUnhandledException{(_isTestController ? "(testhost controller workflow)" : "(testhost workflow)")}]";
+        var exception = e.ExceptionObject as Exception;
+        string consoleMessage = $"{prefix} {e.ExceptionObject}{_environment.NewLine}IsTerminating: {e.IsTerminating}";
+
+        // The structured log keeps the prefix + IsTerminating in the message and routes the typed
+        // exception through the exception parameter so the existing formatter (and structured sinks)
+        // can capture stack/inner exceptions independently of the message text.
+        string logMessage = exception is not null
+            ? $"{prefix} IsTerminating: {e.IsTerminating}"
+            : consoleMessage;
+
+        LogErrorAndExit(consoleMessage, logMessage, exception, !e.IsTerminating);
     }
 
     private void OnTaskSchedulerUnobservedTaskException(object? sender, UnobservedTaskExceptionEventArgs e)
     {
-        string error = $"[UnhandledExceptionHandler.OnTaskSchedulerUnobservedTaskException{(_isTestController ? "(testhost controller workflow)" : "(testhost workflow)")}] Unhandled exception: {e.Exception}";
-        LogErrorAndExit(error, true);
+        string prefix = $"[UnhandledExceptionHandler.OnTaskSchedulerUnobservedTaskException{(_isTestController ? "(testhost controller workflow)" : "(testhost workflow)")}]";
+        string consoleMessage = $"{prefix} Unhandled exception: {e.Exception}";
+        string logMessage = $"{prefix} Unhandled task exception";
+        LogErrorAndExit(consoleMessage, logMessage, e.Exception, true);
     }
 
-    private void LogErrorAndExit(string error, bool forceClose)
+    private void LogErrorAndExit(string consoleMessage, string logMessage, Exception? exception, bool forceClose)
     {
-        _console.WriteLine(error);
-        _logger?.LogCritical(error);
+        _console.WriteLine(consoleMessage);
+
+        if (_logger is not null)
+        {
+            if (exception is not null)
+            {
+                _logger.Log(LogLevel.Critical, logMessage, exception, LoggingExtensions.Formatter);
+            }
+            else
+            {
+                _logger.LogCritical(logMessage);
+            }
+        }
+
         if (forceClose)
         {
-            _environment.FailFast(error);
+            if (exception is not null)
+            {
+                _environment.FailFast(consoleMessage, exception);
+            }
+            else
+            {
+                _environment.FailFast(consoleMessage);
+            }
         }
     }
 }

src/Platform/Microsoft.Testing.Platform/Hosts/ServerTestHost.cs

@@ -99,21 +99,33 @@ public ServerTestHost(
 
     private void OnCurrentDomainUnhandledException(object sender, UnhandledExceptionEventArgs e)
     {
-        _logger.LogWarning($"[ServerTestHost.OnCurrentDomainUnhandledException] {e.ExceptionObject}{_environment.NewLine}IsTerminating: {e.IsTerminating}");
+        const string Prefix = "[ServerTestHost.OnCurrentDomainUnhandledException]";
+        var exception = e.ExceptionObject as Exception;
+
+        // Log the exception via the structured exception parameter so sinks can capture it
+        // independently of the message text. Output device still gets the human-readable form.
+        if (exception is not null)
+        {
+            _logger.Log(LogLevel.Warning, $"{Prefix} IsTerminating: {e.IsTerminating}", exception, LoggingExtensions.Formatter);
+        }
+        else
+        {
+            _logger.LogWarning($"{Prefix} {e.ExceptionObject}{_environment.NewLine}IsTerminating: {e.IsTerminating}");
+        }
 
         // Looks like nothing in this message to really be localized?
         // All are class names, method names, property names, and placeholders. So none is localizable?
         ServiceProvider.GetOutputDevice().DisplayAsync(
             this,
             new WarningMessageOutputDeviceData(
-                $"[ServerTestHost.OnCurrentDomainUnhandledException] {e.ExceptionObject}{_environment.NewLine}IsTerminating: {e.IsTerminating}"), CancellationToken.None)
+                $"{Prefix} {e.ExceptionObject}{_environment.NewLine}IsTerminating: {e.IsTerminating}"), CancellationToken.None)
             .GetAwaiter().GetResult();
     }
 
     private void OnTaskSchedulerUnobservedTaskException(object? sender, UnobservedTaskExceptionEventArgs e)
     {
         e.SetObserved();
-        _logger.LogWarning($"[ServerTestHost.OnTaskSchedulerUnobservedTaskException] Unhandled exception: {e.Exception}");
+        _logger.Log(LogLevel.Warning, "[ServerTestHost.OnTaskSchedulerUnobservedTaskException] Unhandled task exception", e.Exception, LoggingExtensions.Formatter);
 
         ServiceProvider.GetOutputDevice().DisplayAsync(this, new WarningMessageOutputDeviceData(string.Format(CultureInfo.InvariantCulture, PlatformResources.UnobservedTaskExceptionWarningMessage, e.Exception.ToString())), CancellationToken.None)
             .GetAwaiter().GetResult();

src/Platform/Microsoft.Testing.Platform/Hosts/TestHostControllersTestHost.cs

@@ -251,10 +251,11 @@ protected override async Task<int> InternalRunAsync(CancellationToken cancellati
             {
                 testHostProcessId = testHostProcess.Id;
             }
-            catch (InvalidOperationException) when (testHostProcess.HasExited)
+            catch (InvalidOperationException ex) when (testHostProcess.HasExited)
             {
                 // Access PID can throw InvalidOperationException if the process has already exited:
                 // System.InvalidOperationException: No process is associated with this object.
+                await _logger.LogDebugAsync($"Unable to obtain test host PID; process had already exited (ExitCode: {testHostProcess.ExitCode}). {ex.GetType().FullName}: {ex.Message}").ConfigureAwait(false);
             }
 
             testHostProcess.Exited += (_, _) =>
@@ -355,6 +356,16 @@ protected override async Task<int> InternalRunAsync(CancellationToken cancellati
             else if (!testHostProcessInformation.HasExitedGracefully ||
                 _testHostExitCodeReceived != testHostProcess.ExitCode)
             {
+                await _logger.LogWarningAsync(
+                    $"""
+                     Test host did not exit gracefully.
+                       OS exit code: '{testHostProcess.ExitCode}'
+                       IPC-reported exit code: '{(_testHostExitCodeReceived.HasValue ? _testHostExitCodeReceived.Value.ToString(CultureInfo.InvariantCulture) : "<not received>")}'
+                       TestHostCompletedRequest received: '{_testHostCompletedReceived}'
+                       PID: '{_testHostPID.Value.ToString(CultureInfo.InvariantCulture)}'
+                       CancellationRequested: '{cancellationToken.IsCancellationRequested}'
+                     """)
+                    .ConfigureAwait(false);
                 await outputDevice.DisplayAsync(this, new ErrorMessageOutputDeviceData(string.Format(CultureInfo.InvariantCulture, PlatformResources.TestProcessDidNotExitGracefullyErrorMessage, testHostProcess.ExitCode)), cancellationToken).ConfigureAwait(false);
                 exitCode = (int)ExitCode.TestHostProcessExitedNonGracefully;
             }

src/Platform/Microsoft.Testing.Platform/IPC/NamedPipeClient.cs

@@ -181,6 +181,19 @@ public async Task<TResponse> RequestReplyAsync<TRequest, TResponse>(TRequest req
                     // This is especially important for 'dotnet test', where the user can simply kill the dotnet.exe process themselves.
                     // In that case, we want the MTP process to also die.
                     // Exit code 1 indicates abnormal termination due to IPC connection loss.
+
+                    // Surface a diagnostic on stderr so the user has a chance to understand why this process is exiting.
+                    // We deliberately use Console.Error (and not stdout) to avoid corrupting any machine-readable output
+                    // that may be flowing through stdout.
+                    try
+                    {
+                        await Console.Error.WriteLineAsync($"[NamedPipeClient] Pipe '{PipeName}' was closed by the server before a response was received. The peer process likely exited or was killed. Terminating with exit code {(int)ExitCode.GenericFailure}.").ConfigureAwait(false);
+                    }
+                    catch (Exception ex) when (ex is IOException or ObjectDisposedException or InvalidOperationException or NotSupportedException or ArgumentException or OperationCanceledException)
+                    {
+                        // Best-effort diagnostic only; never let logging failures shadow the original problem.
+                    }
+
                     _environment.Exit((int)ExitCode.GenericFailure);
                 }
 

src/Platform/Microsoft.Testing.Platform/IPC/NamedPipeServer.cs

@@ -141,6 +141,7 @@ private async Task InternalLoopAsync(CancellationToken cancellationToken)
             if (currentReadBytes == 0)
             {
                 // The client has disconnected
+                await _logger.LogDebugAsync($"Client disconnected from pipe '{PipeName.Name}', exiting read loop").ConfigureAwait(false);
                 return;
             }
 
@@ -304,6 +305,7 @@ public void Dispose()
             // To close gracefully we need to ensure that the client closed the stream in the InternalLoopAsync method (there is comment `// The client has disconnected`).
             if (!_loopTask.Wait(TimeoutHelper.DefaultHangTimeSpanTimeout))
             {
+                _logger.LogError($"NamedPipeServer.Dispose: '{nameof(InternalLoopAsync)}' for pipe '{PipeName.Name}' did not complete within {TimeoutHelper.DefaultHangTimeSpanTimeout}. WasConnected={WasConnected}, LoopTaskStatus={_loopTask.Status}.");
                 throw new InvalidOperationException(string.Format(
                     CultureInfo.InvariantCulture,
                     PlatformResources.InternalLoopAsyncDidNotExitSuccessfullyErrorMessage,
@@ -337,6 +339,7 @@ public async ValueTask DisposeAsync()
             }
             catch (TimeoutException)
             {
+                await _logger.LogErrorAsync($"NamedPipeServer.DisposeAsync: '{nameof(InternalLoopAsync)}' for pipe '{PipeName.Name}' did not complete within {TimeoutHelper.DefaultHangTimeSpanTimeout}. WasConnected={WasConnected}, LoopTaskStatus={_loopTask.Status}.").ConfigureAwait(false);
                 throw new InvalidOperationException(string.Format(
                     CultureInfo.InvariantCulture,
                     PlatformResources.InternalLoopAsyncDidNotExitSuccessfullyErrorMessage,

src/Platform/Microsoft.Testing.Platform/Requests/TestHostTestFrameworkInvoker.cs

@@ -45,12 +45,13 @@ public async Task ExecuteAsync(ITestFramework testFramework, ClientInfo client,
         }
 
         SessionUid sessionId = ServiceProvider.GetTestSessionContext().SessionUid;
+        await logger.LogDebugAsync($"Test session UID: '{sessionId.Value}'").ConfigureAwait(false);
 
         IPlatformOpenTelemetryService? otelService = ServiceProvider.GetPlatformOTelService();
         using (otelService?.StartActivity("CreateTestFrameworkSession", tags: [new("SessionUid", sessionId)]))
         {
             CreateTestSessionResult createTestSessionResult = await testFramework.CreateTestSessionAsync(new(sessionId, cancellationToken)).ConfigureAwait(false);
-            await HandleTestSessionResultAsync(createTestSessionResult.IsSuccess, createTestSessionResult.WarningMessage, createTestSessionResult.ErrorMessage, cancellationToken).ConfigureAwait(false);
+            await HandleTestSessionResultAsync(logger, "CreateTestSession", sessionId, createTestSessionResult.IsSuccess, createTestSessionResult.WarningMessage, createTestSessionResult.ErrorMessage, cancellationToken).ConfigureAwait(false);
         }
 
         TestExecutionRequest request;
@@ -71,7 +72,7 @@ public async Task ExecuteAsync(ITestFramework testFramework, ClientInfo client,
         using (otelService?.StartActivity("CloseTestFrameworkSession", tags: [new("SessionUid", sessionId)]))
         {
             CloseTestSessionResult closeTestSessionResult = await testFramework.CloseTestSessionAsync(new(sessionId, cancellationToken)).ConfigureAwait(false);
-            await HandleTestSessionResultAsync(closeTestSessionResult.IsSuccess, closeTestSessionResult.WarningMessage, closeTestSessionResult.ErrorMessage, cancellationToken).ConfigureAwait(false);
+            await HandleTestSessionResultAsync(logger, "CloseTestSession", sessionId, closeTestSessionResult.IsSuccess, closeTestSessionResult.WarningMessage, closeTestSessionResult.ErrorMessage, cancellationToken).ConfigureAwait(false);
         }
     }
 
@@ -85,19 +86,22 @@ public virtual async Task ExecuteRequestAsync(ITestFramework testFramework, Test
         await requestSemaphore.WaitAsync(cancellationToken).ConfigureAwait(false);
     }
 
-    private async Task HandleTestSessionResultAsync(bool isSuccess, string? warningMessage, string? errorMessage, CancellationToken cancellationToken)
+    private async Task HandleTestSessionResultAsync(ILogger logger, string phase, SessionUid sessionId, bool isSuccess, string? warningMessage, string? errorMessage, CancellationToken cancellationToken)
     {
         if (warningMessage is not null)
         {
+            await logger.LogWarningAsync($"Test framework '{phase}' (session '{sessionId.Value}') reported warning: {warningMessage}").ConfigureAwait(false);
             IOutputDevice outputDisplay = ServiceProvider.GetOutputDevice();
             await outputDisplay.DisplayAsync(this, new WarningMessageOutputDeviceData(warningMessage), cancellationToken).ConfigureAwait(false);
         }
 
         if (!isSuccess)
         {
+            string effectiveErrorMessage = errorMessage ?? PlatformResources.TestHostAdapterInvokerFailedTestSessionErrorMessage;
+            await logger.LogErrorAsync($"Test framework '{phase}' (session '{sessionId.Value}') failed: {effectiveErrorMessage}").ConfigureAwait(false);
             ITestApplicationProcessExitCode testApplicationProcessExitCode = ServiceProvider.GetTestApplicationProcessExitCode();
             await testApplicationProcessExitCode.SetTestAdapterTestSessionFailureAsync(
-                errorMessage ?? PlatformResources.TestHostAdapterInvokerFailedTestSessionErrorMessage,
+                effectiveErrorMessage,
                 cancellationToken).ConfigureAwait(false);
         }
     }