Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions .gitignore
Original file line number Diff line number Diff line change
Expand Up @@ -362,3 +362,4 @@ MigrationBackup/
.idea

.vscode/
.nuget/
50 changes: 34 additions & 16 deletions src/Microsoft.DotNet.XHarness.Apple/AppOperations/AppTester.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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);
}
}
}
}
Expand Down Expand Up @@ -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);
}
}
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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}");

Expand Down Expand Up @@ -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;
}
Comment thread
steveisok marked this conversation as resolved.
Comment thread
steveisok marked this conversation as resolved.

// Ensure all asynchronous output/error reads have completed before consuming buffers
collectProcess.WaitForExit();

if (collectErrors.Length > 0)
Expand All @@ -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;
}
}
Expand Down Expand Up @@ -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
{
Comment thread
steveisok marked this conversation as resolved.
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);
Expand Down
52 changes: 39 additions & 13 deletions src/Microsoft.DotNet.XHarness.iOS.Shared/ResultFileHandler.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Expand Down Expand Up @@ -88,20 +93,41 @@ public async Task<bool> 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;
Expand Down
11 changes: 11 additions & 0 deletions src/Microsoft.DotNet.XHarness.iOS.Shared/TestReporter.cs
Original file line number Diff line number Diff line change
Expand Up @@ -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: <b><i>{0} completed but results unavailable</i></b><br/>", _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: <b><i>{0} crashed at startup (no log)</i></b><br/>", _runMode);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -37,9 +37,11 @@ public void Dispose()

private static ResultFileHandler CreateHandler(
Mock<IMlaunchProcessManager> processManagerMock,
Mock<IFileBackedLog> logMock)
Mock<IFileBackedLog> 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<int>());
}

[Fact]
Expand Down Expand Up @@ -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]
Expand Down Expand Up @@ -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]
Expand Down Expand Up @@ -251,6 +253,83 @@ public async Task CopyCrashReportUsesHelixUploadRootWhenAvailable()
}
}

[Fact]
public async Task CopyResultsAsync_WhenFirstAttemptFailsAndSecondSucceeds_ReturnsTrue()
{
Mock<IMlaunchProcessManager> pm = new Mock<IMlaunchProcessManager>();
Mock<IFileBackedLog> log = new Mock<IFileBackedLog>();
// 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<string>(),
It.IsAny<IList<string>>(),
It.IsAny<ILog>(),
It.IsAny<ILog>(),
It.IsAny<ILog>(),
It.IsAny<TimeSpan>(),
It.IsAny<Dictionary<string, string>>(),
It.IsAny<CancellationToken?>()))
.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<string>(s => s.Contains("Retrying results file copy (attempt 2)"))), Times.Once);
}

[Fact]
public async Task CopyResultsAsync_WhenAllRetriesFail_ReturnsFalse()
{
Mock<IMlaunchProcessManager> pm = new Mock<IMlaunchProcessManager>();
Mock<IFileBackedLog> log = new Mock<IFileBackedLog>();
// 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<string>(),
It.IsAny<IList<string>>(),
It.IsAny<ILog>(),
It.IsAny<ILog>(),
It.IsAny<ILog>(),
It.IsAny<TimeSpan>(),
It.IsAny<Dictionary<string, string>>(),
It.IsAny<CancellationToken?>()))
.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<string>(s => s.Contains("Retrying results file copy (attempt 2)"))), Times.Once);
log.Verify(l => l.WriteLine(It.Is<string>(s => s.Contains("Retrying results file copy (attempt 3)"))), Times.Once);
}

private static string GetArgumentValue(MlaunchArguments args, string argumentName)
{
string prefix = $"--{argumentName}=";
Expand Down
Loading
Loading