[Mono.Android] Marshal .NET stack trace to Throwable.getStackTrace() (#8185)

Context: #1198
Context: #1188 (comment)
Context: #4877
Context: #4927 (comment)

What happens with unhandled exceptions?

	throw new InvalidOperationException ("oops!");

This is a surprisingly complicated question:

If this happens when a debugger is attached, the debugger will get a
"first chance notification" at the `throw` site.  If execution
continues, odds are high that the app will abort if there is a JNI
transition in the callstack.

If no debugger is attached, then it depends on which thread threw the
unhandled exception.

If the thread which threw the unhandled exception is a .NET Thread:

	static void ThrowFromAnotherManagedThread() {
	    var t = new System.Threading.Thread(() => {
	        throw new new Java.Lang.Error ("from another thread?!");
	    });
	    t.Start ();
	    t.Join ();
	}

Then .NET will report the unhandled exception, *and*
the app will restart:

	F mono-rt : [ERROR] FATAL UNHANDLED EXCEPTION: System.InvalidOperationException: oops!
	F mono-rt :    at android_unhandled_exception.MainActivity.<>c.<ThrowFromAnotherManagedThread>b__1_0()
	F mono-rt :    at System.Threading.Thread.StartCallback()
	# app restarts

If the thread which threw the unhandled exception is a *Java* thread,
which could be the UI thread (e.g. thrown from an `Activity.OnCreate()`
override) or via a `Java.Lang.Thread` instance:

	static void ThrowFromAnotherJavaThread() {
	    var t = new Java.Lang.Thread(() => {
	        throw new InvalidOperationException ("oops!");
	    });
	    t.Start ();
	    t.Join ();
	}

Then .NET will report the unhandled exception, *and* the app will
*not* restart (which differs from using .NET threads):

	E AndroidRuntime: Process: com.companyname.android_unhandled_exception, PID: 5436
	E AndroidRuntime: android.runtime.JavaProxyThrowable: System.InvalidOperationException: oops!
	E AndroidRuntime:    at android_unhandled_exception.MainActivity.<>c.<ThrowFromAnotherJavaThread>b__2_0()
	E AndroidRuntime:    at Java.Lang.Thread.RunnableImplementor.Run()
	E AndroidRuntime:    at Java.Lang.IRunnableInvoker.n_Run(IntPtr , IntPtr )
	E AndroidRuntime:    at Android.Runtime.JNINativeWrapper.Wrap_JniMarshal_PP_V(_JniMarshal_PP_V , IntPtr , IntPtr )
	E AndroidRuntime:        at mono.java.lang.RunnableImplementor.n_run(Native Method)
	E AndroidRuntime:        at mono.java.lang.RunnableImplementor.run(RunnableImplementor.java:31)
	E AndroidRuntime:        at java.lang.Thread.run(Thread.java:1012)
	I MonoDroid: Android.Runtime.JavaProxyThrowable: Exception_WasThrown, Android.Runtime.JavaProxyThrowable
	I MonoDroid: 
	I MonoDroid:   --- End of managed Android.Runtime.JavaProxyThrowable stack trace ---
	I MonoDroid: android.runtime.JavaProxyThrowable: System.InvalidOperationException: oops!
	I MonoDroid:    at android_unhandled_exception.MainActivity.<>c.<ThrowFromAnotherJavaThread>b__2_0()
	I MonoDroid:    at Java.Lang.Thread.RunnableImplementor.Run()
	I MonoDroid:    at Java.Lang.IRunnableInvoker.n_Run(IntPtr , IntPtr )
	I MonoDroid:    at Android.Runtime.JNINativeWrapper.Wrap_JniMarshal_PP_V(_JniMarshal_PP_V , IntPtr , IntPtr )
	I MonoDroid:     at mono.java.lang.RunnableImplementor.n_run(Native Method)
	I MonoDroid:     at mono.java.lang.RunnableImplementor.run(RunnableImplementor.java:31)
	I MonoDroid:     at java.lang.Thread.run(Thread.java:1012)
	I MonoDroid: 
	I MonoDroid:   --- End of managed Android.Runtime.JavaProxyThrowable stack trace ---
	I MonoDroid: android.runtime.JavaProxyThrowable: System.InvalidOperationException: oops!
	I MonoDroid:    at android_unhandled_exception.MainActivity.<>c.<ThrowFromAnotherJavaThread>b__2_0()
	I MonoDroid:    at Java.Lang.Thread.RunnableImplementor.Run()
	I MonoDroid:    at Java.Lang.IRunnableInvoker.n_Run(IntPtr , IntPtr )
	I MonoDroid:    at Android.Runtime.JNINativeWrapper.Wrap_JniMarshal_PP_V(_JniMarshal_PP_V , IntPtr , IntPtr )
	I MonoDroid:     at mono.java.lang.RunnableImplementor.n_run(Native Method)
	I MonoDroid:     at mono.java.lang.RunnableImplementor.run(RunnableImplementor.java:31)
	I MonoDroid:     at java.lang.Thread.run(Thread.java

This "works", until we enter the world of crash logging for later
diagnosis and fixing.  The problem with our historical approach is
that we would "stuff" the .NET stack trace into the "message" of the
Java-side `Throwable` instance, and the "message" may not be
transmitted as part of the crash logging!

(This is noticeable by the different indentation levels for the
`at …` lines in the crash output.  Three space indents are from the
`Throwable.getMessage()` output, while four space indents are from
the Java-side stack trace.)

We *think* that we can improve this by replacing the Java-side stack
trace with a "merged" stack trace which includes both the Java-side
and .NET-side stack traces.  This does nothing for unhandled exceptions
on .NET threads, but does alter the output from Java threads:

	E AndroidRuntime: FATAL EXCEPTION: Thread-3
	E AndroidRuntime: Process: com.companyname.android_unhandled_exception, PID: 12321
	E AndroidRuntime: android.runtime.JavaProxyThrowable: [System.InvalidOperationException]: oops!
	E AndroidRuntime:        at android_unhandled_exception.MainActivity+<>c.<ThrowFromAnotherJavaThread>b__2_0(Unknown Source:0)
	E AndroidRuntime:        at Java.Lang.Thread+RunnableImplementor.Run(Unknown Source:0)
	E AndroidRuntime:        at Java.Lang.IRunnableInvoker.n_Run(Unknown Source:0)
	E AndroidRuntime:        at Android.Runtime.JNINativeWrapper.Wrap_JniMarshal_PP_V(Unknown Source:0)
	E AndroidRuntime:        at mono.java.lang.RunnableImplementor.n_run(Native Method)
	E AndroidRuntime:        at mono.java.lang.RunnableImplementor.run(RunnableImplementor.java:31)
	E AndroidRuntime:        at java.lang.Thread.run(Thread.java:1012)
	I MonoDroid: UNHANDLED EXCEPTION:
	I MonoDroid: Android.Runtime.JavaProxyThrowable: Exception_WasThrown, Android.Runtime.JavaProxyThrowable
	I MonoDroid: 
	I MonoDroid:   --- End of managed Android.Runtime.JavaProxyThrowable stack trace ---
	I MonoDroid: android.runtime.JavaProxyThrowable: [System.InvalidOperationException]: oops!
	I MonoDroid:     at android_unhandled_exception.MainActivity+<>c.<ThrowFromAnotherJavaThread>b__2_0(Unknown Source:0)
	I MonoDroid:     at Java.Lang.Thread+RunnableImplementor.Run(Unknown Source:0)
	I MonoDroid:     at Java.Lang.IRunnableInvoker.n_Run(Unknown Source:0)
	I MonoDroid:     at Android.Runtime.JNINativeWrapper.Wrap_JniMarshal_PP_V(Unknown Source:0)
	I MonoDroid:     at mono.java.lang.RunnableImplementor.n_run(Native Method)
	I MonoDroid:     at mono.java.lang.RunnableImplementor.run(RunnableImplementor.java:31)
	I MonoDroid:     at java.lang.Thread.run(Thread.java:1012)
	I MonoDroid: 
	I MonoDroid:   --- End of managed Android.Runtime.JavaProxyThrowable stack trace ---
	I MonoDroid: android.runtime.JavaProxyThrowable: [System.InvalidOperationException]: oops!
	I MonoDroid:     at android_unhandled_exception.MainActivity+<>c.<ThrowFromAnotherJavaThread>b__2_0(Unknown Source:0)
	I MonoDroid:     at Java.Lang.Thread+RunnableImplementor.Run(Unknown Source:0)
	I MonoDroid:     at Java.Lang.IRunnableInvoker.n_Run(Unknown Source:0)
	I MonoDroid:     at Android.Runtime.JNINativeWrapper.Wrap_JniMarshal_PP_V(Unknown Source:0)
	I MonoDroid:     at mono.java.lang.RunnableImplementor.n_run(Native Method)
	I MonoDroid:     at mono.java.lang.RunnableImplementor.run(RunnableImplementor.java:31)
	I MonoDroid:     at java.lang.Thread.run(Thread.java:1012)

Note how `at …` is always a four-space indent and always lines up.
*Hopefully* this means that crash loggers can provide more useful
information.

TODO:

  * Create an "end-to-end" test which uses an actual crash logger
    (which one?) in order to better understand what the
    "end user" experience is.

  * The "merged" stack trace always places the managed stack trace
    above the Java-side stack trace.  This means things will look
    "weird"/"wrong" if you have an *intermixed* stack trace, e.g.
    (Java code calls .NET code which calls Java code)+
    which eventually throws from .NET.

Author: grendello

src/Mono.Android/Android.Runtime/AndroidRuntime.cs

@@ -79,7 +79,7 @@ public override void RaisePendingException (Exception pendingException)
 		{
 			var je  = pendingException as JavaProxyThrowable;
 			if (je == null) {
-				je  = new JavaProxyThrowable (pendingException);
+				je  = JavaProxyThrowable.Create (pendingException);
 			}
 			var r = new JniObjectReference (je.Handle);
 			JniEnvironment.Exceptions.Throw (r);

src/Mono.Android/Android.Runtime/JavaProxyThrowable.cs

@@ -1,23 +1,83 @@
 using System;
+using System.Diagnostics;
+using System.Reflection;
+
+using StackTraceElement = Java.Lang.StackTraceElement;
 
 namespace Android.Runtime {
 
-	class JavaProxyThrowable : Java.Lang.Error {
+	sealed class JavaProxyThrowable : Java.Lang.Error {
 
 		public  readonly Exception InnerException;
 
-		public JavaProxyThrowable (Exception innerException)
-			: base (GetDetailMessage (innerException))
+		JavaProxyThrowable (string message, Exception innerException)
+			: base (message)
 		{
 			InnerException  = innerException;
 		}
 
-		static string GetDetailMessage (Exception innerException)
+		public static JavaProxyThrowable Create (Exception innerException)
+		{
+			if (innerException == null) {
+				throw new ArgumentNullException (nameof (innerException));
+			}
+
+			// We prepend managed exception type to message since Java will see `JavaProxyThrowable` instead.
+			var proxy = new JavaProxyThrowable ($"[{innerException.GetType ()}]: {innerException.Message}", innerException);
+
+			try {
+				proxy.TranslateStackTrace ();
+			} catch (Exception ex) {
+				// We shouldn't throw here, just try to do the best we can do
+				Console.WriteLine ($"JavaProxyThrowable: translation threw an exception: {ex}");
+				proxy = new JavaProxyThrowable (innerException.ToString (), innerException);
+			}
+
+			return proxy;
+		}
+
+		void TranslateStackTrace ()
 		{
-			if (innerException == null)
-				throw new ArgumentNullException ("innerException");
+			var trace = new StackTrace (InnerException, fNeedFileInfo: true);
+			if (trace.FrameCount <= 0) {
+				return;
+			}
+
+			StackTraceElement[]? javaTrace = null;
+			try {
+				javaTrace = GetStackTrace ();
+			} catch (Exception ex) {
+				// Report...
+				Console.WriteLine ($"JavaProxyThrowable: obtaining Java stack trace threw an exception: {ex}");
+				// ..but ignore
+			}
+
+
+			StackFrame[] frames = trace.GetFrames ();
+			int nElements = frames.Length + (javaTrace?.Length ?? 0);
+			StackTraceElement[] elements = new StackTraceElement[nElements];
+
+			for (int i = 0; i < frames.Length; i++) {
+				StackFrame managedFrame = frames[i];
+				MethodBase? managedMethod = managedFrame.GetMethod ();
+
+				var throwableFrame = new StackTraceElement (
+					declaringClass: managedMethod?.DeclaringType?.FullName,
+					methodName: managedMethod?.Name,
+					fileName: managedFrame?.GetFileName (),
+					lineNumber: managedFrame?.GetFileLineNumber () ?? -1
+				);
+
+				elements[i] = throwableFrame;
+			}
+
+			if (javaTrace != null) {
+				for (int i = frames.Length; i < nElements; i++) {
+					elements[i] = javaTrace[i - frames.Length];
+				}
+			}
 
-			return innerException.ToString ();
+			SetStackTrace (elements);
 		}
 	}
 }

src/Mono.Android/Java.Lang/Throwable.cs

@@ -253,7 +253,7 @@ public static Throwable FromException (System.Exception e)
 			if (e is Throwable)
 				return (Throwable) e;
 
-			return new Android.Runtime.JavaProxyThrowable (e);
+			return Android.Runtime.JavaProxyThrowable.Create (e);
 		}
 
 		public static System.Exception ToException (Throwable e)

tests/Mono.Android-Tests/System/ExceptionTest.cs

@@ -1,5 +1,7 @@
 using System;
+using System.Diagnostics;
 using System.Globalization;
+using System.Reflection;
 
 using Android.App;
 using Android.Content;
@@ -17,18 +19,53 @@ static Java.Lang.Throwable CreateJavaProxyThrowable (Exception e)
 			var JavaProxyThrowable_type = typeof (Java.Lang.Object)
 				.Assembly
 				.GetType ("Android.Runtime.JavaProxyThrowable");
-			return (Java.Lang.Throwable) Activator.CreateInstance (JavaProxyThrowable_type, e);
+			MethodInfo? create = JavaProxyThrowable_type.GetMethod (
+				"Create",
+				BindingFlags.Static | BindingFlags.Public,
+				new Type[] { typeof (Exception) }
+			);
+
+			Assert.AreNotEqual (null, create, "Unable to find the Android.Runtime.JavaProxyThrowable.Create(Exception) method");
+			return (Java.Lang.Throwable)create.Invoke (null, new object[] { e }); // Don't append Java stack trace
 		}
 
 		[Test]
 		public void InnerExceptionIsSet ()
 		{
-			var ex  = new InvalidOperationException ("boo!");
-			using (var source = new Java.Lang.Throwable ("detailMessage", CreateJavaProxyThrowable (ex)))
+			Exception ex;
+			try {
+				throw new InvalidOperationException ("boo!");
+			} catch (Exception e) {
+				ex = e;
+			}
+
+			using (Java.Lang.Throwable proxy = CreateJavaProxyThrowable (ex))
+			using (var source = new Java.Lang.Throwable ("detailMessage", proxy))
 			using (var alias  = new Java.Lang.Throwable (source.Handle, JniHandleOwnership.DoNotTransfer)) {
+				CompareStackTraces (ex, proxy);
 				Assert.AreEqual ("detailMessage", alias.Message);
 				Assert.AreSame (ex, alias.InnerException);
 			}
 		}
+
+		void CompareStackTraces (Exception ex, Java.Lang.Throwable throwable)
+		{
+			var managedTrace = new StackTrace (ex);
+			StackFrame[] managedFrames = managedTrace.GetFrames ();
+			Java.Lang.StackTraceElement[] javaFrames = throwable.GetStackTrace ();
+
+			// Java
+			Assert.IsTrue (javaFrames.Length >= managedFrames.Length,
+					$"Java should have at least as many frames as .NET does; java({javaFrames.Length}) < managed({managedFrames.Length})");
+			for (int i = 0; i < managedFrames.Length; i++) {
+				var mf = managedFrames[i];
+				var jf = javaFrames[i];
+
+				Assert.AreEqual (mf.GetMethod ()?.Name,                   jf.MethodName, $"Frame {i}: method names differ");
+				Assert.AreEqual (mf.GetMethod ()?.DeclaringType.FullName, jf.ClassName,  $"Frame {i}: class names differ");
+				Assert.AreEqual (mf.GetFileName (),                       jf.FileName,   $"Frame {i}: file names differ");
+				Assert.AreEqual (mf.GetFileLineNumber (),                 jf.LineNumber, $"Frame {i}: line numbers differ");
+			}
+		}
 	}
 }