From c1f8287aa98f6975a18bdc60692343d638540dec Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?P=C5=99emek=20Vysok=C3=BD?= Date: Fri, 18 Jun 2021 19:40:24 +0200 Subject: [PATCH] Add `--signal-app-end` to detect test run end for iOS/tvOS 14+ devices (#643) Signals the test runner to log a given tag at the end of the test run and ends the test run. Useful for iOS/tvOS 14+ where mlaunch cannot detect the app quit. This functionality should be eventually superseded by a full protocol between the app and XHarness but this way keeps it backwards compatible and also won't break Xamarin who is sharing some of the code. --- README.md | 25 +++ .../AppOperations/AppRunner.cs | 190 +++++++++++------- .../AppOperations/AppRunnerBase.cs | 44 ++++ .../AppOperations/AppTester.cs | 108 +++++++--- .../Orchestration/RunOrchestrator.cs | 15 +- .../Orchestration/TestOrchestrator.cs | 67 ++++-- .../Apple/AppleJustRunCommandArguments.cs | 2 + .../Apple/AppleJustTestCommandArguments.cs | 2 + .../Apple/AppleRunCommandArguments.cs | 2 + .../Apple/AppleTestCommandArguments.cs | 2 + .../Apple/Arguments/SignalAppEndArgument.cs | 16 ++ .../Commands/Apple/AppleJustRunCommand.cs | 1 + .../Commands/Apple/AppleJustTestCommand.cs | 7 +- .../Commands/Apple/AppleRunCommand.cs | 1 + .../Commands/Apple/AppleTestCommand.cs | 7 +- .../Logging/Log.cs | 2 +- .../Logging/ScanLog.cs | 90 +++++++++ .../ApplicationOptions.cs | 13 +- .../AndroidApplicationEntryPoint.cs | 6 + .../iOSApplicationEntryPoint.cs | 5 + .../Execution/EnviromentVariables.cs | 7 +- .../Listeners/SimpleListener.cs | 1 + .../Listeners/SimpleTcpListener.cs | 30 ++- .../Logging/DeviceLogCapturer.cs | 4 +- .../Utilities/Helpers.cs | 4 + .../AppRunTestBase.cs | 8 +- .../AppRunnerTests.cs | 128 +++++++++++- .../AppTesterTests.cs | 173 ++++++++++++++-- .../Logging/ScanLogTest.cs | 36 ++++ .../Apple/Device.Commands.Tests.proj | 12 +- 30 files changed, 826 insertions(+), 182 deletions(-) create mode 100644 src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/Arguments/SignalAppEndArgument.cs create mode 100644 src/Microsoft.DotNet.XHarness.Common/Logging/ScanLog.cs create mode 100644 tests/Microsoft.DotNet.XHarness.Common.Tests/Logging/ScanLogTest.cs diff --git a/README.md b/README.md index 203815cb03db3..f6b663eebd491 100644 --- a/README.md +++ b/README.md @@ -180,6 +180,31 @@ To run the E2E tests, you can find a script in `tools/` that will build everythi ./tools/run-e2e-test.sh Apple/Simulator.Tests.proj ``` +## Troubleshooting + +Some XHarness commands only work in some scenarios and it's good to know what to expect from the tool. +Some Android/Apple versions also require some workarounds and those are also good to know about. + +### My Apple unit tests are not running + +For the `apple test` command, XHarness expects the application to contain a `TestRunner` which is a library you can find in this repository. +This library executes unit tests similarly how you would execute them on other platforms. +However, the `TestRunner` from this repository contains more mechanisms that help to work around some issues (mostly in Apple platforms). + +The way it works is that XHarness usually sets some [environmental variables](https://github.com/dotnet/xharness/blob/main/src/Microsoft.DotNet.XHarness.iOS.Shared/Execution/EnviromentVariables.cs) for the application and the [`TestRunner` recognizes them](https://github.com/dotnet/xharness/blob/main/src/Microsoft.DotNet.XHarness.TestRunners.Common/ApplicationOptions.cs) and acts upon them. + +The workarounds we talk about are for example some TCP connections between the app and XHarness so that we can stream back the test results. + +For these reasons, the `test` command won't just work with any app. For those scenarios, use the `apple run` commands. + +### iOS/tvOS device runs are timing out + +For iOS/tvOS 14+, we have problems detecting when the application exits on the real device (simulators work fine). +The workaround we went with lies in sharing a random string with the application using an [environmental variable `APP_END_TAG`](https://github.com/dotnet/xharness/blob/main/src/Microsoft.DotNet.XHarness.iOS.Shared/Execution/EnviromentVariables.cs) and expecting the app to output this string at the end of its run. + +To turn this workaround on, run XHarness with `--signal-app-end` and make sure your application logs the string it reads from the env variable. +Using the `TestRunner` from this repository will automatically give you this functionality. + ## Contribution We welcome contributions! Please follow the [Code of Conduct](CODE_OF_CONDUCT.md). diff --git a/src/Microsoft.DotNet.XHarness.Apple/AppOperations/AppRunner.cs b/src/Microsoft.DotNet.XHarness.Apple/AppOperations/AppRunner.cs index 38cb47df7fcd3..5b74427c36ed8 100644 --- a/src/Microsoft.DotNet.XHarness.Apple/AppOperations/AppRunner.cs +++ b/src/Microsoft.DotNet.XHarness.Apple/AppOperations/AppRunner.cs @@ -42,7 +42,7 @@ public AppRunner( ILogs logs, IHelpers helpers, Action? logCallback = null) - : base(processManager, captureLogFactory, logs, mainLog, logCallback) + : base(processManager, captureLogFactory, logs, mainLog, helpers, logCallback) { _processManager = processManager ?? throw new ArgumentNullException(nameof(processManager)); _snapshotReporterFactory = snapshotReporterFactory ?? throw new ArgumentNullException(nameof(snapshotReporterFactory)); @@ -56,16 +56,33 @@ public AppRunner( public async Task RunMacCatalystApp( AppBundleInformation appInformation, TimeSpan timeout, + bool signalAppEnd, IEnumerable extraAppArguments, IEnumerable<(string, string)> extraEnvVariables, CancellationToken cancellationToken = default) { _mainLog.WriteLine($"*** Executing '{appInformation.AppName}' on MacCatalyst ***"); + var appOutputLog = _logs.Create(appInformation.BundleIdentifier + ".log", LogType.ApplicationLog.ToString(), timestamp: true); var envVariables = new Dictionary(); AddExtraEnvVars(envVariables, extraEnvVariables); - return await RunMacCatalystApp(appInformation, timeout, extraAppArguments ?? Enumerable.Empty(), envVariables, cancellationToken); + if (signalAppEnd) + { + WatchForAppEndTag(out var appEndTag, ref appOutputLog, ref cancellationToken); + envVariables.Add(EnviromentVariables.AppEndTag, appEndTag); + } + + using (appOutputLog) + { + return await RunAndWatchForAppSignal(() => RunMacCatalystApp( + appInformation, + appOutputLog, + timeout, + extraAppArguments ?? Enumerable.Empty(), + envVariables, + cancellationToken)); + } } public async Task RunApp( @@ -74,6 +91,7 @@ public async Task RunApp( IDevice device, IDevice? companionDevice, TimeSpan timeout, + bool signalAppEnd, IEnumerable extraAppArguments, IEnumerable<(string, string)> extraEnvVariables, CancellationToken cancellationToken = default) @@ -84,6 +102,7 @@ public async Task RunApp( var isSimulator = target.Platform.IsSimulator(); using var crashLogs = new Logs(_logs.Directory); + var appOutputLog = _logs.Create(appInformation.BundleIdentifier + ".log", LogType.ApplicationLog.ToString(), timestamp: true); ICrashSnapshotReporter crashReporter = _snapshotReporterFactory.Create( _mainLog, @@ -93,50 +112,63 @@ public async Task RunApp( _mainLog.WriteLine($"*** Executing '{appInformation.AppName}' on {target.AsString()} '{device.Name}' ***"); - if (isSimulator) + string? appEndTag = null; + if (signalAppEnd) { - simulator = device as ISimulatorDevice; - companionSimulator = companionDevice as ISimulatorDevice; + WatchForAppEndTag(out appEndTag, ref appOutputLog, ref cancellationToken); + } - if (simulator == null) + using (appOutputLog) + { + if (isSimulator) { - _mainLog.WriteLine("Didn't find any suitable simulator"); - throw new NoDeviceFoundException(); + simulator = device as ISimulatorDevice; + companionSimulator = companionDevice as ISimulatorDevice; + + if (simulator == null) + { + _mainLog.WriteLine("Didn't find any suitable simulator"); + throw new NoDeviceFoundException(); + } + + var mlaunchArguments = GetSimulatorArguments( + appInformation, + simulator, + extraAppArguments, + extraEnvVariables, + appEndTag); + + result = await RunSimulatorApp( + mlaunchArguments, + crashReporter, + simulator, + companionSimulator, + appOutputLog, + timeout, + cancellationToken); + } + else + { + var mlaunchArguments = GetDeviceArguments( + appInformation, + device, + target.Platform.IsWatchOSTarget(), + extraAppArguments, + extraEnvVariables, + appEndTag); + + result = await RunDeviceApp( + mlaunchArguments, + crashReporter, + device, + appOutputLog, + extraEnvVariables, + timeout, + cancellationToken); } - var mlaunchArguments = GetSimulatorArguments( - appInformation, - simulator, - extraAppArguments, - extraEnvVariables); - - result = await RunSimulatorApp( - mlaunchArguments, - crashReporter, - simulator, - companionSimulator, - timeout, - cancellationToken); + return result; } - else - { - var mlaunchArguments = GetDeviceArguments( - appInformation, - device, - target.Platform.IsWatchOSTarget(), - extraAppArguments, - extraEnvVariables); - - result = await RunDeviceApp( - mlaunchArguments, - crashReporter, - device, - extraEnvVariables, - timeout, - cancellationToken); - } - - return result; } private async Task RunSimulatorApp( @@ -144,6 +176,7 @@ private async Task RunSimulatorApp( ICrashSnapshotReporter crashReporter, ISimulatorDevice simulator, ISimulatorDevice? companionSimulator, + ILog appOutputLog, TimeSpan timeout, CancellationToken cancellationToken) { @@ -182,72 +215,72 @@ private async Task RunSimulatorApp( _mainLog.WriteLine("Starting test run"); - return await _processManager.ExecuteCommandAsync(mlaunchArguments, _mainLog, timeout, cancellationToken: cancellationToken); + return await RunAndWatchForAppSignal(() => _processManager.ExecuteCommandAsync( + mlaunchArguments, + _mainLog, + appOutputLog, + appOutputLog, + timeout, + cancellationToken: cancellationToken)); } private async Task RunDeviceApp( MlaunchArguments mlaunchArguments, ICrashSnapshotReporter crashReporter, IDevice device, + ILog appOutputLog, IEnumerable<(string, string)> extraEnvVariables, TimeSpan timeout, CancellationToken cancellationToken) { - var deviceSystemLog = _logs.Create($"device-{device.Name}-{_helpers.Timestamp}.log", LogType.SystemLog.ToString()); - var deviceLogCapturer = _deviceLogCapturerFactory.Create(_mainLog, deviceSystemLog, device.Name); + using var deviceSystemLog = _logs.Create($"device-{device.Name}-{_helpers.Timestamp}.log", LogType.SystemLog.ToString()); + using var deviceLogCapturer = _deviceLogCapturerFactory.Create(_mainLog, deviceSystemLog, device.Name); deviceLogCapturer.StartCapture(); - try - { - await crashReporter.StartCaptureAsync(); + await crashReporter.StartCaptureAsync(); - _mainLog.WriteLine("Starting the app"); + _mainLog.WriteLine("Starting the app"); - var envVars = new Dictionary(); - AddExtraEnvVars(envVars, extraEnvVariables); + var envVars = new Dictionary(); + AddExtraEnvVars(envVars, extraEnvVariables); - return await _processManager.ExecuteCommandAsync( - mlaunchArguments, - _mainLog, - timeout, - envVars, - cancellationToken: cancellationToken); - } - finally - { - deviceLogCapturer.StopCapture(); - deviceSystemLog.Dispose(); - } + return await RunAndWatchForAppSignal(() => _processManager.ExecuteCommandAsync( + mlaunchArguments, + _mainLog, + appOutputLog, + appOutputLog, + timeout, + envVars, + cancellationToken: cancellationToken)); } - private MlaunchArguments GetCommonArguments( - AppBundleInformation appInformation, + private static MlaunchArguments GetCommonArguments( IEnumerable extraAppArguments, - IEnumerable<(string, string)> extraEnvVariables) + IEnumerable<(string, string)> extraEnvVariables, + string? appEndTag) { - string appOutputLog = _logs.CreateFile($"{appInformation.BundleIdentifier}.log", LogType.ApplicationLog); - string appErrorOutputLog = _logs.CreateFile($"{appInformation.BundleIdentifier}.err.log", LogType.ApplicationLog); - - var args = new MlaunchArguments - { - new SetStdoutArgument(appOutputLog), - new SetStderrArgument(appErrorOutputLog), - }; + var args = new MlaunchArguments(); // Arguments passed to the iOS app bundle args.AddRange(extraAppArguments.Select(arg => new SetAppArgumentArgument(arg))); args.AddRange(extraEnvVariables.Select(v => new SetEnvVariableArgument(v.Item1, v.Item2))); + if (appEndTag != null) + { + args.Add(new SetEnvVariableArgument(EnviromentVariables.AppEndTag, appEndTag)); + } + return args; } - private MlaunchArguments GetSimulatorArguments( + private static MlaunchArguments GetSimulatorArguments( AppBundleInformation appInformation, ISimulatorDevice simulator, IEnumerable extraAppArguments, - IEnumerable<(string, string)> extraEnvVariables) + IEnumerable<(string, string)> extraEnvVariables, + string? appEndTag) { - var args = GetCommonArguments(appInformation, extraAppArguments, extraEnvVariables); + var args = GetCommonArguments(extraAppArguments, extraEnvVariables, appEndTag); args.Add(new SimulatorUDIDArgument(simulator.UDID)); @@ -271,14 +304,15 @@ private MlaunchArguments GetSimulatorArguments( return args; } - private MlaunchArguments GetDeviceArguments( + private static MlaunchArguments GetDeviceArguments( AppBundleInformation appInformation, IDevice device, bool isWatchTarget, IEnumerable extraAppArguments, - IEnumerable<(string, string)> extraEnvVariables) + IEnumerable<(string, string)> extraEnvVariables, + string? appEndTag) { - var args = GetCommonArguments(appInformation, extraAppArguments, extraEnvVariables); + var args = GetCommonArguments(extraAppArguments, extraEnvVariables, appEndTag); args.Add(new DisableMemoryLimitsArgument()); args.Add(new DeviceNameArgument(device)); diff --git a/src/Microsoft.DotNet.XHarness.Apple/AppOperations/AppRunnerBase.cs b/src/Microsoft.DotNet.XHarness.Apple/AppOperations/AppRunnerBase.cs index ec39051f42bb9..6d8c31ddb929d 100644 --- a/src/Microsoft.DotNet.XHarness.Apple/AppOperations/AppRunnerBase.cs +++ b/src/Microsoft.DotNet.XHarness.Apple/AppOperations/AppRunnerBase.cs @@ -11,6 +11,7 @@ using Microsoft.DotNet.XHarness.Common.Logging; using Microsoft.DotNet.XHarness.iOS.Shared; using Microsoft.DotNet.XHarness.iOS.Shared.Logging; +using Microsoft.DotNet.XHarness.iOS.Shared.Utilities; namespace Microsoft.DotNet.XHarness.Apple { @@ -21,18 +22,23 @@ public abstract class AppRunnerBase private readonly IProcessManager _processManager; private readonly ICaptureLogFactory _captureLogFactory; private readonly ILogs _logs; + private readonly IHelpers _helpers; private readonly IFileBackedLog _mainLog; + private bool _appEndSignalDetected = false; + protected AppRunnerBase( IProcessManager processManager, ICaptureLogFactory captureLogFactory, ILogs logs, IFileBackedLog mainLog, + IHelpers helpers, Action? logCallback = null) { _processManager = processManager ?? throw new ArgumentNullException(nameof(processManager)); _captureLogFactory = captureLogFactory ?? throw new ArgumentNullException(nameof(captureLogFactory)); _logs = logs ?? throw new ArgumentNullException(nameof(logs)); + _helpers = helpers ?? throw new ArgumentNullException(nameof(helpers)); if (logCallback == null) { @@ -47,6 +53,7 @@ protected AppRunnerBase( protected async Task RunMacCatalystApp( AppBundleInformation appInfo, + ILog appOutputLog, TimeSpan timeout, IEnumerable extraArguments, Dictionary environmentVariables, @@ -87,6 +94,8 @@ protected async Task RunMacCatalystApp( "open", arguments, _mainLog, + appOutputLog, + appOutputLog, timeout, environmentVariables, cancellationToken); @@ -117,5 +126,40 @@ protected void AddExtraEnvVars(Dictionary envVariables, IEnumera envVariables[name] = value; } } + + protected string WatchForAppEndTag( + out string tag, + ref IFileBackedLog appLog, + ref CancellationToken cancellationToken) + { + tag = _helpers.GenerateGuid().ToString(); + var appEndDetected = new CancellationTokenSource(); + var appEndScanner = new ScanLog(tag, () => + { + _mainLog.WriteLine("Detected test end tag in application's output"); + _appEndSignalDetected = true; + appEndDetected.Cancel(); + }); + + // We need to check for test end tag since iOS 14+ doesn't send the pidDiedCallback event to mlaunch + appLog = Log.CreateReadableAggregatedLog(appLog, appEndScanner); + cancellationToken = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken, appEndDetected.Token).Token; + + return tag; + } + + protected async Task RunAndWatchForAppSignal(Func> action) + { + var result = await action(); + + // When signal is detected, we cancel the call above via the cancellation token so we need to fix the result + if (_appEndSignalDetected) + { + result.TimedOut = false; + result.ExitCode = 0; + } + + return result; + } } } diff --git a/src/Microsoft.DotNet.XHarness.Apple/AppOperations/AppTester.cs b/src/Microsoft.DotNet.XHarness.Apple/AppOperations/AppTester.cs index 077e61815c78d..61a375bbfb2c3 100644 --- a/src/Microsoft.DotNet.XHarness.Apple/AppOperations/AppTester.cs +++ b/src/Microsoft.DotNet.XHarness.Apple/AppOperations/AppTester.cs @@ -49,7 +49,7 @@ public AppTester( ILogs logs, IHelpers helpers, Action? logCallback = null) - : base(processManager, captureLogFactory, logs, mainLog, logCallback) + : base(processManager, captureLogFactory, logs, mainLog, helpers, logCallback) { _processManager = processManager ?? throw new ArgumentNullException(nameof(processManager)); _listenerFactory = simpleListenerFactory ?? throw new ArgumentNullException(nameof(simpleListenerFactory)); @@ -67,6 +67,7 @@ public AppTester( AppBundleInformation appInformation, TimeSpan timeout, TimeSpan testLaunchTimeout, + bool signalAppEnd, IEnumerable extraAppArguments, IEnumerable<(string, string)> extraEnvVariables, XmlResultJargon xmlResultJargon = XmlResultJargon.xUnit, @@ -74,23 +75,32 @@ public AppTester( string[]? skippedTestClasses = null, CancellationToken cancellationToken = default) { - using var deviceListenerLog = _logs.Create($"test-maccatalyst-{_helpers.Timestamp}.log", LogType.TestLog.ToString(), timestamp: true); + var testLog = _logs.Create($"test-{TestTarget.MacCatalyst.AsString()}-{_helpers.Timestamp}.log", LogType.TestLog.ToString(), timestamp: false); + var appOutputLog = _logs.Create(appInformation.BundleIdentifier + ".log", LogType.ApplicationLog.ToString(), timestamp: true); var (deviceListenerTransport, deviceListener, deviceListenerTmpFile) = _listenerFactory.Create( RunMode.MacOS, log: _mainLog, - testLog: deviceListenerLog, + testLog: testLog, isSimulator: true, autoExit: true, xmlOutput: true); - using(deviceListener) + string? appEndTag = null; + if (signalAppEnd) + { + WatchForAppEndTag(out appEndTag, ref appOutputLog, ref cancellationToken); + } + + using (testLog) + using (deviceListener) { var (catalystTestResult, catalystResultMessage) = await RunMacCatalystTests( deviceListenerTransport, deviceListener, deviceListenerTmpFile, appInformation, + appOutputLog, timeout, testLaunchTimeout, xmlResultJargon, @@ -98,6 +108,7 @@ public AppTester( skippedTestClasses, extraAppArguments, extraEnvVariables, + appEndTag, cancellationToken); return (catalystTestResult, catalystResultMessage); @@ -111,6 +122,7 @@ public AppTester( IDevice? companionDevice, TimeSpan timeout, TimeSpan testLaunchTimeout, + bool signalAppEnd, IEnumerable extraAppArguments, IEnumerable<(string, string)> extraEnvVariables, XmlResultJargon xmlResultJargon = XmlResultJargon.xUnit, @@ -121,16 +133,25 @@ public AppTester( var runMode = target.Platform.ToRunMode(); var isSimulator = target.Platform.IsSimulator(); - using var deviceListenerLog = _logs.Create($"test-{target.AsString()}-{_helpers.Timestamp}.log", LogType.TestLog.ToString(), timestamp: false); + var testLog = _logs.Create($"test-{target.AsString()}-{_helpers.Timestamp}.log", LogType.TestLog.ToString(), timestamp: false); + var appOutputLog = _logs.Create(appInformation.BundleIdentifier + ".log", LogType.ApplicationLog.ToString(), timestamp: true); var (deviceListenerTransport, deviceListener, deviceListenerTmpFile) = _listenerFactory.Create( runMode, log: _mainLog, - testLog: deviceListenerLog, + testLog: testLog, isSimulator: isSimulator, autoExit: true, xmlOutput: true); // cli always uses xml + string? appEndTag = null; + if (signalAppEnd) + { + WatchForAppEndTag(out appEndTag , ref appOutputLog, ref cancellationToken); + } + + using (testLog) + using (appOutputLog) using (deviceListener) { var deviceListenerPort = deviceListener.InitializeAndGetPort(); @@ -174,7 +195,8 @@ public AppTester( deviceListenerPort, deviceListenerTmpFile, extraAppArguments, - extraEnvVariables); + extraEnvVariables, + appEndTag); await RunSimulatorTests( mlaunchArguments, @@ -182,6 +204,7 @@ await RunSimulatorTests( testReporter, (ISimulatorDevice)device, companionDevice as ISimulatorDevice, + appOutputLog, timeout, combinedCancellationToken.Token); } @@ -198,7 +221,8 @@ await RunSimulatorTests( deviceListenerPort, deviceListenerTmpFile, extraAppArguments, - extraEnvVariables); + extraEnvVariables, + appEndTag); await RunDeviceTests( mlaunchArguments, @@ -206,6 +230,7 @@ await RunDeviceTests( testReporter, deviceListener, device, + appOutputLog, timeout, extraEnvVariables, combinedCancellationToken.Token); @@ -222,6 +247,7 @@ private async Task RunSimulatorTests( ITestReporter testReporter, ISimulatorDevice simulator, ISimulatorDevice? companionSimulator, + ILog appOutputLog, TimeSpan timeout, CancellationToken cancellationToken) { @@ -260,7 +286,14 @@ private async Task RunSimulatorTests( _mainLog.WriteLine("Starting test run"); - var result = await _processManager.ExecuteCommandAsync(mlaunchArguments, _mainLog, timeout, cancellationToken: cancellationToken); + var result = await RunAndWatchForAppSignal(() => _processManager.ExecuteCommandAsync( + mlaunchArguments, + _mainLog, + appOutputLog, + appOutputLog, + timeout, + cancellationToken: cancellationToken)); + await testReporter.CollectSimulatorResult(result); } @@ -270,6 +303,7 @@ private async Task RunDeviceTests( ITestReporter testReporter, ISimpleListener deviceListener, IDevice device, + ILog appOutputLog, TimeSpan timeout, IEnumerable<(string, string)> extraEnvVariables, CancellationToken cancellationToken) @@ -299,14 +333,17 @@ private async Task RunDeviceTests( var envVars = new Dictionary(); AddExtraEnvVars(envVars, extraEnvVariables); - // We need to check for MT1111 (which means that mlaunch won't wait for the app to exit). - var aggregatedLog = Log.CreateReadableAggregatedLog(_mainLog, testReporter.CallbackLog); - var result = await _processManager.ExecuteCommandAsync( + // We need to check for MT1111 (which means that mlaunch won't wait for the app to exit) + IFileBackedLog aggregatedLog = Log.CreateReadableAggregatedLog(_mainLog, testReporter.CallbackLog); + + var result = await RunAndWatchForAppSignal(() => _processManager.ExecuteCommandAsync( mlaunchArguments, aggregatedLog, + appOutputLog, + appOutputLog, timeout, envVars, - cancellationToken: cancellationToken); + cancellationToken: cancellationToken)); await testReporter.CollectDeviceResult(result); } @@ -337,6 +374,7 @@ private async Task RunDeviceTests( ISimpleListener deviceListener, string deviceListenerTmpFile, AppBundleInformation appInformation, + ILog appOutputLog, TimeSpan timeout, TimeSpan testLaunchTimeout, XmlResultJargon xmlResultJargon, @@ -344,6 +382,7 @@ private async Task RunDeviceTests( string[]? skippedTestClasses, IEnumerable extraAppArguments, IEnumerable<(string, string)> extraEnvVariables, + string? appEndTag, CancellationToken cancellationToken) { var deviceListenerPort = deviceListener.InitializeAndGetPort(); @@ -385,7 +424,8 @@ private async Task RunDeviceTests( deviceListenerTransport, deviceListenerPort, deviceListenerTmpFile, - extraEnvVariables); + extraEnvVariables, + appEndTag); envVariables[EnviromentVariables.HostName] = "127.0.0.1"; @@ -393,7 +433,7 @@ private async Task RunDeviceTests( await crashReporter.StartCaptureAsync(); - var result = await RunMacCatalystApp(appInformation, timeout, extraAppArguments, envVariables, combinedCancellationToken.Token); + var result = await RunMacCatalystApp(appInformation, appOutputLog, timeout, extraAppArguments, envVariables, combinedCancellationToken.Token); await testReporter.CollectSimulatorResult(result); } finally @@ -411,7 +451,8 @@ private Dictionary GetEnvVariables( ListenerTransport listenerTransport, int listenerPort, string listenerTmpFile, - IEnumerable<(string, string)> extraEnvVariables) + IEnumerable<(string, string)> extraEnvVariables, + string? appEndTag) { var variables = new Dictionary { @@ -447,13 +488,17 @@ private Dictionary GetEnvVariables( variables.Add(EnviromentVariables.LogFilePath, listenerTmpFile); } + if (appEndTag != null) + { + variables.Add(EnviromentVariables.AppEndTag, appEndTag); + } + AddExtraEnvVars(variables, extraEnvVariables); return variables; } private MlaunchArguments GetCommonArguments( - AppBundleInformation appInformation, XmlResultJargon xmlResultJargon, string[]? skippedMethods, string[]? skippedTestClasses, @@ -461,16 +506,10 @@ private MlaunchArguments GetCommonArguments( int listenerPort, string listenerTmpFile, IEnumerable extraAppArguments, - IEnumerable<(string, string)> extraEnvVariables) + IEnumerable<(string, string)> extraEnvVariables, + string? appEndTag) { - string appOutputLog = _logs.CreateFile($"{appInformation.BundleIdentifier}.log", LogType.ApplicationLog); - string appErrorOutputLog = _logs.CreateFile($"{appInformation.BundleIdentifier}.err.log", LogType.ApplicationLog); - - var args = new MlaunchArguments - { - new SetStdoutArgument(appOutputLog), - new SetStderrArgument(appErrorOutputLog), - }; + var args = new MlaunchArguments(); // Environment variables var envVariables = GetEnvVariables( @@ -480,7 +519,8 @@ private MlaunchArguments GetCommonArguments( listenerTransport, listenerPort, listenerTmpFile, - extraEnvVariables); + extraEnvVariables, + appEndTag); // Variables passed through --set-env args.AddRange(envVariables.Select(pair => new SetEnvVariableArgument(pair.Key, pair.Value))); @@ -501,10 +541,10 @@ private MlaunchArguments GetSimulatorArguments( int deviceListenerPort, string deviceListenerTmpFile, IEnumerable extraAppArguments, - IEnumerable<(string, string)> extraEnvVariables) + IEnumerable<(string, string)> extraEnvVariables, + string? appEndTag) { var args = GetCommonArguments( - appInformation, xmlResultJargon, skippedMethods, skippedTestClasses, @@ -512,7 +552,8 @@ private MlaunchArguments GetSimulatorArguments( deviceListenerPort, deviceListenerTmpFile, extraAppArguments, - extraEnvVariables); + extraEnvVariables, + appEndTag); args.Add(new SetEnvVariableArgument(EnviromentVariables.HostName, "127.0.0.1")); args.Add(new SimulatorUDIDArgument(simulator)); @@ -548,10 +589,10 @@ private MlaunchArguments GetDeviceArguments( int deviceListenerPort, string deviceListenerTmpFile, IEnumerable extraAppArguments, - IEnumerable<(string, string)> extraEnvVariables) + IEnumerable<(string, string)> extraEnvVariables, + string? appEndTag) { var args = GetCommonArguments( - appInformation, xmlResultJargon, skippedMethods, skippedTestClasses, @@ -559,7 +600,8 @@ private MlaunchArguments GetDeviceArguments( deviceListenerPort, deviceListenerTmpFile, extraAppArguments, - extraEnvVariables); + extraEnvVariables, + appEndTag); var ips = string.Join(",", _helpers.GetLocalIpAddresses().Select(ip => ip.ToString())); diff --git a/src/Microsoft.DotNet.XHarness.Apple/Orchestration/RunOrchestrator.cs b/src/Microsoft.DotNet.XHarness.Apple/Orchestration/RunOrchestrator.cs index e01641bc1017c..4421b5f947865 100644 --- a/src/Microsoft.DotNet.XHarness.Apple/Orchestration/RunOrchestrator.cs +++ b/src/Microsoft.DotNet.XHarness.Apple/Orchestration/RunOrchestrator.cs @@ -29,6 +29,7 @@ Task OrchestrateRun( bool includeWirelessDevices, bool resetSimulator, bool enableLldb, + bool signalAppEnd, IReadOnlyCollection<(string, string)> environmentalVariables, IEnumerable passthroughArguments, CancellationToken cancellationToken); @@ -87,6 +88,7 @@ public Task OrchestrateRun( bool includeWirelessDevices, bool resetSimulator, bool enableLldb, + bool signalAppEnd, IReadOnlyCollection<(string, string)> environmentalVariables, IEnumerable passthroughArguments, CancellationToken cancellationToken) @@ -96,6 +98,7 @@ public Task OrchestrateRun( appBundleInfo, timeout, expectedExitCode, + signalAppEnd, environmentalVariables, passthroughArguments, cancellationToken); @@ -108,6 +111,7 @@ public Task OrchestrateRun( companionDevice, timeout, expectedExitCode, + signalAppEnd, environmentalVariables, passthroughArguments, cancellationToken); @@ -131,6 +135,7 @@ private async Task ExecuteApp( IDevice? companionDevice, TimeSpan timeout, int expectedExitCode, + bool signalAppEnd, IReadOnlyCollection<(string, string)> environmentalVariables, IEnumerable passthroughArguments, CancellationToken cancellationToken) @@ -143,6 +148,7 @@ private async Task ExecuteApp( device, companionDevice, timeout, + signalAppEnd, passthroughArguments, environmentalVariables, cancellationToken); @@ -160,6 +166,7 @@ private async Task ExecuteMacCatalystApp( AppBundleInformation appBundleInfo, TimeSpan timeout, int expectedExitCode, + bool signalAppEnd, IReadOnlyCollection<(string, string)> environmentalVariables, IEnumerable passthroughArguments, CancellationToken cancellationToken) @@ -169,6 +176,7 @@ private async Task ExecuteMacCatalystApp( ProcessExecutionResult result = await _appRunner.RunMacCatalystApp( appBundleInfo, timeout, + signalAppEnd, passthroughArguments, environmentalVariables, cancellationToken: cancellationToken); @@ -204,9 +212,12 @@ private ExitCode ParseResult( { _logger.LogError($"Application has finished with exit code {exitCode} but {expectedExitCode} was expected"); - if (_errorKnowledgeBase.IsKnownTestIssue(_mainLog, out var failureMessage)) + foreach (var log in _logs) { - _logger.LogError(failureMessage.Value.HumanMessage); + if (_errorKnowledgeBase.IsKnownTestIssue(log, out var failureMessage)) + { + _logger.LogError(failureMessage.Value.HumanMessage); + } } return ExitCode.GENERAL_FAILURE; diff --git a/src/Microsoft.DotNet.XHarness.Apple/Orchestration/TestOrchestrator.cs b/src/Microsoft.DotNet.XHarness.Apple/Orchestration/TestOrchestrator.cs index d7c525f402983..88702d6a2b28d 100644 --- a/src/Microsoft.DotNet.XHarness.Apple/Orchestration/TestOrchestrator.cs +++ b/src/Microsoft.DotNet.XHarness.Apple/Orchestration/TestOrchestrator.cs @@ -35,6 +35,7 @@ Task OrchestrateTest( bool includeWirelessDevices, bool resetSimulator, bool enableLldb, + bool signalAppEnd, IReadOnlyCollection<(string, string)> environmentalVariables, IEnumerable passthroughArguments, CancellationToken cancellationToken); @@ -81,6 +82,7 @@ public Task OrchestrateTest( bool includeWirelessDevices, bool resetSimulator, bool enableLldb, + bool signalAppEnd, IReadOnlyCollection<(string, string)> environmentalVariables, IEnumerable passthroughArguments, CancellationToken cancellationToken) @@ -96,6 +98,7 @@ public Task OrchestrateTest( classMethodFilters, environmentalVariables, passthroughArguments, + signalAppEnd, cancellationToken); Func> executeApp = (appBundleInfo, device, companionDevice) => @@ -112,6 +115,7 @@ public Task OrchestrateTest( classMethodFilters, environmentalVariables, passthroughArguments, + signalAppEnd, cancellationToken); return OrchestrateRun( @@ -139,20 +143,38 @@ private async Task ExecuteApp( IEnumerable classMethodFilters, IReadOnlyCollection<(string, string)> environmentalVariables, IEnumerable passthroughArguments, + bool signalAppEnd, CancellationToken cancellationToken) { - // iOS 14+ devices doesn't allow local network access and won't work unless the user confirms a dialog on the screen - // https://developer.apple.com/forums/thread/663858 - if (communicationChannel == CommunicationChannel.Network && - target.Platform.ToRunMode() == RunMode.iOS && - Version.TryParse(device.OSVersion, out var version) && version.Major >= 14) + var runMode = target.Platform.ToRunMode(); + if (Version.TryParse(device.OSVersion, out var version) && version.Major >= 14) { - _logger.LogWarning( - "Applications need user permission for communication over local network on iOS 14 and newer." + Environment.NewLine + - "Either confirm a dialog on the device after the application launches or use the USB tunnel communication channel." + Environment.NewLine + - "Test run might fail if permission is not granted. Permission is valid until app is uninstalled."); + if (runMode == RunMode.iOS) + { + // iOS 14+ devices do not allow local network access and won't work unless the user confirms a dialog on the screen + // https://developer.apple.com/forums/thread/663858 + if (communicationChannel == CommunicationChannel.Network) + { + _logger.LogWarning( + "Applications need user permission for communication over local network on iOS 14 and newer." + Environment.NewLine + + "Either confirm a dialog on the device after the application launches or use the USB tunnel communication channel." + Environment.NewLine + + "Test run might fail if permission is not granted. Permission is valid until app is uninstalled."); + } + + if (!signalAppEnd) + { + _logger.LogWarning("XHarness cannot reliably detect when app quits on iOS 14 and newer. Consider using --signal-app-end"); + } + } + } + + if (signalAppEnd && (runMode == RunMode.Sim64 || runMode == RunMode.Sim32)) + { + _logger.LogWarning("The --signal-app-end option is recommended for device tests and is not required for simulators"); } + _logger.LogInformation("Starting test run for " + appBundleInfo.BundleIdentifier + ".."); + AppTester appTester = GetAppTester(communicationChannel, target.Platform.IsSimulator()); (TestExecutingResult testResult, string resultMessage) = await appTester.TestApp( @@ -162,6 +184,7 @@ private async Task ExecuteApp( companionDevice, timeout, launchTimeout, + signalAppEnd, passthroughArguments, environmentalVariables, xmlResultJargon, @@ -182,6 +205,7 @@ private async Task ExecuteMacCatalystApp( IEnumerable classMethodFilters, IReadOnlyCollection<(string, string)> environmentalVariables, IEnumerable passthroughArguments, + bool signalAppEnd, CancellationToken cancellationToken) { AppTester appTester = GetAppTester(communicationChannel, TestTarget.MacCatalyst.IsSimulator()); @@ -190,6 +214,7 @@ private async Task ExecuteMacCatalystApp( appBundleInfo, timeout, launchTimeout, + signalAppEnd, passthroughArguments, environmentalVariables, xmlResultJargon, @@ -230,20 +255,22 @@ private ExitCode ParseResult(TestExecutingResult testResult, string resultMessag void LogProblem(string message) { - if (_errorKnowledgeBase.IsKnownTestIssue(_mainLog, out var issue)) + foreach (var log in _logs) + { + if (_errorKnowledgeBase.IsKnownTestIssue(log, out var issue)) + { + _logger.LogError(message + newLine + issue.Value.HumanMessage); + return; + } + } + + if (resultMessage != null) { - _logger.LogError(message + newLine + issue.Value.HumanMessage); + _logger.LogError(message + newLine + resultMessage + newLine + newLine + checkLogsMessage); } else { - if (resultMessage != null) - { - _logger.LogError(message + newLine + resultMessage + newLine + newLine + checkLogsMessage); - } - else - { - _logger.LogError(message + newLine + checkLogsMessage); - } + _logger.LogError(message + newLine + checkLogsMessage); } } @@ -264,7 +291,7 @@ void LogProblem(string message) return ExitCode.APP_LAUNCH_FAILURE; case TestExecutingResult.Crashed: - LogProblem("Application run crashed"); + LogProblem("Application test run crashed"); return ExitCode.APP_CRASH; case TestExecutingResult.TimedOut: diff --git a/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/AppleJustRunCommandArguments.cs b/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/AppleJustRunCommandArguments.cs index f87be0e7d3845..d0c04fad52615 100644 --- a/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/AppleJustRunCommandArguments.cs +++ b/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/AppleJustRunCommandArguments.cs @@ -22,6 +22,7 @@ internal class AppleJustRunCommandArguments : XHarnessCommandArguments, IAppleAp public EnvironmentalVariablesArgument EnvironmentalVariables { get; } = new(); public ResetSimulatorArgument ResetSimulator { get; } = new(); public ExpectedExitCodeArgument ExpectedExitCode { get; } = new((int)ExitCode.SUCCESS); + public SignalAppEndArgument SignalAppEnd { get; } = new(); protected override IEnumerable GetArguments() => new Argument[] { @@ -35,6 +36,7 @@ internal class AppleJustRunCommandArguments : XHarnessCommandArguments, IAppleAp XcodeRoot, MlaunchPath, EnableLldb, + SignalAppEnd, EnvironmentalVariables, ResetSimulator, }; diff --git a/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/AppleJustTestCommandArguments.cs b/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/AppleJustTestCommandArguments.cs index f32c0dc952991..474d31fd156ef 100644 --- a/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/AppleJustTestCommandArguments.cs +++ b/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/AppleJustTestCommandArguments.cs @@ -25,6 +25,7 @@ internal class AppleJustTestCommandArguments : XHarnessCommandArguments, IAppleA public EnableLldbArgument EnableLldb { get; } = new(); public EnvironmentalVariablesArgument EnvironmentalVariables { get; } = new(); public ResetSimulatorArgument ResetSimulator { get; } = new(); + public SignalAppEndArgument SignalAppEnd { get; } = new(); protected override IEnumerable GetArguments() => new Argument[] { @@ -42,6 +43,7 @@ internal class AppleJustTestCommandArguments : XHarnessCommandArguments, IAppleA SingleMethodFilters, ClassMethodFilters, EnableLldb, + SignalAppEnd, EnvironmentalVariables, ResetSimulator, }; diff --git a/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/AppleRunCommandArguments.cs b/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/AppleRunCommandArguments.cs index 219d6854ff354..8aedf87e532c7 100644 --- a/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/AppleRunCommandArguments.cs +++ b/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/AppleRunCommandArguments.cs @@ -22,6 +22,7 @@ internal class AppleRunCommandArguments : XHarnessCommandArguments, IAppleAppRun public EnvironmentalVariablesArgument EnvironmentalVariables { get; } = new(); public ResetSimulatorArgument ResetSimulator { get; } = new(); public ExpectedExitCodeArgument ExpectedExitCode { get; } = new((int)ExitCode.SUCCESS); + public SignalAppEndArgument SignalAppEnd { get; } = new(); protected override IEnumerable GetArguments() => new Argument[] { @@ -35,6 +36,7 @@ internal class AppleRunCommandArguments : XHarnessCommandArguments, IAppleAppRun XcodeRoot, MlaunchPath, EnableLldb, + SignalAppEnd, EnvironmentalVariables, ResetSimulator, }; diff --git a/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/AppleTestCommandArguments.cs b/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/AppleTestCommandArguments.cs index 832295bd9c88e..2a96a9d57185e 100644 --- a/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/AppleTestCommandArguments.cs +++ b/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/AppleTestCommandArguments.cs @@ -25,6 +25,7 @@ internal class AppleTestCommandArguments : XHarnessCommandArguments, IAppleAppRu public EnableLldbArgument EnableLldb { get; } = new(); public EnvironmentalVariablesArgument EnvironmentalVariables { get; } = new(); public ResetSimulatorArgument ResetSimulator { get; } = new(); + public SignalAppEndArgument SignalAppEnd { get; } = new(); protected override IEnumerable GetArguments() => new Argument[] { @@ -42,6 +43,7 @@ internal class AppleTestCommandArguments : XHarnessCommandArguments, IAppleAppRu SingleMethodFilters, ClassMethodFilters, EnableLldb, + SignalAppEnd, EnvironmentalVariables, ResetSimulator, }; diff --git a/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/Arguments/SignalAppEndArgument.cs b/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/Arguments/SignalAppEndArgument.cs new file mode 100644 index 0000000000000..3018b08dfc582 --- /dev/null +++ b/src/Microsoft.DotNet.XHarness.CLI/CommandArguments/Apple/Arguments/SignalAppEndArgument.cs @@ -0,0 +1,16 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. +// See the LICENSE file in the project root for more information. + +namespace Microsoft.DotNet.XHarness.CLI.CommandArguments.Apple +{ + /// + /// Enables extra signaling between the TestRunner application and XHarness to work around problems in newer iOS. + /// + internal class SignalAppEndArgument : SwitchArgument + { + public SignalAppEndArgument() : base("signal-app-end", "Tells the test application to signal back when tests have finished (iOS 14+ cannot detect this reliably otherwise)", false) + { + } + } +} diff --git a/src/Microsoft.DotNet.XHarness.CLI/Commands/Apple/AppleJustRunCommand.cs b/src/Microsoft.DotNet.XHarness.CLI/Commands/Apple/AppleJustRunCommand.cs index b68077ad6e43d..28fdd1b4ca3b4 100644 --- a/src/Microsoft.DotNet.XHarness.CLI/Commands/Apple/AppleJustRunCommand.cs +++ b/src/Microsoft.DotNet.XHarness.CLI/Commands/Apple/AppleJustRunCommand.cs @@ -38,6 +38,7 @@ protected override Task InvokeInternal(CancellationToken cancellationT Arguments.IncludeWireless, Arguments.ResetSimulator, Arguments.EnableLldb, + Arguments.SignalAppEnd, Arguments.EnvironmentalVariables.Value, PassThroughArguments, cancellationToken); diff --git a/src/Microsoft.DotNet.XHarness.CLI/Commands/Apple/AppleJustTestCommand.cs b/src/Microsoft.DotNet.XHarness.CLI/Commands/Apple/AppleJustTestCommand.cs index c7bab98ba8c8a..fbc969292cfdc 100644 --- a/src/Microsoft.DotNet.XHarness.CLI/Commands/Apple/AppleJustTestCommand.cs +++ b/src/Microsoft.DotNet.XHarness.CLI/Commands/Apple/AppleJustTestCommand.cs @@ -38,9 +38,10 @@ protected override Task InvokeInternal(CancellationToken cancellationT Arguments.XmlResultJargon, Arguments.SingleMethodFilters.Value, Arguments.ClassMethodFilters.Value, - Arguments.IncludeWireless, - Arguments.ResetSimulator, - Arguments.EnableLldb, + includeWirelessDevices: Arguments.IncludeWireless, + resetSimulator: Arguments.ResetSimulator, + enableLldb: Arguments.EnableLldb, + signalAppEnd: Arguments.SignalAppEnd, Arguments.EnvironmentalVariables.Value, PassThroughArguments, cancellationToken); diff --git a/src/Microsoft.DotNet.XHarness.CLI/Commands/Apple/AppleRunCommand.cs b/src/Microsoft.DotNet.XHarness.CLI/Commands/Apple/AppleRunCommand.cs index fe44c98598ad7..135e6d0fa2de5 100644 --- a/src/Microsoft.DotNet.XHarness.CLI/Commands/Apple/AppleRunCommand.cs +++ b/src/Microsoft.DotNet.XHarness.CLI/Commands/Apple/AppleRunCommand.cs @@ -55,6 +55,7 @@ protected override async Task InvokeInternal(CancellationToken cancell Arguments.IncludeWireless, Arguments.ResetSimulator, Arguments.EnableLldb, + Arguments.SignalAppEnd, Arguments.EnvironmentalVariables.Value, PassThroughArguments, cancellationToken); diff --git a/src/Microsoft.DotNet.XHarness.CLI/Commands/Apple/AppleTestCommand.cs b/src/Microsoft.DotNet.XHarness.CLI/Commands/Apple/AppleTestCommand.cs index 6e32c419d2738..1447bc1126231 100644 --- a/src/Microsoft.DotNet.XHarness.CLI/Commands/Apple/AppleTestCommand.cs +++ b/src/Microsoft.DotNet.XHarness.CLI/Commands/Apple/AppleTestCommand.cs @@ -53,9 +53,10 @@ protected override async Task InvokeInternal(CancellationToken cancell Arguments.XmlResultJargon, Arguments.SingleMethodFilters.Value, Arguments.ClassMethodFilters.Value, - Arguments.IncludeWireless, - Arguments.ResetSimulator, - Arguments.EnableLldb, + includeWirelessDevices: Arguments.IncludeWireless, + resetSimulator: Arguments.ResetSimulator, + enableLldb: Arguments.EnableLldb, + signalAppEnd: Arguments.SignalAppEnd, Arguments.EnvironmentalVariables.Value, PassThroughArguments, cancellationToken); diff --git a/src/Microsoft.DotNet.XHarness.Common/Logging/Log.cs b/src/Microsoft.DotNet.XHarness.Common/Logging/Log.cs index 9fffbee536a7b..f2d0c7cffdf4d 100644 --- a/src/Microsoft.DotNet.XHarness.Common/Logging/Log.cs +++ b/src/Microsoft.DotNet.XHarness.Common/Logging/Log.cs @@ -12,7 +12,7 @@ public abstract partial class Log : ILog { public virtual Encoding Encoding => Encoding.UTF8; public string? Description { get; set; } - public bool Timestamp { get; set; } = true; + public virtual bool Timestamp { get; set; } = true; protected Log(string? description = null) { diff --git a/src/Microsoft.DotNet.XHarness.Common/Logging/ScanLog.cs b/src/Microsoft.DotNet.XHarness.Common/Logging/ScanLog.cs new file mode 100644 index 0000000000000..5a029d96e3fb2 --- /dev/null +++ b/src/Microsoft.DotNet.XHarness.Common/Logging/ScanLog.cs @@ -0,0 +1,90 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. +// See the LICENSE file in the project root for more information. + +using System; + +#nullable enable +namespace Microsoft.DotNet.XHarness.Common.Logging +{ + /// + /// Log that scans for a given tag and notifies when tag is found in the stream. + /// + public class ScanLog : Log + { + private readonly string _tag; + private readonly Action _tagFoundNotify; + private readonly char[] _buffer; + private int _startIndex; + private bool _hasBeenFilled = false; + + public override bool Timestamp { get => false; set { } } + + public ScanLog(string tag, Action tagFoundNotify) + { + if (string.IsNullOrEmpty(tag)) + { + throw new ArgumentException($"'{nameof(tag)}' cannot be null or empty.", nameof(tag)); + } + + _tag = tag; + _tagFoundNotify = tagFoundNotify; + _buffer = new char[_tag.Length]; + _startIndex = -1; + } + + protected override void WriteImpl(string value) + { + foreach (var c in value) + { + Add(c); + + if (IsMatch()) + { + _tagFoundNotify(); + } + } + } + + public override void Flush() + { + } + + public override void Dispose() + { + GC.SuppressFinalize(this); + } + + private void Add(char c) + { + _startIndex++; + + if (_startIndex == _buffer.Length - 1) + { + _hasBeenFilled = true; + } + + _startIndex %= _buffer.Length; + _buffer[_startIndex] = c; + } + + private bool IsMatch() + { + if (!_hasBeenFilled) + { + return false; + } + + for (int i = 1; i <= _buffer.Length; i++) + { + int index = (i + _startIndex) % _buffer.Length; + if (_buffer[index] != _tag[i - 1]) + { + return false; + } + } + + return true; + } + } +} diff --git a/src/Microsoft.DotNet.XHarness.TestRunners.Common/ApplicationOptions.cs b/src/Microsoft.DotNet.XHarness.TestRunners.Common/ApplicationOptions.cs index 8d74960681435..310086deeadc9 100644 --- a/src/Microsoft.DotNet.XHarness.TestRunners.Common/ApplicationOptions.cs +++ b/src/Microsoft.DotNet.XHarness.TestRunners.Common/ApplicationOptions.cs @@ -76,6 +76,11 @@ public ApplicationOptions() _classMethodFilters.AddRange(classes.Split(',')); } + if (!string.IsNullOrEmpty(Environment.GetEnvironmentVariable(EnviromentVariables.AppEndTag))) + { + AppEndTag = Environment.GetEnvironmentVariable(EnviromentVariables.AppEndTag); + } + var os = new OptionSet() { { "autoexit", "Exit application once the test run has completed", v => TerminateAfterExecution = true }, { "autostart", "If the app should automatically start running the tests", v => AutoStart = true }, @@ -106,7 +111,8 @@ public ApplicationOptions() "tests that have been provided by the '--method' and '--class' arguments will be ran. " + "All other test will be ignored. Can be used more than once.", v => _classMethodFilters.Add(v) - } + }, + { "test-end-tag=", "String that will be outputted when test run has finished", v => AppEndTag = v }, }; try @@ -168,5 +174,10 @@ public ApplicationOptions() /// Specify the test classes to be ran in the app. /// public ICollection ClassMethodFilters => _classMethodFilters; + + /// + /// String that will be outputted when test run has finished. + /// + public string AppEndTag { get; private set; } } } diff --git a/src/Microsoft.DotNet.XHarness.TestRunners.Xunit/AndroidApplicationEntryPoint.cs b/src/Microsoft.DotNet.XHarness.TestRunners.Xunit/AndroidApplicationEntryPoint.cs index 687dd4f6804f7..8d8eeaa2686a0 100644 --- a/src/Microsoft.DotNet.XHarness.TestRunners.Xunit/AndroidApplicationEntryPoint.cs +++ b/src/Microsoft.DotNet.XHarness.TestRunners.Xunit/AndroidApplicationEntryPoint.cs @@ -64,6 +64,12 @@ public override async Task RunAsync() } logger.Info($"Tests run: {runner.TotalTests} Passed: {runner.PassedTests} Inconclusive: {runner.InconclusiveTests} Failed: {runner.FailedTests} Ignored: {runner.FilteredTests}"); + + if (options.AppEndTag != null) + { + logger.Info(options.AppEndTag); + } + if (options.TerminateAfterExecution) { TerminateWithSuccess(); diff --git a/src/Microsoft.DotNet.XHarness.TestRunners.Xunit/iOSApplicationEntryPoint.cs b/src/Microsoft.DotNet.XHarness.TestRunners.Xunit/iOSApplicationEntryPoint.cs index f767031692a24..134b5dad1791d 100644 --- a/src/Microsoft.DotNet.XHarness.TestRunners.Xunit/iOSApplicationEntryPoint.cs +++ b/src/Microsoft.DotNet.XHarness.TestRunners.Xunit/iOSApplicationEntryPoint.cs @@ -52,6 +52,11 @@ public override async Task RunAsync() logger.Info($"Tests run: {runner.TotalTests} Passed: {runner.PassedTests} Inconclusive: {runner.InconclusiveTests} Failed: {runner.FailedTests} Ignored: {runner.FilteredTests + runner.SkippedTests}"); + if (options.AppEndTag != null) + { + logger.Info(options.AppEndTag); + } + if (options.TerminateAfterExecution) { TerminateWithSuccess(); diff --git a/src/Microsoft.DotNet.XHarness.iOS.Shared/Execution/EnviromentVariables.cs b/src/Microsoft.DotNet.XHarness.iOS.Shared/Execution/EnviromentVariables.cs index be53ecd82d195..177df55bca036 100644 --- a/src/Microsoft.DotNet.XHarness.iOS.Shared/Execution/EnviromentVariables.cs +++ b/src/Microsoft.DotNet.XHarness.iOS.Shared/Execution/EnviromentVariables.cs @@ -9,7 +9,7 @@ public static class EnviromentVariables public const string AutoStart = "NUNIT_AUTOSTART"; /// - /// Env car that will tell the test application to exit once all the test have been ran. + /// Env var that will tell the test application to exit once all the test have been ran. /// public const string AutoExit = "NUNIT_AUTOEXIT"; @@ -50,6 +50,11 @@ public static class EnviromentVariables /// public const string UseTcpTunnel = "USE_TCP_TUNNEL"; + /// + /// Env var containing a tag that the test application will output once tests are finished to signalize it. + /// + public const string AppEndTag = "RUN_END_TAG"; + /// /// Env var used to notify the test application that the output is expected to be xml. /// diff --git a/src/Microsoft.DotNet.XHarness.iOS.Shared/Listeners/SimpleListener.cs b/src/Microsoft.DotNet.XHarness.iOS.Shared/Listeners/SimpleListener.cs index fb573dd6c82d5..14a01345545f5 100644 --- a/src/Microsoft.DotNet.XHarness.iOS.Shared/Listeners/SimpleListener.cs +++ b/src/Microsoft.DotNet.XHarness.iOS.Shared/Listeners/SimpleListener.cs @@ -8,6 +8,7 @@ using System.Threading.Tasks; using Microsoft.DotNet.XHarness.Common.Logging; +#nullable enable namespace Microsoft.DotNet.XHarness.iOS.Shared.Listeners { public interface ISimpleListener : IDisposable diff --git a/src/Microsoft.DotNet.XHarness.iOS.Shared/Listeners/SimpleTcpListener.cs b/src/Microsoft.DotNet.XHarness.iOS.Shared/Listeners/SimpleTcpListener.cs index 75ecc34167c47..25e60c313314c 100644 --- a/src/Microsoft.DotNet.XHarness.iOS.Shared/Listeners/SimpleTcpListener.cs +++ b/src/Microsoft.DotNet.XHarness.iOS.Shared/Listeners/SimpleTcpListener.cs @@ -11,6 +11,7 @@ using System.Threading.Tasks; using Microsoft.DotNet.XHarness.Common.Logging; +#nullable enable namespace Microsoft.DotNet.XHarness.iOS.Shared.Listeners { public class SimpleTcpListener : SimpleListener, ITunnelListener @@ -24,8 +25,8 @@ public class SimpleTcpListener : SimpleListener, ITunnelListener private readonly bool _useTcpTunnel = true; private readonly byte[] _buffer = new byte[16 * 1024]; - private TcpListener _server; - private TcpClient _client; + private TcpListener? _server; + private TcpClient? _client; public TaskCompletionSource TunnelHoleThrough { get; } = new TaskCompletionSource(); @@ -76,6 +77,11 @@ public override int InitializeAndGetPort() private void StartNetworkTcp() { + if (_server == null) + { + throw new InvalidOperationException("Initialize the listener first via " + nameof(this.InitializeAndGetPort)); + } + bool processed; try @@ -86,7 +92,7 @@ private void StartNetworkTcp() using (_client = _server.AcceptTcpClient()) { _client.ReceiveBufferSize = _buffer.Length; - processed = Processing(); + processed = Processing(_client); } } while (!_autoExit || !processed); } @@ -113,10 +119,15 @@ private void StartNetworkTcp() private void StartTcpTunnel() { if (!TunnelHoleThrough.Task.Result) - { // do nothing until the tunnel is ready + { throw new InvalidOperationException("Tcp tunnel could not be initialized."); } + if (_server == null) + { + throw new InvalidOperationException("Initialize the listener first via " + nameof(this.InitializeAndGetPort)); + } + bool processed; try { @@ -159,7 +170,8 @@ private void StartTcpTunnel() $"Increasing retry period from {(int)_retryPeriod.TotalMilliseconds} ms " + $"to {(int)_retryPeriodIncreased.TotalMilliseconds} ms"); - } else if ((++logCounter) % 100 == 0) + } + else if ((++logCounter) % 100 == 0) { Log.WriteLine($"TCP tunnel still has not connected"); } @@ -171,7 +183,7 @@ private void StartTcpTunnel() do { _client.ReceiveBufferSize = _buffer.Length; - processed = Processing(); + processed = Processing(_client); } while (!_autoExit || !processed); } catch (Exception e) @@ -199,14 +211,14 @@ protected override void Start() } } - private bool Processing() + private bool Processing(TcpClient client) { - Connected(_client.Client.RemoteEndPoint.ToString()); + Connected(client.Client.RemoteEndPoint.ToString()); // now simply copy what we receive int i; int total = 0; - NetworkStream stream = _client.GetStream(); + NetworkStream stream = client.GetStream(); while ((i = stream.Read(_buffer, 0, _buffer.Length)) != 0) { TestLog.Write(_buffer, 0, i); diff --git a/src/Microsoft.DotNet.XHarness.iOS.Shared/Logging/DeviceLogCapturer.cs b/src/Microsoft.DotNet.XHarness.iOS.Shared/Logging/DeviceLogCapturer.cs index 7b396ce63b6d5..5e40bdc80365b 100644 --- a/src/Microsoft.DotNet.XHarness.iOS.Shared/Logging/DeviceLogCapturer.cs +++ b/src/Microsoft.DotNet.XHarness.iOS.Shared/Logging/DeviceLogCapturer.cs @@ -9,7 +9,7 @@ namespace Microsoft.DotNet.XHarness.iOS.Shared.Logging { - public interface IDeviceLogCapturer + public interface IDeviceLogCapturer : IDisposable { void StartCapture(); void StopCapture(); @@ -97,6 +97,8 @@ public void StopCapture() _processManager.KillTreeAsync(_process, _mainLog, diagnostics: false).Wait(); _process.Dispose(); } + + public void Dispose() => StopCapture(); } } diff --git a/src/Microsoft.DotNet.XHarness.iOS.Shared/Utilities/Helpers.cs b/src/Microsoft.DotNet.XHarness.iOS.Shared/Utilities/Helpers.cs index 22b6e8c6a6d51..aadc6b66408b1 100644 --- a/src/Microsoft.DotNet.XHarness.iOS.Shared/Utilities/Helpers.cs +++ b/src/Microsoft.DotNet.XHarness.iOS.Shared/Utilities/Helpers.cs @@ -17,6 +17,8 @@ public interface IHelpers Guid GenerateStableGuid(string seed = null); + Guid GenerateGuid(); + string Timestamp { get; } IEnumerable GetLocalIpAddresses(); @@ -49,6 +51,8 @@ public Guid GenerateStableGuid(string seed = null) return new Guid(bytes); } + public Guid GenerateGuid() => Guid.NewGuid(); + public string Timestamp => $"{DateTime.Now:yyyyMMdd_HHmmss}"; [DllImport("/usr/lib/libc.dylib")] diff --git a/tests/Microsoft.DotNet.XHarness.Apple.Tests/AppRunTestBase.cs b/tests/Microsoft.DotNet.XHarness.Apple.Tests/AppRunTestBase.cs index 855202d796a03..c652b0bdae1f8 100644 --- a/tests/Microsoft.DotNet.XHarness.Apple.Tests/AppRunTestBase.cs +++ b/tests/Microsoft.DotNet.XHarness.Apple.Tests/AppRunTestBase.cs @@ -74,11 +74,11 @@ protected AppRunTestBase() .Setup(x => x.CreateFile($"{AppBundleIdentifier}-mocked_timestamp.log", It.IsAny())) .Returns($"./{AppBundleIdentifier}-mocked_timestamp.log"); _logs - .Setup(x => x.CreateFile(AppBundleIdentifier + ".log", LogType.ApplicationLog)) - .Returns(_stdoutLog.FullPath); + .Setup(x => x.Create(AppBundleIdentifier + ".log", LogType.ApplicationLog.ToString(), It.IsAny())) + .Returns(_stdoutLog); _logs - .Setup(x => x.CreateFile(AppBundleIdentifier + ".err.log", LogType.ApplicationLog)) - .Returns(_stderrLog.FullPath); + .Setup(x => x.Create(AppBundleIdentifier + ".err.log", LogType.ApplicationLog.ToString(), It.IsAny())) + .Returns(_stderrLog); var factory2 = new Mock(); factory2.SetReturnsDefault(_snapshotReporter.Object); diff --git a/tests/Microsoft.DotNet.XHarness.Apple.Tests/AppRunnerTests.cs b/tests/Microsoft.DotNet.XHarness.Apple.Tests/AppRunnerTests.cs index 608ae76dbdf58..bae0a9539b5b3 100644 --- a/tests/Microsoft.DotNet.XHarness.Apple.Tests/AppRunnerTests.cs +++ b/tests/Microsoft.DotNet.XHarness.Apple.Tests/AppRunnerTests.cs @@ -8,6 +8,7 @@ using System.Linq; using System.Threading; using System.Threading.Tasks; +using Microsoft.DotNet.XHarness.Common.Execution; using Microsoft.DotNet.XHarness.Common.Logging; using Microsoft.DotNet.XHarness.iOS.Shared; using Microsoft.DotNet.XHarness.iOS.Shared.Execution; @@ -15,6 +16,7 @@ using Moq; using Xunit; +#nullable enable namespace Microsoft.DotNet.XHarness.Apple.Tests { public class AppRunnerTests : AppRunTestBase @@ -55,6 +57,7 @@ public async Task RunOnSimulatorTest() _mockSimulator, null, timeout: TimeSpan.FromSeconds(30), + signalAppEnd: false, extraAppArguments: new[] { "--foo=bar", "--xyz" }, extraEnvVariables: new[] { ("appArg1", "value1") }); @@ -67,7 +70,9 @@ public async Task RunOnSimulatorTest() .Verify( x => x.ExecuteCommandAsync( It.Is(args => args.AsCommandLine() == expectedArgs), - _mainLog.Object, + It.IsAny(), + It.IsAny(), + It.IsAny(), It.IsAny(), It.IsAny>(), It.IsAny(), @@ -117,6 +122,7 @@ public async Task RunOnDeviceTest() s_mockDevice, null, timeout: TimeSpan.FromSeconds(30), + signalAppEnd: false, extraAppArguments: new[] { "--foo=bar", "--xyz" }, extraEnvVariables: new[] { ("appArg1", "value1") }); @@ -130,6 +136,8 @@ public async Task RunOnDeviceTest() x => x.ExecuteCommandAsync( It.Is(args => args.AsCommandLine() == expectedArgs), It.IsAny(), + It.IsAny(), + It.IsAny(), It.IsAny(), It.IsAny>(), It.IsAny(), @@ -137,6 +145,117 @@ public async Task RunOnDeviceTest() Times.Once); _snapshotReporter.Verify(x => x.StartCaptureAsync(), Times.AtLeastOnce); + + deviceSystemLog.Verify(x => x.Dispose(), Times.AtLeastOnce); + } + + [Fact] + public async Task RunOnDeviceWithAppEndSignalTest() + { + var deviceSystemLog = new Mock(); + deviceSystemLog.SetupGet(x => x.FullPath).Returns(AppBundleIdentifier + "system.log"); + deviceSystemLog.SetupGet(x => x.Description).Returns(LogType.SystemLog.ToString()); + + SetupLogList(new[] { deviceSystemLog.Object, _stdoutLog, _stderrLog }); + + _logs + .Setup(x => x.Create("device-" + DeviceName + "-mocked_timestamp.log", LogType.SystemLog.ToString(), It.IsAny())) + .Returns(deviceSystemLog.Object); + + var deviceLogCapturer = new Mock(); + + var deviceLogCapturerFactory = new Mock(); + deviceLogCapturerFactory + .Setup(x => x.Create(_mainLog.Object, deviceSystemLog.Object, DeviceName)) + .Returns(deviceLogCapturer.Object); + + var testEndSignal = Guid.NewGuid(); + _helpers + .Setup(x => x.GenerateGuid()) + .Returns(testEndSignal); + + var appInformation = GetMockedAppBundleInfo(); + + List mlaunchArguments = new(); + List appOutputLogs = new(); + List cancellationTokens = new(); + + // Endlessly running mlaunch until it gets cancelled by the signal + var mlaunchCompleted = new TaskCompletionSource(); + var appStarted = new TaskCompletionSource(); + + _processManager + .Setup(x => x.ExecuteCommandAsync( + Capture.In(mlaunchArguments), + It.IsAny(), + Capture.In(appOutputLogs), + Capture.In(appOutputLogs), + It.IsAny(), + It.IsAny?>(), + It.IsAny(), + Capture.In(cancellationTokens))) + .Callback(() => + { + // Signal we have started mlaunch + appStarted.SetResult(); + + // When mlaunch gets signalled to shut down, shut down even our fake mlaunch + cancellationTokens.Last().Register(() => mlaunchCompleted.SetResult(new ProcessExecutionResult + { + TimedOut = true, + })); + }) + .Returns(mlaunchCompleted.Task); + + // Act + var appRunner = new AppRunner( + _processManager.Object, + _snapshotReporterFactory, + Mock.Of(), + deviceLogCapturerFactory.Object, + _mainLog.Object, + _logs.Object, + _helpers.Object); + + var runTask = appRunner.RunApp( + appInformation, + new TestTargetOs(TestTarget.Device_iOS, null), + s_mockDevice, + null, + timeout: TimeSpan.FromSeconds(30), + signalAppEnd: true, + Array.Empty(), + Array.Empty<(string, string)>()); + + // Everything should hang now since we mimicked mlaunch not being able to tell the app quits + // We will wait for XHarness to kick off the mlaunch (the app) + Assert.False(runTask.IsCompleted); + await Task.WhenAny(appStarted.Task, Task.Delay(1000)); + + // XHarness should still be running + Assert.False(runTask.IsCompleted); + + // mlaunch should be started + Assert.True(appStarted.Task.IsCompleted); + + // We will mimick the app writing the end signal + var appLog = appOutputLogs.First(); + appLog.WriteLine(testEndSignal.ToString()); + + // AppTester should now complete fine + var result = await runTask; + + // Verify + Assert.True(result.Succeeded); + + var expectedArgs = $"-setenv=RUN_END_TAG={testEndSignal} " + + "--disable-memory-limits " + + $"--devname {s_mockDevice.DeviceIdentifier} " + + $"--launchdevbundleid {AppBundleIdentifier} " + + "--wait-for-exit"; + + Assert.Equal(mlaunchArguments.Last().AsCommandLine(), expectedArgs); + _snapshotReporter.Verify(x => x.StartCaptureAsync(), Times.AtLeastOnce); deviceSystemLog.Verify(x => x.Dispose(), Times.AtLeastOnce); @@ -175,6 +294,7 @@ public async Task RunOnMacCatalystTest() var result = await appRunner.RunMacCatalystApp( appInformation, timeout: TimeSpan.FromSeconds(30), + signalAppEnd: false, extraAppArguments: new[] { "--foo=bar", "--xyz" }, extraEnvVariables: new[] { ("appArg1", "value1") }); @@ -189,6 +309,8 @@ public async Task RunOnMacCatalystTest() "open", It.Is>(args => args[0] == "-W" && args[1] == s_appPath), _mainLog.Object, + It.IsAny(), + It.IsAny(), It.IsAny(), It.IsAny>(), It.IsAny()), @@ -207,8 +329,6 @@ private static AppBundleInformation GetMockedAppBundleInfo() => extension: null); private string GetExpectedDeviceMlaunchArgs() => - $"--stdout={_stdoutLog.FullPath} " + - $"--stderr={_stderrLog.FullPath} " + "-argument=--foo=bar " + "-argument=--xyz " + "-setenv=appArg1=value1 " + @@ -218,8 +338,6 @@ private string GetExpectedDeviceMlaunchArgs() => "--wait-for-exit"; private string GetExpectedSimulatorMlaunchArgs() => - $"--stdout={_stdoutLog.FullPath} " + - $"--stderr={_stderrLog.FullPath} " + "-argument=--foo=bar " + "-argument=--xyz " + "-setenv=appArg1=value1 " + diff --git a/tests/Microsoft.DotNet.XHarness.Apple.Tests/AppTesterTests.cs b/tests/Microsoft.DotNet.XHarness.Apple.Tests/AppTesterTests.cs index 3e4886ab7559c..4856ac05cbf38 100644 --- a/tests/Microsoft.DotNet.XHarness.Apple.Tests/AppTesterTests.cs +++ b/tests/Microsoft.DotNet.XHarness.Apple.Tests/AppTesterTests.cs @@ -5,6 +5,7 @@ using System; using System.Collections.Generic; using System.IO; +using System.Linq; using System.Threading; using System.Threading.Tasks; using Microsoft.DotNet.XHarness.Common.Execution; @@ -17,6 +18,7 @@ using Moq; using Xunit; +#nullable enable namespace Microsoft.DotNet.XHarness.Apple.Tests { public class AppTesterTests : AppRunTestBase @@ -32,8 +34,6 @@ public class AppTesterTests : AppRunTestBase public AppTesterTests() { - _processManager.SetReturnsDefault(Task.FromResult(new ProcessExecutionResult() { ExitCode = 0 })); - _listener = new Mock(); _listener .SetupGet(x => x.ConnectedTask) @@ -123,8 +123,9 @@ public async Task TestOnSimulatorTest(bool useTunnel) null, TimeSpan.FromSeconds(30), TimeSpan.FromSeconds(30), - new string[] { "--foo=bar", "--xyz" }, - new[] { ("appArg1", "value1") }); + signalAppEnd: false, + extraAppArguments: new string[] { "--foo=bar", "--xyz" }, + extraEnvVariables: new[] { ("appArg1", "value1") }); // Verify Assert.Equal(TestExecutingResult.Succeeded, result); @@ -137,6 +138,8 @@ public async Task TestOnSimulatorTest(bool useTunnel) x => x.ExecuteCommandAsync( It.Is(args => args.AsCommandLine() == expectedArgs), _mainLog.Object, + It.IsAny(), + It.IsAny(), It.IsAny(), It.IsAny>(), It.IsAny(), @@ -215,6 +218,7 @@ public async Task TestOnDeviceTest(bool useTunnel) null, timeout: TimeSpan.FromSeconds(30), testLaunchTimeout: TimeSpan.FromSeconds(30), + signalAppEnd: false, extraAppArguments: new[] { "--foo=bar", "--xyz" }, extraEnvVariables: new[] { ("appArg1", "value1") }); @@ -231,6 +235,8 @@ public async Task TestOnDeviceTest(bool useTunnel) x => x.ExecuteCommandAsync( It.Is(args => args.AsCommandLine() == expectedArgs), It.IsAny(), + It.IsAny(), + It.IsAny(), It.IsAny(), It.Is>(d => d["appArg1"] == "value1"), It.IsAny(), @@ -248,7 +254,6 @@ public async Task TestOnDeviceTest(bool useTunnel) _tunnelBore.Verify(t => t.Close(s_mockDevice.DeviceIdentifier)); } - _snapshotReporter.Verify(x => x.StartCaptureAsync(), Times.AtLeastOnce); _snapshotReporter.Verify(x => x.StartCaptureAsync(), Times.AtLeastOnce); deviceSystemLog.Verify(x => x.Dispose(), Times.AtLeastOnce); @@ -308,9 +313,10 @@ public async Task TestOnDeviceWithSkippedTestsTest(params string[] skippedTests) s_mockDevice, null, timeout: TimeSpan.FromSeconds(30), + testLaunchTimeout: TimeSpan.FromSeconds(30), + signalAppEnd: false, extraAppArguments: new[] { "--foo=bar", "--xyz" }, extraEnvVariables: new[] { ("appArg1", "value1") }, - testLaunchTimeout: TimeSpan.FromSeconds(30), skippedMethods: skippedTests); // Verify @@ -326,6 +332,8 @@ public async Task TestOnDeviceWithSkippedTestsTest(params string[] skippedTests) x => x.ExecuteCommandAsync( It.Is(args => args.AsCommandLine() == expectedArgs), It.IsAny(), + It.IsAny(), + It.IsAny(), It.IsAny(), It.IsAny>(), It.IsAny(), @@ -336,7 +344,6 @@ public async Task TestOnDeviceWithSkippedTestsTest(params string[] skippedTests) _listener.Verify(x => x.StartAsync(), Times.AtLeastOnce); _listener.Verify(x => x.Dispose(), Times.AtLeastOnce); - _snapshotReporter.Verify(x => x.StartCaptureAsync(), Times.AtLeastOnce); _snapshotReporter.Verify(x => x.StartCaptureAsync(), Times.AtLeastOnce); deviceSystemLog.Verify(x => x.Dispose(), Times.AtLeastOnce); @@ -398,6 +405,7 @@ public async Task TestOnDeviceWithSkippedClassesTestTest(params string[] skipped extraEnvVariables: new[] { ("appArg1", "value1") }, timeout: TimeSpan.FromSeconds(30), testLaunchTimeout: TimeSpan.FromSeconds(30), + signalAppEnd: false, skippedTestClasses: skippedClasses); // Verify @@ -412,6 +420,8 @@ public async Task TestOnDeviceWithSkippedClassesTestTest(params string[] skipped x => x.ExecuteCommandAsync( It.Is(args => args.AsCommandLine() == expectedArgs), It.IsAny(), + It.IsAny(), + It.IsAny(), It.IsAny(), It.IsAny>(), It.IsAny(), @@ -422,7 +432,6 @@ public async Task TestOnDeviceWithSkippedClassesTestTest(params string[] skipped _listener.Verify(x => x.StartAsync(), Times.AtLeastOnce); _listener.Verify(x => x.Dispose(), Times.AtLeastOnce); - _snapshotReporter.Verify(x => x.StartCaptureAsync(), Times.AtLeastOnce); _snapshotReporter.Verify(x => x.StartCaptureAsync(), Times.AtLeastOnce); deviceSystemLog.Verify(x => x.Dispose(), Times.AtLeastOnce); @@ -476,6 +485,7 @@ public async Task TestOnMacCatalystTest() appInformation, timeout: TimeSpan.FromSeconds(30), testLaunchTimeout: TimeSpan.FromSeconds(30), + signalAppEnd: false, extraAppArguments: new[] { "--foo=bar", "--xyz" }, extraEnvVariables: new[] { ("appArg1", "value1") }); @@ -489,6 +499,8 @@ public async Task TestOnMacCatalystTest() "open", It.Is>(args => args.Contains(s_appPath) && args.Contains("--foo=bar") && args.Contains("--foo=bar")), _mainLog.Object, + It.IsAny(), + It.IsAny(), It.IsAny(), It.Is>(envVars => envVars["NUNIT_HOSTNAME"] == "127.0.0.1" && @@ -504,9 +516,146 @@ public async Task TestOnMacCatalystTest() _listener.Verify(x => x.Dispose(), Times.AtLeastOnce); } - private string GetExpectedDeviceMlaunchArgs(string skippedTests = null, bool useTunnel = false, string extraArgs = null) => - $"--stdout={_stdoutLog.FullPath} " + - $"--stderr={_stderrLog.FullPath} " + + [Fact] + public async Task TestOnDeviceWithAppEndSignalTest() + { + var deviceSystemLog = new Mock(); + deviceSystemLog.SetupGet(x => x.FullPath).Returns(Path.GetTempFileName()); + + var deviceLogCapturer = new Mock(); + + var deviceLogCapturerFactory = new Mock(); + deviceLogCapturerFactory + .Setup(x => x.Create(_mainLog.Object, deviceSystemLog.Object, DeviceName)) + .Returns(deviceLogCapturer.Object); + + var testResultFilePath = Path.GetTempFileName(); + var listenerLogFile = Mock.Of(x => x.FullPath == testResultFilePath); + File.WriteAllLines(testResultFilePath, new[] { "Some result here", "Tests run: 124", "Some result there" }); + + _logs + .Setup(x => x.Create("test-ios-device-mocked_timestamp.log", "TestLog", It.IsAny())) + .Returns(listenerLogFile); + + _logs + .Setup(x => x.Create($"device-{DeviceName}-mocked_timestamp.log", LogType.SystemLog.ToString(), It.IsAny())) + .Returns(deviceSystemLog.Object); + + _tunnelBore.Setup(t => t.Create(DeviceName, It.IsAny())); + _listenerFactory + .Setup(f => f.UseTunnel) + .Returns(true); + + var testEndSignal = Guid.NewGuid(); + _helpers + .Setup(x => x.GenerateGuid()) + .Returns(testEndSignal); + + List mlaunchArguments = new(); + List appOutputLogs = new(); + List cancellationTokens = new(); + + // Endlessly running mlaunch until it gets cancelled by the signal + var mlaunchCompleted = new TaskCompletionSource(); + var appStarted = new TaskCompletionSource(); + + _processManager + .Setup(x => x.ExecuteCommandAsync( + Capture.In(mlaunchArguments), + It.IsAny(), + Capture.In(appOutputLogs), + Capture.In(appOutputLogs), + It.IsAny(), + It.IsAny?>(), + It.IsAny(), + Capture.In(cancellationTokens))) + .Callback(() => + { + // Signal we have started mlaunch + appStarted.SetResult(); + + // When mlaunch gets signalled to shut down, shut down even our fake mlaunch + cancellationTokens.Last().Register(() => mlaunchCompleted.SetResult(new ProcessExecutionResult + { + TimedOut = true, + })); + }) + .Returns(mlaunchCompleted.Task); + + var appInformation = new AppBundleInformation( + appName: AppName, + bundleIdentifier: AppBundleIdentifier, + appPath: s_appPath, + launchAppPath: s_appPath, + supports32b: false, + extension: null); + + // Act + var appTester = new AppTester( + _processManager.Object, + _listenerFactory.Object, + _snapshotReporterFactory, + Mock.Of(), + deviceLogCapturerFactory.Object, + _testReporterFactory, + new XmlResultParser(), + _mainLog.Object, + _logs.Object, + _helpers.Object); + + var testTask = appTester.TestApp( + appInformation, + new TestTargetOs(TestTarget.Device_iOS, null), + s_mockDevice, + null, + timeout: TimeSpan.FromMinutes(30), + testLaunchTimeout: TimeSpan.FromMinutes(30), + signalAppEnd: true, + Array.Empty(), + Array.Empty<(string, string)>()); + + // Everything should hang now since we mimicked mlaunch not being able to tell the app quits + // We will wait for XHarness to kick off the mlaunch (the app) + Assert.False(testTask.IsCompleted); + await Task.WhenAny(appStarted.Task, Task.Delay(1000)); + + // XHarness should still be running + Assert.False(testTask.IsCompleted); + + // mlaunch should be started + Assert.True(appStarted.Task.IsCompleted); + + // We will mimick the app writing the end signal + var appLog = appOutputLogs.First(); + appLog.WriteLine(testEndSignal.ToString()); + + // AppTester should now complete fine + var (result, resultMessage) = await testTask; + + // Verify + Assert.Equal(TestExecutingResult.Succeeded, result); + Assert.Equal("Tests run: 1194 Passed: 1191 Inconclusive: 0 Failed: 0 Ignored: 0", resultMessage); + + var expectedArgs = GetExpectedDeviceMlaunchArgs( + useTunnel: true, + extraArgs: $"-setenv=RUN_END_TAG={testEndSignal} "); + + Assert.Equal(mlaunchArguments.Last().AsCommandLine(), expectedArgs); + + _listener.Verify(x => x.InitializeAndGetPort(), Times.AtLeastOnce); + _listener.Verify(x => x.StartAsync(), Times.AtLeastOnce); + _listener.Verify(x => x.Dispose(), Times.AtLeastOnce); + + // verify that we do close the tunnel when it was used + // we dont want to leak a process + _tunnelBore.Verify(t => t.Close(s_mockDevice.DeviceIdentifier)); + + _snapshotReporter.Verify(x => x.StartCaptureAsync(), Times.AtLeastOnce); + + deviceSystemLog.Verify(x => x.Dispose(), Times.AtLeastOnce); + } + + private string GetExpectedDeviceMlaunchArgs(string? skippedTests = null, bool useTunnel = false, string? extraArgs = null) => "-setenv=NUNIT_AUTOEXIT=true " + $"-setenv=NUNIT_HOSTPORT={Port} " + "-setenv=NUNIT_ENABLE_XML_OUTPUT=true " + @@ -521,8 +670,6 @@ private string GetExpectedDeviceMlaunchArgs(string skippedTests = null, bool use "--wait-for-exit"; private string GetExpectedSimulatorMlaunchArgs() => - $"--stdout={_stdoutLog.FullPath} " + - $"--stderr={_stderrLog.FullPath} " + "-setenv=NUNIT_AUTOEXIT=true " + $"-setenv=NUNIT_HOSTPORT={Port} " + "-setenv=NUNIT_ENABLE_XML_OUTPUT=true " + diff --git a/tests/Microsoft.DotNet.XHarness.Common.Tests/Logging/ScanLogTest.cs b/tests/Microsoft.DotNet.XHarness.Common.Tests/Logging/ScanLogTest.cs new file mode 100644 index 0000000000000..247503a7be3ec --- /dev/null +++ b/tests/Microsoft.DotNet.XHarness.Common.Tests/Logging/ScanLogTest.cs @@ -0,0 +1,36 @@ +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. +// See the LICENSE file in the project root for more information. + +using Microsoft.DotNet.XHarness.Common.Logging; +using Xunit; + +namespace Microsoft.DotNet.XHarness.Common.Tests.Logging +{ + public class ScanLogTest + { + [Theory] + [InlineData("This is a log message", "log", true)] + [InlineData("emessag", "message", false)] + [InlineData("This is a log message", "This is a log message", true)] + [InlineData("This is a log message.", ".", true)] + public void TagIsFoundInLog(string message, string tag, bool shouldFind) + { + bool found = false; + var log = new ScanLog(tag, () => found = true); + log.Write(message); + Assert.Equal(shouldFind, found); + } + + [Fact] + public void TagIsFoundInSeveralMessages() + { + bool found = false; + var log = new ScanLog("123", () => found = true); + log.Write("abc1"); + log.Write("2"); + log.Write("3cdef"); + Assert.True(found); + } + } +} diff --git a/tests/integration-tests/Apple/Device.Commands.Tests.proj b/tests/integration-tests/Apple/Device.Commands.Tests.proj index a78d1251ea39e..90b611de735a5 100644 --- a/tests/integration-tests/Apple/Device.Commands.Tests.proj +++ b/tests/integration-tests/Apple/Device.Commands.Tests.proj @@ -27,15 +27,11 @@ 00:05:00 00:04:30 - set -ex; - deviceId=`xharness apple device $target`; + set -ex; deviceId=`xharness apple device $target`; xharness apple install -t=$target --device="$deviceId" -o="$output_directory" --app="$app" -v; - set +e; - result=0; - xharness apple just-test -t=$target --device="$deviceId" -o="$output_directory" --app="net.dot.$(TestAppBundleName)" --launch-timeout=$launch_timeout --timeout=$timeout -v; - ((result|=$?)); - xharness apple uninstall -t=$target --device="$deviceId" -o="$output_directory" --app="net.dot.$(TestAppBundleName)" -v; - ((result|=$?)); + set +e; result=0; + xharness apple just-test -t=$target --device="$deviceId" -o="$output_directory" --app="net.dot.$(TestAppBundleName)" --launch-timeout=$launch_timeout --timeout=$timeout --signal-app-end -v; ((result|=$?)); + xharness apple uninstall -t=$target --device="$deviceId" -o="$output_directory" --app="net.dot.$(TestAppBundleName)" -v; ((result|=$?)); exit $result;