diff --git a/.gitignore b/.gitignore index 2a3a04a21..c4efd286f 100644 --- a/.gitignore +++ b/.gitignore @@ -362,3 +362,4 @@ MigrationBackup/ .idea .vscode/ +.nuget/ diff --git a/src/Microsoft.DotNet.XHarness.Apple/AppOperations/AppTester.cs b/src/Microsoft.DotNet.XHarness.Apple/AppOperations/AppTester.cs index ffa3c1509..de7d04314 100644 --- a/src/Microsoft.DotNet.XHarness.Apple/AppOperations/AppTester.cs +++ b/src/Microsoft.DotNet.XHarness.Apple/AppOperations/AppTester.cs @@ -352,16 +352,25 @@ private async Task RunSimulatorTests( deviceListener.TestLog.FullPath); // If results weren't copied, it likely means the app crashed before tests could run - // Try to retrieve the crash report + // Try to retrieve the crash report, but only if the test run didn't already complete. + // When test run completed (Success=true from CollectSimulatorResult), the failure is a + // communication issue, not an app crash, so we skip crash report retrieval. if (!resultsCopied) { - _mainLog.WriteLine("Test results file not found, app may have crashed before tests started."); - await resultFileHandler.CopyCrashReportAsync( - simulator.UDID, - simulator.Name, - appInformation, - _mainLog, - isSimulator: true); + if (testReporter.Success == true) + { + _mainLog.WriteLine("Test results file not found after retries, but test run completed successfully. Device communication issue likely caused the copy failure."); + } + else + { + _mainLog.WriteLine("Test results file not found, app may have crashed before tests started."); + await resultFileHandler.CopyCrashReportAsync( + simulator.UDID, + simulator.Name, + appInformation, + _mainLog, + isSimulator: true); + } } } } @@ -452,16 +461,25 @@ private async Task RunDeviceTests( deviceListener.TestLog.FullPath); // If results weren't copied, it likely means the app crashed before tests could run - // Try to retrieve the crash report + // Try to retrieve the crash report, but only if the test run didn't already complete. + // When test run completed (Success=true from CollectDeviceResult), the failure is a + // device communication issue, not an app crash, so we skip crash report retrieval. if (!resultsCopied) { - _mainLog.WriteLine("Test results file not found, app may have crashed before tests started."); - await resultFileHandler.CopyCrashReportAsync( - device.UDID, - device.Name, - appInformation, - _mainLog, - isSimulator: false); + if (testReporter.Success == true) + { + _mainLog.WriteLine("Test results file not found after retries, but test run completed successfully. Device communication issue likely caused the copy failure."); + } + else + { + _mainLog.WriteLine("Test results file not found, app may have crashed before tests started."); + await resultFileHandler.CopyCrashReportAsync( + device.UDID, + device.Name, + appInformation, + _mainLog, + isSimulator: false); + } } } } diff --git a/src/Microsoft.DotNet.XHarness.iOS.Shared/Logging/DeviceLogCapturer.cs b/src/Microsoft.DotNet.XHarness.iOS.Shared/Logging/DeviceLogCapturer.cs index 1ad7e5427..428041c1a 100644 --- a/src/Microsoft.DotNet.XHarness.iOS.Shared/Logging/DeviceLogCapturer.cs +++ b/src/Microsoft.DotNet.XHarness.iOS.Shared/Logging/DeviceLogCapturer.cs @@ -46,7 +46,10 @@ public void StopCapture() string startTimeStr = _startTime.ToString("yyyy-MM-dd HH:mm:ss"); - // Collect logs + // Collect logs. Use a timeout to avoid hanging indefinitely if the device + // becomes unresponsive (e.g. tvOS devices with broken log streaming). + const int processTimeoutMs = 120_000; // 2 minutes + string collectArguments = $"log collect --device-udid {_deviceUdid} --start \"{startTimeStr}\" --output \"{_outputPath}\""; _deviceLog.WriteLine($"Collecting logs: sudo {collectArguments}"); @@ -75,6 +78,16 @@ public void StopCapture() collectProcess.Start(); collectProcess.BeginOutputReadLine(); collectProcess.BeginErrorReadLine(); + + if (!collectProcess.WaitForExit(processTimeoutMs)) + { + _mainLog.WriteLine($"Device log collection timed out after {processTimeoutMs / 1000}s. Killing process and skipping log reading."); + try { collectProcess.Kill(entireProcessTree: true); } catch { /* best effort */ } + CleanupOutputPath(); + return; + } + + // Ensure all asynchronous output/error reads have completed before consuming buffers collectProcess.WaitForExit(); if (collectErrors.Length > 0) @@ -84,6 +97,7 @@ public void StopCapture() if (collectProcess.ExitCode != 0) { _deviceLog.WriteLine($"Log collection failed with exit code {collectProcess.ExitCode}. Skipping log reading."); + CleanupOutputPath(); return; } } @@ -117,21 +131,36 @@ public void StopCapture() readProcess.Start(); readProcess.BeginOutputReadLine(); readProcess.BeginErrorReadLine(); - readProcess.WaitForExit(); - if (output.Length > 0) + if (!readProcess.WaitForExit(processTimeoutMs)) + { + _mainLog.WriteLine($"Device log reading timed out after {processTimeoutMs / 1000}s. Killing process."); + try { readProcess.Kill(entireProcessTree: true); } catch { /* best effort */ } + } + else { - lock (_deviceLog) + // Ensure all asynchronous output/error reads have completed before consuming buffers + readProcess.WaitForExit(); + + if (output.Length > 0) { - _deviceLog.WriteLine(output.ToString()); + lock (_deviceLog) + { + _deviceLog.WriteLine(output.ToString()); + } } - } - if (errors.Length > 0) - { - _mainLog.WriteLine($"Errors while reading device logs: {errors}"); + if (errors.Length > 0) + { + _mainLog.WriteLine($"Errors while reading device logs: {errors}"); + } } + CleanupOutputPath(); + } + + private void CleanupOutputPath() + { if (Directory.Exists(_outputPath)) { Directory.Delete(_outputPath, true); diff --git a/src/Microsoft.DotNet.XHarness.iOS.Shared/ResultFileHandler.cs b/src/Microsoft.DotNet.XHarness.iOS.Shared/ResultFileHandler.cs index 1c7c70313..5c3c18049 100644 --- a/src/Microsoft.DotNet.XHarness.iOS.Shared/ResultFileHandler.cs +++ b/src/Microsoft.DotNet.XHarness.iOS.Shared/ResultFileHandler.cs @@ -17,13 +17,18 @@ namespace Microsoft.DotNet.XHarness.iOS.Shared; public class ResultFileHandler : IResultFileHandler { + private static readonly int[] DefaultRetryDelaysMs = { 5_000, 10_000, 20_000 }; + private IMlaunchProcessManager _processManager; private IFileBackedLog _mainLog; + private readonly int[] _retryDelaysMs; - public ResultFileHandler(IMlaunchProcessManager pm, IFileBackedLog fs) + public ResultFileHandler(IMlaunchProcessManager pm, IFileBackedLog fs, int[]? retryDelaysMs = null) { _processManager = pm; _mainLog = fs; + // Clone to prevent external mutation of the shared default array + _retryDelaysMs = (retryDelaysMs ?? DefaultRetryDelaysMs).ToArray(); } public bool IsVersionSupported(string osVersion, bool isSimulator) @@ -88,20 +93,41 @@ public async Task CopyResultsAsync( cmd = $"xcrun devicectl device copy from --device {udid} --source {sourcePath} --destination {hostDestinationPath} --user mobile --domain-type appDataContainer --domain-identifier {bundleIdentifier}"; } - await _processManager.ExecuteCommandAsync( - "/bin/bash", - new[] { "-c", cmd }, - _mainLog, - _mainLog, - _mainLog, - TimeSpan.FromMinutes(1), - null); - - if (!File.Exists(hostDestinationPath)) + // Retry up to 3 times with increasing delays to handle transient device communication errors + // (e.g., com.apple.Mercury.error 1000 or RSD error 0xE8000003 on tvOS devices). + for (int attempt = 0; attempt <= _retryDelaysMs.Length; attempt++) { - _mainLog.WriteLine($"Failed to copy results file from {(isSimulator ? "simulator" : "device")}. Expected at: {hostDestinationPath}"); - return false; + if (attempt > 0) + { + int delayMs = _retryDelaysMs[attempt - 1]; + _mainLog.WriteLine($"Retrying results file copy (attempt {attempt + 1}) after {delayMs / 1000}s delay..."); + await Task.Delay(delayMs); + + // Remove a partial/failed destination file before retrying + if (File.Exists(hostDestinationPath)) + { + File.Delete(hostDestinationPath); + } + } + + await _processManager.ExecuteCommandAsync( + "/bin/bash", + new[] { "-c", cmd }, + _mainLog, + _mainLog, + _mainLog, + TimeSpan.FromMinutes(1), + null); + + if (File.Exists(hostDestinationPath)) + { + return true; + } + + _mainLog.WriteLine($"Failed to copy results file from {(isSimulator ? "simulator" : "device")} (attempt {attempt + 1}). Expected at: {hostDestinationPath}"); } + + return false; } return true; diff --git a/src/Microsoft.DotNet.XHarness.iOS.Shared/TestReporter.cs b/src/Microsoft.DotNet.XHarness.iOS.Shared/TestReporter.cs index a321d6a31..209f25cbb 100644 --- a/src/Microsoft.DotNet.XHarness.iOS.Shared/TestReporter.cs +++ b/src/Microsoft.DotNet.XHarness.iOS.Shared/TestReporter.cs @@ -607,6 +607,17 @@ private async Task GenerateXmlFailures(string failure, bool crashed, string? cra result.ResultMessage = "Test runner failed to launch"; Success = false; } + else if (Success == true) + { + // Test run completed (detected via app end signal or mlaunch exit) but the results file + // was not found. This can happen when the device file copy (devicectl) fails due to + // transient device communication issues (e.g., tvOS Mercury error 1000, RSD 0xE8000003). + // Since we already confirmed test completion, treat this as success with a warning. + WrenchLog.WriteLine("AddSummary: {0} completed but results unavailable
", _runMode); + _mainLog.WriteLine("Test run completed but results file was not available (device communication issue)"); + result.ResultMessage = "Test run completed but results file was not available"; + // Success remains true + } else { WrenchLog.WriteLine("AddSummary: {0} crashed at startup (no log)
", _runMode); diff --git a/tests/Microsoft.DotNet.XHarness.iOS.Shared.Tests/ResultFileHandlerTests.cs b/tests/Microsoft.DotNet.XHarness.iOS.Shared.Tests/ResultFileHandlerTests.cs index 0670140a1..82904bf50 100644 --- a/tests/Microsoft.DotNet.XHarness.iOS.Shared.Tests/ResultFileHandlerTests.cs +++ b/tests/Microsoft.DotNet.XHarness.iOS.Shared.Tests/ResultFileHandlerTests.cs @@ -37,9 +37,11 @@ public void Dispose() private static ResultFileHandler CreateHandler( Mock processManagerMock, - Mock logMock) + Mock logMock, + int[] retryDelaysMs = null) { - return new ResultFileHandler(processManagerMock.Object, logMock.Object); + // Default to no retry delays in tests to keep them fast + return new ResultFileHandler(processManagerMock.Object, logMock.Object, retryDelaysMs ?? Array.Empty()); } [Fact] @@ -112,7 +114,7 @@ public async Task SimulatorOsVersion18FileMissingReturnsFalse() RunMode.iOS, true, "Simulator 18.0", "udid", "bundle", _tempFile); Assert.False(result); - log.Verify(l => l.WriteLine($"Failed to copy results file from simulator. Expected at: {_tempFile}"), Times.Once); + log.Verify(l => l.WriteLine($"Failed to copy results file from simulator (attempt 1). Expected at: {_tempFile}"), Times.Once); } [Fact] @@ -171,7 +173,7 @@ public async Task DeviceOsVersion18FileMissingReturnsFalse() RunMode.iOS, false, "18.0", "udid", "bundle", _tempFile); Assert.False(result); - log.Verify(l => l.WriteLine($"Failed to copy results file from device. Expected at: {_tempFile}"), Times.Once); + log.Verify(l => l.WriteLine($"Failed to copy results file from device (attempt 1). Expected at: {_tempFile}"), Times.Once); } [Fact] @@ -251,6 +253,83 @@ public async Task CopyCrashReportUsesHelixUploadRootWhenAvailable() } } + [Fact] + public async Task CopyResultsAsync_WhenFirstAttemptFailsAndSecondSucceeds_ReturnsTrue() + { + Mock pm = new Mock(); + Mock log = new Mock(); + // Use a short delay for the test + ResultFileHandler handler = CreateHandler(pm, log, new[] { 1 }); + + if (File.Exists(_tempFile)) + File.Delete(_tempFile); + + int callCount = 0; + pm.Setup(m => m.ExecuteCommandAsync( + It.IsAny(), + It.IsAny>(), + It.IsAny(), + It.IsAny(), + It.IsAny(), + It.IsAny(), + It.IsAny>(), + It.IsAny())) + .Returns(() => + { + callCount++; + if (callCount == 2) + { + // Simulate success on second attempt by writing the file + File.WriteAllText(_tempFile, "results"); + } + return Task.FromResult(new ProcessExecutionResult { ExitCode = 0 }); + }); + + bool result = await handler.CopyResultsAsync( + RunMode.iOS, false, "18.0", "udid", "bundle", _tempFile); + + Assert.True(result); + Assert.Equal(2, callCount); + log.Verify(l => l.WriteLine(It.Is(s => s.Contains("Retrying results file copy (attempt 2)"))), Times.Once); + } + + [Fact] + public async Task CopyResultsAsync_WhenAllRetriesFail_ReturnsFalse() + { + Mock pm = new Mock(); + Mock log = new Mock(); + // Two retries with minimal delay + ResultFileHandler handler = CreateHandler(pm, log, new[] { 1, 1 }); + + if (File.Exists(_tempFile)) + File.Delete(_tempFile); + + int callCount = 0; + pm.Setup(m => m.ExecuteCommandAsync( + It.IsAny(), + It.IsAny>(), + It.IsAny(), + It.IsAny(), + It.IsAny(), + It.IsAny(), + It.IsAny>(), + It.IsAny())) + .Returns(() => + { + callCount++; + return Task.FromResult(new ProcessExecutionResult { ExitCode = 1 }); + }); + + bool result = await handler.CopyResultsAsync( + RunMode.iOS, false, "18.0", "udid", "bundle", _tempFile); + + Assert.False(result); + // 1 initial attempt + 2 retries = 3 total + Assert.Equal(3, callCount); + log.Verify(l => l.WriteLine(It.Is(s => s.Contains("Retrying results file copy (attempt 2)"))), Times.Once); + log.Verify(l => l.WriteLine(It.Is(s => s.Contains("Retrying results file copy (attempt 3)"))), Times.Once); + } + private static string GetArgumentValue(MlaunchArguments args, string argumentName) { string prefix = $"--{argumentName}="; diff --git a/tests/Microsoft.DotNet.XHarness.iOS.Shared.Tests/TestReporterTests.cs b/tests/Microsoft.DotNet.XHarness.iOS.Shared.Tests/TestReporterTests.cs index 1041652b5..4445ec41d 100644 --- a/tests/Microsoft.DotNet.XHarness.iOS.Shared.Tests/TestReporterTests.cs +++ b/tests/Microsoft.DotNet.XHarness.iOS.Shared.Tests/TestReporterTests.cs @@ -427,4 +427,37 @@ public async Task ParseResultLaunchTimedOutTest() _processManager.Verify(p => p.KillTreeAsync(It.IsAny(), It.IsAny(), true), Times.Never); _crashReporter.Verify(c => c.EndCaptureAsync(TimeSpan.FromSeconds(5)), Times.Once); } + + /// + /// When CollectDeviceResult sets Success=true (tests completed via app end signal) + /// but the results file copy fails (e.g., devicectl error on tvOS), ParseResult should + /// return Succeeded rather than Crashed, since we already confirmed test completion. + /// + [Fact] + public async Task ParseResult_WhenTestCompletedButResultsUnavailable_ReturnsSucceeded() + { + // Set up listener with a non-existent log file (simulate failed devicectl copy) + var listenerLog = Mock.Of(l => l.FullPath == "/this/path/does/not/exist"); + _listener.Setup(l => l.TestLog).Returns(listenerLog); + + var testReporter = BuildTestReporter(); + + // Simulate mlaunch exiting with 0 (after app end signal detection → RunAndWatchForAppSignal sets ExitCode=0) + var processResult = new ProcessExecutionResult() { TimedOut = false, ExitCode = 0 }; + await testReporter.CollectDeviceResult(processResult); + + // At this point Success=true (set by CollectDeviceResult via CollectResult) + Assert.True(testReporter.Success, "Success should be true after CollectDeviceResult with ExitCode=0"); + + var (result, resultMessage) = await testReporter.ParseResult(); + + // Should return Succeeded, not Crashed, since we know tests completed + Assert.Equal(TestExecutingResult.Succeeded, result); + Assert.True(testReporter.Success, "Success should remain true"); + Assert.Contains("completed but results file was not available", resultMessage); + + _mainLog.Verify(l => l.WriteLine(It.Is(s => s.Contains("Test run completed but results file was not available"))), Times.Once); + // Crash reporter should be called with 0 delay since tests succeeded + _crashReporter.Verify(c => c.EndCaptureAsync(It.Is(t => t.TotalSeconds == 0)), Times.Once); + } } diff --git a/tests/integration-tests/Apple/Simulator.Commands.Tests.proj b/tests/integration-tests/Apple/Simulator.Commands.Tests.proj index bca59f7e7..80bd71faa 100644 --- a/tests/integration-tests/Apple/Simulator.Commands.Tests.proj +++ b/tests/integration-tests/Apple/Simulator.Commands.Tests.proj @@ -1,7 +1,7 @@ - +