diff --git a/src/Microsoft.DotNet.XHarness.Android/AdbRunner.cs b/src/Microsoft.DotNet.XHarness.Android/AdbRunner.cs index 31734af81..07506d5c1 100644 --- a/src/Microsoft.DotNet.XHarness.Android/AdbRunner.cs +++ b/src/Microsoft.DotNet.XHarness.Android/AdbRunner.cs @@ -9,6 +9,7 @@ using System.Runtime.InteropServices; using System.Threading; using Microsoft.DotNet.XHarness.Android.Execution; +using Microsoft.DotNet.XHarness.Common.Utilities; using Microsoft.Extensions.Logging; namespace Microsoft.DotNet.XHarness.Android @@ -19,6 +20,7 @@ public class AdbRunner private const string AdbEnvironmentVariableName = "ADB_EXE_PATH"; private const string AdbDeviceFullInstallFailureMessage = "INSTALL_FAILED_INSUFFICIENT_STORAGE"; + private const string AdbInstallBrokenPipeError = "Failure calling service package: Broken pipe"; private const string AdbShellPropertyForBootCompletion = "sys.boot_completed"; private readonly string _absoluteAdbExePath; private readonly ILogger _log; @@ -132,7 +134,7 @@ public void DumpBugReport(string outputFilePath) } } - public void WaitForDevice() + public void WaitForDevice(int timeToWaitForBootCompletionSeconds = 300) { // This command waits for ANY kind of device to be available (emulator or real) // Needed because emulators start up asynchronously and take a while. @@ -146,16 +148,27 @@ public void WaitForDevice() throw new Exception($"Error waiting for Android device/emulator. Std out:{result.StandardOutput} Std. Err: {result.StandardError}. Do you need to set the current device?"); } - // Once wait-for-device returns, we'll give it up to 30s for 'adb shell getprop sys.boot_completed' to be '1' (as opposed to empty) to make package managers happy + // Some users will be installing the emulator and immediately calling xharness, they need to be able to expect the device is ready to load APKs. + // Once wait-for-device returns, we'll give it up to timeToWaitForBootCompletionSeconds seconds (default 5 min) for 'adb shell getprop sys.boot_completed' + // to be '1' (as opposed to empty) to make subsequent automation happy. + var began = DateTimeOffset.UtcNow; + var waitingUntil = began.AddSeconds(timeToWaitForBootCompletionSeconds); var bootCompleted = RunAdbCommand($"shell getprop {AdbShellPropertyForBootCompletion}"); - int triesLeft = 3; - while (!bootCompleted.StandardOutput.Trim().StartsWith("1") && triesLeft > 1) + while (!bootCompleted.StandardOutput.Trim().StartsWith("1") && DateTimeOffset.UtcNow < waitingUntil) { bootCompleted = RunAdbCommand($"shell getprop {AdbShellPropertyForBootCompletion}"); _log.LogDebug($"{AdbShellPropertyForBootCompletion} = '{bootCompleted.StandardOutput.Trim()}'"); Thread.Sleep((int)TimeSpan.FromSeconds(10).TotalMilliseconds); - triesLeft--; + } + + if (bootCompleted.StandardOutput.Trim().StartsWith("1")) + { + _log.LogDebug($"Waited {DateTimeOffset.UtcNow.Subtract(began).TotalSeconds} seconds for device for {AdbShellPropertyForBootCompletion} to be 1."); + } + else + { + _log.LogWarning($"Did not detect boot completion variable on device; variable used ('{AdbShellPropertyForBootCompletion}') may be incorrect or device may be in a bad state"); } } @@ -180,7 +193,6 @@ public void KillAdbServer() public int InstallApk(string apkPath) { - bool needToRetry = false; _log.LogInformation($"Attempting to install {apkPath}: "); if (string.IsNullOrEmpty(apkPath)) { @@ -193,26 +205,23 @@ public int InstallApk(string apkPath) var result = RunAdbCommand($"install \"{apkPath}\""); - // If this keeps happening, we should look into exercising Helix infra retry logic when on Helix - // since users should be able assume tests themselves can't break the ADB server. - if (result.ExitCode == (int)AdbExitCodes.ADB_BROKEN_PIPE) + // Two possible retry scenarios, theoretically both can happen on the same run: + + // 1. Pipe between ADB server and emulator device is broken; restarting the ADB server helps + if (result.ExitCode == (int)AdbExitCodes.ADB_BROKEN_PIPE || result.StandardError.Contains(AdbInstallBrokenPipeError)) { _log.LogWarning($"Hit broken pipe error; Will make one attempt to restart ADB server, then retry the install"); KillAdbServer(); StartAdbServer(); - needToRetry = true; + result = RunAdbCommand($"install \"{apkPath}\""); } + // 2. Installation cache on device is messed up; restarting the device reliably seems to unblock this (unless the device is actually full, if so this will error the same) if (result.ExitCode != (int)AdbExitCodes.SUCCESS && result.StandardError.Contains(AdbDeviceFullInstallFailureMessage)) { _log.LogWarning($"It seems the package installation cache may be full on the device. We'll try to reboot it before trying one more time.{Environment.NewLine}Output:{result}"); RebootAndroidDevice(); WaitForDevice(); - needToRetry = true; - } - - if (needToRetry) - { result = RunAdbCommand($"install \"{apkPath}\""); } @@ -224,6 +233,7 @@ public int InstallApk(string apkPath) { _log.LogInformation($"Successfully installed {apkPath}."); } + return result.ExitCode; } @@ -318,7 +328,8 @@ public List PullFiles(string devicePath, string localPath) if (result.ExitCode != (int)AdbExitCodes.SUCCESS) { - _log.LogError(message: $"ERROR: {result}"); + throw new Exception($"Failed pulling files: {result}"); + } else { @@ -442,8 +453,9 @@ public void PushFiles(string localDirectory, string devicePath, bool removeIfPre } else { - // May consider abandoning the run here instead of just printing errors. + // Abandon the run here, don't just guess. _log.LogError($"Error: listing attached devices / emulators: {result.StandardError}. Check that any emulators have been started, and attached device(s) are connected via USB, powered-on, and unlocked."); + throw new Exception("One or more attached Android devices are offline"); } return devicesAndArchitectures; } diff --git a/src/Microsoft.DotNet.XHarness.CLI/Commands/Android/AndroidTestCommand.cs b/src/Microsoft.DotNet.XHarness.CLI/Commands/Android/AndroidTestCommand.cs index 2e86f96a5..d81648d7d 100644 --- a/src/Microsoft.DotNet.XHarness.CLI/Commands/Android/AndroidTestCommand.cs +++ b/src/Microsoft.DotNet.XHarness.CLI/Commands/Android/AndroidTestCommand.cs @@ -13,6 +13,7 @@ using Microsoft.DotNet.XHarness.Common.CLI; using Microsoft.DotNet.XHarness.Common.CLI.CommandArguments; using Microsoft.DotNet.XHarness.Common.CLI.Commands; +using Microsoft.DotNet.XHarness.Common.Utilities; using Microsoft.Extensions.Logging; namespace Microsoft.DotNet.XHarness.CLI.Commands.Android @@ -95,7 +96,14 @@ protected override Task InvokeInternal(ILogger logger) // enumerate the devices attached and their architectures // Tell ADB to only use that one (will always use the present one for systems w/ only 1 machine) - runner.SetActiveDevice(GetDeviceToUse(logger, runner, apkRequiredArchitecture)); + var deviceToUse = GetDeviceToUse(logger, runner, apkRequiredArchitecture); + + if (deviceToUse == null) + { + return Task.FromResult(ExitCode.ADB_DEVICE_ENUMERATION_FAILURE); + } + + runner.SetActiveDevice(deviceToUse); // Wait til at least device(s) are ready runner.WaitForDevice(); @@ -120,6 +128,7 @@ protected override Task InvokeInternal(ILogger logger) // No class name = default Instrumentation ProcessExecutionResults? result = runner.RunApkInstrumentation(apkPackageName, _arguments.InstrumentationName, _arguments.InstrumentationArguments, _arguments.Timeout); bool processCrashed = false; + bool failurePullingFiles = false; using (logger.BeginScope("Post-test copy and cleanup")) { @@ -136,7 +145,15 @@ protected override Task InvokeInternal(ILogger logger) if (resultValues.ContainsKey(possibleResultKey)) { logger.LogInformation($"Found XML result file: '{resultValues[possibleResultKey]}'(key: {possibleResultKey})"); - runner.PullFiles(resultValues[possibleResultKey], _arguments.OutputDirectory); + try + { + runner.PullFiles(resultValues[possibleResultKey], _arguments.OutputDirectory); + } + catch (Exception toLog) + { + logger.LogError(toLog, "Hit error (typically permissions) trying to pull {filePathOnDevice}", resultValues[possibleResultKey]); + failurePullingFiles = true; + } } } if (resultValues.ContainsKey(TestRunSummaryVariableName)) @@ -174,10 +191,18 @@ protected override Task InvokeInternal(ILogger logger) // Optionally copy off an entire folder if (!string.IsNullOrEmpty(_arguments.DeviceOutputFolder)) { - var logs = runner.PullFiles(_arguments.DeviceOutputFolder, _arguments.OutputDirectory); - foreach (string log in logs) + try + { + var logs = runner.PullFiles(_arguments.DeviceOutputFolder, _arguments.OutputDirectory); + foreach (string log in logs) + { + logger.LogDebug($"Found output file: {log}"); + } + } + catch (Exception toLog) { - logger.LogDebug($"Found output file: {log}"); + logger.LogError(toLog, "Hit error (typically permissions) trying to pull {filePathOnDevice}", _arguments.DeviceOutputFolder); + failurePullingFiles = true; } } @@ -195,6 +220,11 @@ protected override Task InvokeInternal(ILogger logger) { logger.LogError($"Non-success instrumentation exit code: {instrumentationExitCode}, expected: {_arguments.ExpectedExitCode}"); } + else if (failurePullingFiles) + { + logger.LogError($"Received expected instrumentation exit code ({instrumentationExitCode}), but we hit errors pulling files from the device (see log for details.)"); + return Task.FromResult(ExitCode.DEVICE_FILE_COPY_FAILURE); + } else { return Task.FromResult(ExitCode.SUCCESS); @@ -210,23 +240,35 @@ protected override Task InvokeInternal(ILogger logger) private string? GetDeviceToUse(ILogger logger, AdbRunner runner, string apkRequiredArchitecture) { - var allDevicesAndTheirArchitectures = runner.GetAttachedDevicesAndArchitectures(); - if (allDevicesAndTheirArchitectures.Count > 0) + Dictionary allDevicesAndTheirArchitectures = new Dictionary(); + try { - if (allDevicesAndTheirArchitectures.Any(kvp => kvp.Value != null && kvp.Value.Equals(apkRequiredArchitecture, StringComparison.OrdinalIgnoreCase))) - { - var firstAvailableCompatible = allDevicesAndTheirArchitectures.Where(kvp => kvp.Value != null && kvp.Value.Equals(apkRequiredArchitecture, StringComparison.OrdinalIgnoreCase)).FirstOrDefault(); - logger.LogInformation($"Using first-found compatible device of {allDevicesAndTheirArchitectures.Count} total- serial: '{firstAvailableCompatible.Key}' - Arch: {firstAvailableCompatible.Value}"); - return firstAvailableCompatible.Key; - } - else - { - logger.LogWarning($"No devices found with architecture '{apkRequiredArchitecture}'. Just returning first available device; installation will likely fail, but we'll try anyways."); - return allDevicesAndTheirArchitectures.Keys.First(); - } + allDevicesAndTheirArchitectures = runner.GetAttachedDevicesAndArchitectures(); + } + catch (Exception toLog) + { + logger.LogError(toLog, "Exception thrown while trying to find compatible device with architecture {architecture}", apkRequiredArchitecture); + } + + if (allDevicesAndTheirArchitectures.Count == 0) + { + logger.LogError("No attached device detected"); + return null; + } + + if (allDevicesAndTheirArchitectures.Any(kvp => kvp.Value.Equals(apkRequiredArchitecture, StringComparison.OrdinalIgnoreCase))) + { + // Key-value tuples here are of the form + KeyValuePair firstAvailableCompatible = allDevicesAndTheirArchitectures.FirstOrDefault(kvp => apkRequiredArchitecture.Equals(kvp.Value, StringComparison.OrdinalIgnoreCase)); + logger.LogInformation($"Using first-found compatible device of {allDevicesAndTheirArchitectures.Count} total- serial: '{firstAvailableCompatible.Key}' - Arch: {firstAvailableCompatible.Value}"); + return firstAvailableCompatible.Key; + } + else + { + // In this case, the enumeration worked, we found one or more devices, but nothing matched the APK's architecture; fail out. + logger.LogError($"No devices found with architecture '{apkRequiredArchitecture}'."); + return null; } - logger.LogError("No attached device detected"); - return null; } private (Dictionary values, int exitCode) ParseInstrumentationOutputs(ILogger logger, string stdOut) diff --git a/src/Microsoft.DotNet.XHarness.Common/CLI/ExitCode.cs b/src/Microsoft.DotNet.XHarness.Common/CLI/ExitCode.cs index f1e589af3..f0d29002b 100644 --- a/src/Microsoft.DotNet.XHarness.Common/CLI/ExitCode.cs +++ b/src/Microsoft.DotNet.XHarness.Common/CLI/ExitCode.cs @@ -51,6 +51,8 @@ public enum ExitCode DEVICE_NOT_FOUND = 81, RETURN_CODE_NOT_SET = 82, APP_LAUNCH_FAILURE = 83, + DEVICE_FILE_COPY_FAILURE = 84, + ADB_DEVICE_ENUMERATION_FAILURE = 85, #endregion }