public async Task <int> RunAsync() { CrashReportSnapshot crash_reports; Log device_system_log = null; Log listener_log = null; Log run_log = main_log; Initialize(); if (!isSimulator) { FindDevice(); } crash_reports = new CrashReportSnapshot() { Device = !isSimulator, DeviceName = device_name, Harness = Harness, Log = main_log, Logs = Logs, LogDirectory = LogDirectory, }; var args = new StringBuilder(); if (!string.IsNullOrEmpty(Harness.XcodeRoot)) { args.Append(" --sdkroot ").Append(Harness.XcodeRoot); } for (int i = -1; i < Harness.Verbosity; i++) { args.Append(" -v "); } args.Append(" -argument=-connection-mode -argument=none"); // This will prevent the app from trying to connect to any IDEs args.Append(" -argument=-app-arg:-autostart"); args.Append(" -setenv=NUNIT_AUTOSTART=true"); args.Append(" -argument=-app-arg:-autoexit"); args.Append(" -setenv=NUNIT_AUTOEXIT=true"); args.Append(" -argument=-app-arg:-enablenetwork"); args.Append(" -setenv=NUNIT_ENABLE_NETWORK=true"); // detect if we are using a jenkins bot. var useXmlOutput = Harness.InJenkins; if (useXmlOutput) { args.Append(" -setenv=NUNIT_ENABLE_XML_OUTPUT=true"); args.Append(" -setenv=NUNIT_ENABLE_XML_MODE=wrapped"); } if (!Harness.IncludeSystemPermissionTests) { args.Append(" -setenv=DISABLE_SYSTEM_PERMISSION_TESTS=1"); } if (isSimulator) { args.Append(" -argument=-app-arg:-hostname:127.0.0.1"); args.Append(" -setenv=NUNIT_HOSTNAME=127.0.0.1"); } else { var ips = new StringBuilder(); var ipAddresses = System.Net.Dns.GetHostEntry(System.Net.Dns.GetHostName()).AddressList; for (int i = 0; i < ipAddresses.Length; i++) { if (i > 0) { ips.Append(','); } ips.Append(ipAddresses [i].ToString()); } args.AppendFormat(" -argument=-app-arg:-hostname:{0}", ips.ToString()); args.AppendFormat(" -setenv=NUNIT_HOSTNAME={0}", ips.ToString()); } string transport; if (mode == "watchos") { transport = isSimulator ? "FILE" : "HTTP"; } else { transport = "TCP"; } args.AppendFormat(" -argument=-app-arg:-transport:{0}", transport); args.AppendFormat(" -setenv=NUNIT_TRANSPORT={0}", transport); listener_log = Logs.Create($"test-{mode}-{Harness.Timestamp}.log", "Test log"); SimpleListener listener; switch (transport) { case "FILE": var fn = listener_log.FullPath + ".tmp"; listener = new SimpleFileListener(fn); args.Append(" -setenv=NUNIT_LOG_FILE=").Append(StringUtils.Quote(fn)); break; case "HTTP": listener = new SimpleHttpListener(); break; case "TCP": listener = new SimpleTcpListener(); break; default: throw new NotImplementedException(); } listener.TestLog = listener_log; listener.Log = main_log; listener.AutoExit = true; listener.Address = System.Net.IPAddress.Any; listener.XmlOutput = useXmlOutput; listener.Initialize(); args.AppendFormat(" -argument=-app-arg:-hostport:{0}", listener.Port); args.AppendFormat(" -setenv=NUNIT_HOSTPORT={0}", listener.Port); listener.StartAsync(); var cancellation_source = new CancellationTokenSource(); var timed_out = false; ThreadPool.QueueUserWorkItem((v) => { if (!listener.WaitForConnection(TimeSpan.FromMinutes(Harness.LaunchTimeout))) { cancellation_source.Cancel(); main_log.WriteLine("Test launch timed out after {0} minute(s).", Harness.LaunchTimeout); timed_out = true; } else { main_log.WriteLine("Test run started"); } }); foreach (var kvp in Harness.EnvironmentVariables) { args.AppendFormat(" -setenv={0}={1}", kvp.Key, kvp.Value); } bool?success = null; bool launch_failure = false; if (isExtension) { switch (extension) { case Extension.TodayExtension: args.Append(isSimulator ? " --launchsimbundleid" : " --launchdevbundleid"); args.Append(" todayviewforextensions:"); args.Append(BundleIdentifier); args.Append(" --observe-extension "); args.Append(StringUtils.Quote(launchAppPath)); break; case Extension.WatchKit2: default: throw new NotImplementedException(); } } else { args.Append(isSimulator ? " --launchsim " : " --launchdev "); args.Append(StringUtils.Quote(launchAppPath)); } if (!isSimulator) { args.Append(" --disable-memory-limits"); } if (isSimulator) { if (!await FindSimulatorAsync()) { return(1); } if (mode != "watchos") { var stderr_tty = Marshal.PtrToStringAuto(ttyname(2)); if (!string.IsNullOrEmpty(stderr_tty)) { args.Append(" --stdout=").Append(StringUtils.Quote(stderr_tty)); args.Append(" --stderr=").Append(StringUtils.Quote(stderr_tty)); } else { var stdout_log = Logs.CreateFile($"stdout-{Harness.Timestamp}.log", "Standard output"); var stderr_log = Logs.CreateFile($"stderr-{Harness.Timestamp}.log", "Standard error"); args.Append(" --stdout=").Append(StringUtils.Quote(stdout_log)); args.Append(" --stderr=").Append(StringUtils.Quote(stderr_log)); } } var systemLogs = new List <CaptureLog> (); foreach (var sim in simulators) { // Upload the system log main_log.WriteLine("System log for the '{1}' simulator is: {0}", sim.SystemLog, sim.Name); bool isCompanion = sim != simulator; var log = new CaptureLog(Logs, sim.SystemLog, entire_file: Harness.Action != HarnessAction.Jenkins) { Path = Path.Combine(LogDirectory, sim.Name + ".log"), Description = isCompanion ? "System log (companion)" : "System log", }; log.StartCapture(); Logs.Add(log); systemLogs.Add(log); Harness.LogWrench("@MonkeyWrench: AddFile: {0}", log.Path); } main_log.WriteLine("*** Executing {0}/{1} in the simulator ***", appName, mode); if (EnsureCleanSimulatorState) { foreach (var sim in simulators) { await sim.PrepareSimulatorAsync(main_log, bundle_identifier); } } args.Append(" --device=:v2:udid=").Append(simulator.UDID).Append(" "); await crash_reports.StartCaptureAsync(); main_log.WriteLine("Starting test run"); var result = await ProcessHelper.ExecuteCommandAsync(Harness.MlaunchPath, args.ToString(), run_log, TimeSpan.FromMinutes(Harness.Timeout), cancellation_token : cancellation_source.Token); if (result.TimedOut) { timed_out = true; success = false; main_log.WriteLine("Test run timed out after {0} minute(s).", Harness.Timeout); } else if (result.Succeeded) { main_log.WriteLine("Test run completed"); success = true; } else { main_log.WriteLine("Test run failed"); success = false; } if (!success.Value) { // find pid var pid = -1; using (var reader = run_log.GetReader()) { while (!reader.EndOfStream) { var line = reader.ReadLine(); if (line.StartsWith("Application launched. PID = ", StringComparison.Ordinal)) { var pidstr = line.Substring("Application launched. PID = ".Length); if (!int.TryParse(pidstr, out pid)) { main_log.WriteLine("Could not parse pid: {0}", pidstr); } } else if (line.Contains("Xamarin.Hosting: Launched ") && line.Contains(" with pid ")) { var pidstr = line.Substring(line.LastIndexOf(' ')); if (!int.TryParse(pidstr, out pid)) { main_log.WriteLine("Could not parse pid: {0}", pidstr); } } else if (line.Contains("error MT1008")) { launch_failure = true; } } } if (pid > 0) { var launchTimedout = cancellation_source.IsCancellationRequested; var timeoutType = launchTimedout ? "Launch" : "Completion"; var timeoutValue = launchTimedout ? Harness.LaunchTimeout : Harness.Timeout; main_log.WriteLine($"{timeoutType} timed out after {timeoutValue}"); await Process_Extensions.KillTreeAsync(pid, main_log, true); } else { main_log.WriteLine("Could not find pid in mtouch output."); } } listener.Cancel(); // cleanup after us if (EnsureCleanSimulatorState) { await SimDevice.KillEverythingAsync(main_log); } foreach (var log in systemLogs) { log.StopCapture(); } } else { main_log.WriteLine("*** Executing {0}/{1} on device '{2}' ***", appName, mode, device_name); if (mode == "watchos") { args.Append(" --attach-native-debugger"); // this prevents the watch from backgrounding the app. } else { args.Append(" --wait-for-exit"); } AddDeviceName(args); device_system_log = Logs.Create($"device-{device_name}-{Harness.Timestamp}.log", "Device log"); var logdev = new DeviceLogCapturer() { Harness = Harness, Log = device_system_log, DeviceName = device_name, }; logdev.StartCapture(); await crash_reports.StartCaptureAsync(); main_log.WriteLine("Starting test run"); bool waitedForExit = true; // We need to check for MT1111 (which means that mlaunch won't wait for the app to exit). var callbackLog = new CallbackLog((line) => { // MT1111: Application launched successfully, but it's not possible to wait for the app to exit as requested because it's not possible to detect app termination when launching using gdbserver waitedForExit &= line?.Contains("MT1111: ") != true; if (line?.Contains("error MT1007") == true) { launch_failure = true; } }); var runLog = Log.CreateAggregatedLog(callbackLog, main_log); var timeout = TimeSpan.FromMinutes(Harness.Timeout); var timeoutWatch = Stopwatch.StartNew(); var result = await ProcessHelper.ExecuteCommandAsync(Harness.MlaunchPath, args.ToString(), runLog, timeout, cancellation_token : cancellation_source.Token); if (!waitedForExit && !result.TimedOut) { // mlaunch couldn't wait for exit for some reason. Let's assume the app exits when the test listener completes. main_log.WriteLine("Waiting for listener to complete, since mlaunch won't tell."); if (!await listener.CompletionTask.TimeoutAfter(timeout - timeoutWatch.Elapsed)) { result.TimedOut = true; } } if (result.TimedOut) { timed_out = true; success = false; main_log.WriteLine("Test run timed out after {0} minute(s).", Harness.Timeout); } else if (result.Succeeded) { main_log.WriteLine("Test run completed"); success = true; } else { main_log.WriteLine("Test run failed"); success = false; } logdev.StopCapture(); device_system_log.Dispose(); // Upload the system log if (File.Exists(device_system_log.FullPath)) { main_log.WriteLine("A capture of the device log is: {0}", device_system_log.FullPath); Harness.LogWrench("@MonkeyWrench: AddFile: {0}", device_system_log.FullPath); } } listener.Dispose(); // check the final status var crashed = false; if (File.Exists(listener_log.FullPath)) { Harness.LogWrench("@MonkeyWrench: AddFile: {0}", listener_log.FullPath); success = TestsSucceeded(listener_log, timed_out, crashed); } else if (timed_out) { Harness.LogWrench("@MonkeyWrench: AddSummary: <b><i>{0} never launched</i></b><br/>", mode); main_log.WriteLine("Test run never launched"); success = false; } else if (launch_failure) { Harness.LogWrench("@MonkeyWrench: AddSummary: <b><i>{0} failed to launch</i></b><br/>", mode); main_log.WriteLine("Test run failed to launch"); success = false; } else { Harness.LogWrench("@MonkeyWrench: AddSummary: <b><i>{0} crashed at startup (no log)</i></b><br/>", mode); main_log.WriteLine("Test run crashed before it started (no log file produced)"); crashed = true; success = false; } if (!success.HasValue) { success = false; } await crash_reports.EndCaptureAsync(TimeSpan.FromSeconds(success.Value ? 0 : 5)); if (timed_out) { Result = TestExecutingResult.TimedOut; } else if (crashed) { Result = TestExecutingResult.Crashed; } else if (success.Value) { Result = TestExecutingResult.Succeeded; } else { Result = TestExecutingResult.Failed; } // Check crash reports to see if any of them explains why the test run crashed. if (!success.Value) { int pid = 0; string crash_reason = null; foreach (var crash in crash_reports.Logs) { try { if (pid == 0) { // Find the pid using (var log_reader = main_log.GetReader()) { string line; while ((line = log_reader.ReadLine()) != null) { const string str = "was launched with pid '"; var idx = line.IndexOf(str, StringComparison.Ordinal); if (idx > 0) { idx += str.Length; var next_idx = line.IndexOf('\'', idx); if (next_idx > idx) { int.TryParse(line.Substring(idx, next_idx - idx), out pid); } } if (pid != 0) { break; } } } } using (var crash_reader = crash.GetReader()) { var text = crash_reader.ReadToEnd(); var reader = System.Runtime.Serialization.Json.JsonReaderWriterFactory.CreateJsonReader(Encoding.UTF8.GetBytes(text), new XmlDictionaryReaderQuotas()); var doc = new XmlDocument(); doc.Load(reader); foreach (XmlNode node in doc.SelectNodes($"/root/processes/item[pid = '" + pid + "']")) { Console.WriteLine(node?.InnerXml); Console.WriteLine(node?.SelectSingleNode("reason")?.InnerText); crash_reason = node?.SelectSingleNode("reason")?.InnerText; } } if (crash_reason != null) { break; } } catch (Exception e) { Harness.Log(2, "Failed to process crash report '{1}': {0}", e.Message, crash.Description); } } if (!string.IsNullOrEmpty(crash_reason)) { if (crash_reason == "per-process-limit") { FailureMessage = "Killed due to using too much memory (per-process-limit)."; } else { FailureMessage = $"Killed by the OS ({crash_reason})"; } } else if (launch_failure) { FailureMessage = $"Launch failure"; } } return(success.Value ? 0 : 1); }
public async Task <int> RunAsync() { CrashReportSnapshot crash_reports; LogStream device_system_log = null; LogStream listener_log = null; Log run_log = main_log; Initialize(); if (!isSimulator) { FindDevice(); } crash_reports = new CrashReportSnapshot() { Device = !isSimulator, DeviceName = device_name, Harness = Harness, Log = main_log, Logs = Logs, LogDirectory = LogDirectory, }; var args = new StringBuilder(); if (!string.IsNullOrEmpty(Harness.XcodeRoot)) { args.Append(" --sdkroot ").Append(Harness.XcodeRoot); } for (int i = -1; i < Harness.Verbosity; i++) { args.Append(" -v "); } args.Append(" -argument=-connection-mode -argument=none"); // This will prevent the app from trying to connect to any IDEs args.Append(" -argument=-app-arg:-autostart"); args.Append(" -setenv=NUNIT_AUTOSTART=true"); args.Append(" -argument=-app-arg:-autoexit"); args.Append(" -setenv=NUNIT_AUTOEXIT=true"); args.Append(" -argument=-app-arg:-enablenetwork"); args.Append(" -setenv=NUNIT_ENABLE_NETWORK=true"); // detect if we are using a jenkins bot. if (Harness.InJenkins) { args.Append(" -setenv=NUNIT_ENABLE_XML_OUTPUT=true"); } if (isSimulator) { args.Append(" -argument=-app-arg:-hostname:127.0.0.1"); args.Append(" -setenv=NUNIT_HOSTNAME=127.0.0.1"); } else { var ips = new StringBuilder(); var ipAddresses = System.Net.Dns.GetHostEntry(System.Net.Dns.GetHostName()).AddressList; for (int i = 0; i < ipAddresses.Length; i++) { if (i > 0) { ips.Append(','); } ips.Append(ipAddresses [i].ToString()); } args.AppendFormat(" -argument=-app-arg:-hostname:{0}", ips.ToString()); args.AppendFormat(" -setenv=NUNIT_HOSTNAME={0}", ips.ToString()); } var transport = mode == "watchos" ? "HTTP" : "TCP"; args.AppendFormat(" -argument=-app-arg:-transport:{0}", transport); args.AppendFormat(" -setenv=NUNIT_TRANSPORT={0}", transport); SimpleListener listener; switch (transport) { case "HTTP": listener = new SimpleHttpListener(); break; case "TCP": listener = new SimpleTcpListener(); break; default: throw new NotImplementedException(); } listener_log = Logs.CreateStream(LogDirectory, string.Format("test-{0}-{1:yyyyMMdd_HHmmss}.log", mode, DateTime.Now), "Test log"); listener.TestLog = listener_log; listener.Log = main_log; listener.AutoExit = true; listener.Address = System.Net.IPAddress.Any; listener.Initialize(); args.AppendFormat(" -argument=-app-arg:-hostport:{0}", listener.Port); args.AppendFormat(" -setenv=NUNIT_HOSTPORT={0}", listener.Port); listener.StartAsync(); var cancellation_source = new CancellationTokenSource(); var timed_out = false; ThreadPool.QueueUserWorkItem((v) => { if (!listener.WaitForConnection(TimeSpan.FromMinutes(Harness.LaunchTimeout))) { cancellation_source.Cancel(); main_log.WriteLine("Test launch timed out after {0} minute(s).", Harness.LaunchTimeout); timed_out = true; } else { main_log.WriteLine("Test run started"); } }); foreach (var kvp in Harness.EnvironmentVariables) { args.AppendFormat(" -setenv={0}={1}", kvp.Key, kvp.Value); } bool?success = null; bool launch_failure = false; if (isExtension) { switch (extension) { case Extension.TodayExtension: args.Append(isSimulator ? " --launchsimbundleid" : " --launchdevbundleid"); args.Append(" todayviewforextensions:"); args.Append(BundleIdentifier); args.Append(" --observe-extension "); args.Append(Harness.Quote(launchAppPath)); break; case Extension.WatchKit2: default: throw new NotImplementedException(); } } else { args.Append(isSimulator ? " --launchsim " : " --launchdev "); args.Append(Harness.Quote(launchAppPath)); } if (isSimulator) { if (!await FindSimulatorAsync()) { return(1); } if (mode != "watchos") { var stderr_tty = Marshal.PtrToStringAuto(ttyname(2)); if (!string.IsNullOrEmpty(stderr_tty)) { args.Append(" --stdout=").Append(Harness.Quote(stderr_tty)); args.Append(" --stderr=").Append(Harness.Quote(stderr_tty)); } else { var stdout_log = Logs.CreateFile("Standard output", Path.Combine(LogDirectory, "stdout.log")); var stderr_log = Logs.CreateFile("Standard error", Path.Combine(LogDirectory, "stderr.log")); args.Append(" --stdout=").Append(Harness.Quote(stdout_log.FullPath)); args.Append(" --stderr=").Append(Harness.Quote(stderr_log.FullPath)); } } var systemLogs = new List <CaptureLog> (); foreach (var sim in simulators) { // Upload the system log main_log.WriteLine("System log for the '{1}' simulator is: {0}", sim.SystemLog, sim.Name); bool isCompanion = sim != simulator; var log = new CaptureLog(sim.SystemLog, entire_file: Harness.Action != HarnessAction.Jenkins) { Path = Path.Combine(LogDirectory, sim.Name + ".log"), Description = isCompanion ? "System log (companion)" : "System log", }; log.StartCapture(); Logs.Add(log); systemLogs.Add(log); Harness.LogWrench("@MonkeyWrench: AddFile: {0}", log.Path); } main_log.WriteLine("*** Executing {0}/{1} in the simulator ***", appName, mode); if (EnsureCleanSimulatorState) { foreach (var sim in simulators) { await sim.PrepareSimulatorAsync(main_log, bundle_identifier); } } args.Append(" --device=:v2:udid=").Append(simulator.UDID).Append(" "); await crash_reports.StartCaptureAsync(); main_log.WriteLine("Starting test run"); var result = await ProcessHelper.ExecuteCommandAsync(Harness.MlaunchPath, args.ToString(), run_log, TimeSpan.FromMinutes(Harness.Timeout), cancellation_token : cancellation_source.Token); if (result.TimedOut) { timed_out = true; success = false; main_log.WriteLine("Test run timed out after {0} minute(s).", Harness.Timeout); } else if (result.Succeeded) { main_log.WriteLine("Test run completed"); success = true; } else { main_log.WriteLine("Test run failed"); success = false; } if (!success.Value) { // find pid var pid = -1; using (var reader = run_log.GetReader()) { while (!reader.EndOfStream) { var line = reader.ReadLine(); if (line.StartsWith("Application launched. PID = ", StringComparison.Ordinal)) { var pidstr = line.Substring("Application launched. PID = ".Length); if (!int.TryParse(pidstr, out pid)) { main_log.WriteLine("Could not parse pid: {0}", pidstr); } } else if (line.Contains("Xamarin.Hosting: Launched ") && line.Contains(" with pid ")) { var pidstr = line.Substring(line.LastIndexOf(' ')); if (!int.TryParse(pidstr, out pid)) { main_log.WriteLine("Could not parse pid: {0}", pidstr); } } else if (line.Contains("error MT1008")) { launch_failure = true; } } } if (pid > 0) { var launchTimedout = cancellation_source.IsCancellationRequested; var timeoutType = launchTimedout ? "Launch" : "Completion"; var timeoutValue = launchTimedout ? Harness.LaunchTimeout : Harness.Timeout; main_log.WriteLine($"{timeoutType} timed out after {timeoutValue}"); await Process_Extensions.KillTreeAsync(pid, main_log, true); } else { main_log.WriteLine("Could not find pid in mtouch output."); } } listener.Cancel(); // cleanup after us if (EnsureCleanSimulatorState) { await SimDevice.KillEverythingAsync(main_log); } foreach (var log in systemLogs) { log.StopCapture(); } } else { main_log.WriteLine("*** Executing {0}/{1} on device '{2}' ***", appName, mode, device_name); if (mode == "watchos") { args.Append(" --attach-native-debugger"); // this prevents the watch from backgrounding the app. } else { args.Append(" --wait-for-exit"); } AddDeviceName(args); device_system_log = Logs.CreateStream(LogDirectory, $"device-{device_name}-{DateTime.Now:yyyyMMdd_HHmmss}.log", "Device log"); var logdev = new DeviceLogCapturer() { Harness = Harness, Log = device_system_log, DeviceName = device_name, }; logdev.StartCapture(); await crash_reports.StartCaptureAsync(); main_log.WriteLine("Starting test run"); var result = await ProcessHelper.ExecuteCommandAsync(Harness.MlaunchPath, args.ToString(), main_log, TimeSpan.FromMinutes(Harness.Timeout), cancellation_token : cancellation_source.Token); if (result.TimedOut) { timed_out = true; success = false; main_log.WriteLine("Test run timed out after {0} minute(s).", Harness.Timeout); } else if (result.Succeeded) { main_log.WriteLine("Test run completed"); success = true; } else { main_log.WriteLine("Test run failed"); success = false; } logdev.StopCapture(); // Upload the system log if (File.Exists(device_system_log.FullPath)) { main_log.WriteLine("A capture of the device log is: {0}", device_system_log.FullPath); Harness.LogWrench("@MonkeyWrench: AddFile: {0}", device_system_log.FullPath); } } listener.Dispose(); // check the final status var crashed = false; if (File.Exists(listener_log.FullPath)) { Harness.LogWrench("@MonkeyWrench: AddFile: {0}", listener_log.FullPath); success = TestsSucceeded(listener_log, timed_out, crashed); } else if (timed_out) { Harness.LogWrench("@MonkeyWrench: AddSummary: <b><i>{0} never launched</i></b><br/>", mode); main_log.WriteLine("Test run never launched"); success = false; } else if (launch_failure) { Harness.LogWrench("@MonkeyWrench: AddSummary: <b><i>{0} failed to launch</i></b><br/>", mode); main_log.WriteLine("Test run failed to launch"); success = false; } else { Harness.LogWrench("@MonkeyWrench: AddSummary: <b><i>{0} crashed at startup (no log)</i></b><br/>", mode); main_log.WriteLine("Test run crashed before it started (no log file produced)"); crashed = true; success = false; } if (!success.HasValue) { success = false; } await crash_reports.EndCaptureAsync(TimeSpan.FromSeconds(success.Value ? 0 : 5)); if (timed_out) { Result = TestExecutingResult.TimedOut; } else if (crashed) { Result = TestExecutingResult.Crashed; } else if (success.Value) { Result = TestExecutingResult.Succeeded; } else { Result = TestExecutingResult.Failed; } return(success.Value ? 0 : 1); }