Apparently Process.HasExited may throw exceptions, so handle those gracefully
(by ignoring them completely):
Unhandled Exception:
System.AggregateException: One or more errors occurred. (No process is associated with this object.) ---> System.InvalidOperationException: No process is associated with this object.
at System.Diagnostics.Process.EnsureState (System.Diagnostics.Process+State state) [0x00018] in <d012d9eca6d14975a47488863de2f4c6>:0
at System.Diagnostics.Process.get_HasExited () [0x0000b] in <d012d9eca6d14975a47488863de2f4c6>:0
at (wrapper remoting-invoke-with-check) System.Diagnostics.Process.get_HasExited()
at xharness.Process_Extensions+<>c__DisplayClass2_0.<RunAsync>b__2 () [0x00001] in <285dbdcf9e034cd496a3fef953fac640>:0
at System.Threading.CancellationToken.ActionToActionObjShunt (System.Object obj) [0x00000] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.CancellationCallbackInfo.ExecutionContextCallback (System.Object obj) [0x00007] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00071] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00000] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state) [0x0002b] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.CancellationCallbackInfo.ExecuteCallback () [0x00024] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.CancellationTokenSource.CancellationCallbackCoreWork (System.Threading.CancellationCallbackCoreWorkArguments args) [0x00042] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.CancellationTokenSource.ExecuteCallbackHandlers (System.Boolean throwOnFirstException) [0x000c0] in <96207d0baa204f48a53ad6be05f5ecba>:0
--- End of inner exception stack trace ---
at System.Threading.CancellationTokenSource.ExecuteCallbackHandlers (System.Boolean throwOnFirstException) [0x00132] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.CancellationTokenSource.NotifyCancellation (System.Boolean throwOnFirstException) [0x0005f] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.CancellationTokenSource.Cancel (System.Boolean throwOnFirstException) [0x00006] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.CancellationTokenSource.Cancel () [0x00000] in <96207d0baa204f48a53ad6be05f5ecba>:0
at xharness.AppRunner+<>c__DisplayClass73_0.<RunAsync>b__0 (System.Object v) [0x00029] in <285dbdcf9e034cd496a3fef953fac640>:0
at System.Threading.QueueUserWorkItemCallback.WaitCallback_Context (System.Object state) [0x00007] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00071] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00000] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem () [0x00021] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.ThreadPoolWorkQueue.Dispatch () [0x00074] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback () [0x00000] in <96207d0baa204f48a53ad6be05f5ecba>:0
---> (Inner Exception #0) System.InvalidOperationException: No process is associated with this object.
at System.Diagnostics.Process.EnsureState (System.Diagnostics.Process+State state) [0x00018] in <d012d9eca6d14975a47488863de2f4c6>:0
at System.Diagnostics.Process.get_HasExited () [0x0000b] in <d012d9eca6d14975a47488863de2f4c6>:0
at (wrapper remoting-invoke-with-check) System.Diagnostics.Process.get_HasExited()
at xharness.Process_Extensions+<>c__DisplayClass2_0.<RunAsync>b__2 () [0x00001] in <285dbdcf9e034cd496a3fef953fac640>:0
at System.Threading.CancellationToken.ActionToActionObjShunt (System.Object obj) [0x00000] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.CancellationCallbackInfo.ExecutionContextCallback (System.Object obj) [0x00007] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.ExecutionContext.RunInternal (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00071] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state, System.Boolean preserveSyncCtx) [0x00000] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.ExecutionContext.Run (System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, System.Object state) [0x0002b] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.CancellationCallbackInfo.ExecuteCallback () [0x00024] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.CancellationTokenSource.CancellationCallbackCoreWork (System.Threading.CancellationCallbackCoreWorkArguments args) [0x00042] in <96207d0baa204f48a53ad6be05f5ecba>:0
at System.Threading.CancellationTokenSource.ExecuteCallbackHandlers (System.Boolean throwOnFirstException) [0x000c0] in <96207d0baa204f48a53ad6be05f5ecba>:0 <---
Recursively printing diagnostics can leave us with _many_ lldb processes, each
pretty much hanging, and the system overloaded, which, in the worst case
scenario, would require a hard reboot.
Most commonly the "only" thing that happens is an OutOfMemoryException when
the OS eventually tells xharness NO to launching new processes.
Fixes https://github.com/xamarin/maccore/issues/1163.
* [xharness] Simplify code a bit.
Logs are TextWriters by themselves, so no need to get a StreamWriter to pass
to API that takes TextWriter, when we can just pass the log instance itself.
This makes it possible to timestamp external process output (because
Log.Timestamp is honored instead of bypassed).
* [xharness] Timestamp install logs.
So that we get exact numbers of how long it takes to install on watch (and if
the watch installation stalls, or just times out because it takes too long).
Always wait for processes to exit, even if they're killed.
Also make absolutely sure that we can safely handle any exception when getting
the ExitCode, no matter what.
https://bugzilla.xamarin.com/show_bug.cgi?id=57846
Sometimes streams won't write null when done, which means that if we wait
indefinitely for this to happen, we'll effectively deadlock.
Instead have a 1s timeout, after which we consider that we've captured
everything we need.
Example: https://jenkins.mono-project.com/job/xamarin-macios-pr-builder/3771/Test_Report/
(the test run hangs waiting for the mtouch tests, which finished pretty much instantly).
Example log output when bumping mono:
> Found 1 modified file(s) in the pull request #1161.
> external/mono
> Enabled 'mtouch' tests because the modified file 'external/mono' matches prefix 'external/mono'
> Enabled 'mmp' tests because the modified file 'external/mono' matches prefix 'external/mono'
> Enabled 'bcl' tests because the modified file 'external/mono' matches prefix 'external/mono'
> Found 1 label(s) in the pull request #1161: cla-already-signed
Or when changing the static registrar:
> Found 1 modified file(s) in the pull request #1164.
> tools/common/StaticRegistrar.cs
> Enabled 'mtouch' tests because the modified file 'tools/common/StaticRegistrar.cs' matches prefix 'tools/common'
> Enabled 'mmp' tests because the modified file 'tools/common/StaticRegistrar.cs' matches prefix 'tools/common'
> Found 2 label(s) in the pull request #1164: cla-already-signed, run-mmp-tests
> Enabled 'mmp' tests because the label 'run-mmp-tests' is set.
Make sure as much as possible is written to the logs, and not stdout.
Also copy an extra 1024 bytes when fetching the system log (and continue
capturing a while after stopped, since there may be unflushed system log
data in memory).
Split out the code to prepare the simulator from the AppRunner class,
which is now just handling the logic required for each test run.
This way it's easier to handle simulator preparation for multiple
test runs with the same simulator.
Also revamp logging to avoid printing directly to the console, but
instead use the logging classes that permit redirecting logging
to a file. This makes the html report show better logging.
Rolf Bjarne Kvinge
Sebastien Pouliot
Timothy Risi