From 1aa0ea7a8aef616d00e8467aa9eec83a1571cbd0 Mon Sep 17 00:00:00 2001 From: Marek Habersack Date: Wed, 23 Aug 2023 01:12:24 +0000 Subject: [PATCH] [Mono.Android] Marshal .NET stack trace to Throwable.getStackTrace() (#8185) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Context: https://github.com/xamarin/xamarin-android/issues/1198 Context: https://github.com/xamarin/xamarin-android/issues/1188#issuecomment-358184674 Context: https://github.com/xamarin/xamarin-android/pull/4877 Context: https://github.com/xamarin/xamarin-android/pull/4927#issuecomment-875864999 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.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.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.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.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.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.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.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. --- .../Android.Runtime/AndroidRuntime.cs | 2 +- .../Android.Runtime/JavaProxyThrowable.cs | 74 +++++++++++++++++-- src/Mono.Android/Java.Lang/Throwable.cs | 2 +- .../System/ExceptionTest.cs | 43 ++++++++++- 4 files changed, 109 insertions(+), 12 deletions(-) diff --git a/src/Mono.Android/Android.Runtime/AndroidRuntime.cs b/src/Mono.Android/Android.Runtime/AndroidRuntime.cs index fafdc00e8b9..9e67d00721c 100644 --- a/src/Mono.Android/Android.Runtime/AndroidRuntime.cs +++ b/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); diff --git a/src/Mono.Android/Android.Runtime/JavaProxyThrowable.cs b/src/Mono.Android/Android.Runtime/JavaProxyThrowable.cs index 89f4d01844e..7e350980638 100644 --- a/src/Mono.Android/Android.Runtime/JavaProxyThrowable.cs +++ b/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); } } } diff --git a/src/Mono.Android/Java.Lang/Throwable.cs b/src/Mono.Android/Java.Lang/Throwable.cs index 5dc63ef7952..ae668e24c27 100644 --- a/src/Mono.Android/Java.Lang/Throwable.cs +++ b/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) diff --git a/tests/Mono.Android-Tests/System/ExceptionTest.cs b/tests/Mono.Android-Tests/System/ExceptionTest.cs index cc8aaab7a50..0c2c1fd847b 100644 --- a/tests/Mono.Android-Tests/System/ExceptionTest.cs +++ b/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"); + } + } } }