Sanandrea Sanandrea - 28 days ago 16
Java Question

How to debug: JNI DETECTED ERROR IN APPLICATION: use of invalid jobject

I am working on a

Xamarin
Android project, and I get the following error (full log here)

11-07 08:28:09.067: A/art(7164): art/runtime/java_vm_ext.cc:410] JNI DETECTED ERROR IN APPLICATION: use of invalid jobject 0xd4fd90e0
11-07 08:28:09.067: A/art(7164): art/runtime/java_vm_ext.cc:410] "Thread-1973" prio=10 tid=26 Runnable
11-07 08:28:09.067: A/art(7164): art/runtime/java_vm_ext.cc:410] | group="main" sCount=0 dsCount=0 obj=0x137270a0 self=0xc89d4900
11-07 08:28:09.067: A/art(7164): art/runtime/java_vm_ext.cc:410] | sysTid=9034 nice=-11 cgrp=default sched=0/0 handle=0xd4b3a930
11-07 08:28:09.067: A/art(7164): art/runtime/java_vm_ext.cc:410] | state=R schedstat=( 310795035 15833156 94 ) utm=24 stm=7 core=5 HZ=100
11-07 08:28:09.067: A/art(7164): art/runtime/java_vm_ext.cc:410] | stack=0xd4a3c000-0xd4a3e000 stackSize=1022KB
11-07 08:28:09.067: A/art(7164): art/runtime/java_vm_ext.cc:41n0] | held mutexes= "mutator lock"(shared held)


when try to play a movie (custom third party ExoPlayer wrapper library) while in airplane mode. I am not seeking help to find the bug with only this info, but only a way to debug app. When crash appears the debugger is disconnected.

Also I have seen this thread: https://bugzilla.xamarin.com/show_bug.cgi?id=45281
on Xamarin bugzilla, but when I enable GC logs with the following:

$ adb shell setprop debug.mono.log gref,gc


the app does not crash!!!

I am testing on device
Samsung SM-G930F
aka
Samsung S7
and using
API level 23
. The error appears also on other devices.

My build setup:

Xamarin Studio Community
Version 6.1.1 (build 15)
Installation UUID: b3096ed4-0118-4e0d-87f4-a1fe79ffc301
Runtime:
Mono 4.6.1 (mono-4.6.0-branch-c8sr0/ef43c15) (64-bit)
GTK+ 2.24.23 (Raleigh theme)

Package version: 406010005

NuGet
Version: 3.4.3.0

Xamarin.Profiler
Not Installed

Apple Developer Tools
Xcode 8.1 (11544)
Build 8B62

Xamarin.Mac
Version: 2.10.0.105 (Xamarin Studio Community)

Xamarin.iOS
Version: 10.0.1.10 (Xamarin Studio Community)
Hash: ad1cd42
Branch: cycle8-sr0-xi
Build date: 2016-10-03 15:18:44-0400

Xamarin.Android
Version: 7.0.1.3 (Xamarin Studio Community)
Android SDK: /Users/andi/Library/Android/sdk
Supported Android versions:
5.0 (API level 21)
6.0 (API level 23)
7.0 (API level 24)

SDK Tools Version: 25.2.2
SDK Platform Tools Version: 24.0.3
SDK Build Tools Version: 23.0.1

Java SDK: /usr
java version "1.8.0_91"
Java(TM) SE Runtime Environment (build 1.8.0_91-b14)
Java HotSpot(TM) 64-Bit Server VM (build 25.91-b14, mixed mode)

Android Designer EPL code available here:
https://github.com/xamarin/AndroidDesigner.EPL

Xamarin Android Player
Version: 0.6.5
Location: /Applications/Xamarin Android Player.app

Build Information
Release ID: 601010015
Git revision: fa52f02641726146e2589ed86ec4097fbe101888
Build date: 2016-09-22 08:03:02-04
Xamarin addins: 75d65712af93d54dc39ae4c42b21dfa574859fd6
Build lane: monodevelop-lion-cycle8-sr0

Operating System
Mac OS X 10.12.1
Darwin Pentagon.local 16.1.0 Darwin Kernel Version 16.1.0
Thu Oct 13 21:26:57 PDT 2016
root:xnu-3789.21.3~60/RELEASE_X86_64 x86_64


thanks in advance

Answer

Ideally how you would debug this type of situation is very close to the path you are following.

The first thing that you'd want to do is enable gref logs via adb or an environment.txt file with a Build Action of AndroidEnvironment(Note: There are limitations using the latter option - https://developer.xamarin.com/guides/android/advanced_topics/environment/#Overview):

adb shell setprop debug.mono.log gref

https://developer.xamarin.com/guides/android/troubleshooting/troubleshooting/#Global_Reference_Messages

Great! Now we can see the lifetime of respective global references(gref for short). This is a starting point. For future reference in this post, let's define a few items:

  • gref - Global Reference
  • wref - Weak Global Reference

Ideally we want to test this on a physical device as it will have a limit of ~52000 grefs. Whereas an emulator has a limit of 2000 grefs. As you imagine this can be quite troublesome if you cross this line quite quickly(Which you just might).

Next we can follow the convention of four main messages we want to know about:

  • Start with +g+ - gref creation
  • Start with -g- - gref destruction
  • Start with +w+ - wref creation
  • Start with -w- - wref destruction

You might also notice that on these lines there is a grefc value. This refers to the gref count which is the total amount that Xamarin.Android has made. You can then assume the same for the grefwc value being the wref count. Let's define this in a small table:

  • grefc - gref count
  • grefwc - wref count

Let' take a look at an example of this syntax:

I/monodroid-gref(12405): +g+ grefc 108 gwrefc 0 obj-handle 0x40517468/L -> new-handle 0x40517468/L from    at Java.Lang.Object.RegisterInstance(IJavaObject instance, IntPtr value, JniHandleOwnership transfer)
I/monodroid-gref(12405):    at Java.Lang.Object.SetHandle(IntPtr value, JniHandleOwnership transfer)
I/monodroid-gref(12405):    at Java.Lang.Object..ctor(IntPtr handle, JniHandleOwnership transfer)
I/monodroid-gref(12405):    at Java.Lang.Thread+RunnableImplementor..ctor(System.Action handler, Boolean removable)
I/monodroid-gref(12405):    at Java.Lang.Thread+RunnableImplementor..ctor(System.Action handler)
I/monodroid-gref(12405):    at Android.App.Activity.RunOnUiThread(System.Action action)
I/monodroid-gref(12405):    at Mono.Samples.Hello.HelloActivity.UseLotsOfMemory(Android.Widget.TextView textview)
I/monodroid-gref(12405):    at Mono.Samples.Hello.HelloActivity.<OnCreate>m__3(System.Object o)
I/monodroid-gref(12405): handle 0x40517468; key_handle 0x40517468: Java Type: `mono/java/lang/RunnableImplementor`; MCW type: `Java.Lang.Thread+RunnableImplementor`
I/monodroid-gref(12405): Disposing handle 0x40517468
I/monodroid-gref(12405): -g- grefc 107 gwrefc 0 handle 0x40517468/L from    at Java.Lang.Object.Dispose(System.Object instance, IntPtr handle, IntPtr key_handle, JObjectRefType handle_type)
I/monodroid-gref(12405):    at Java.Lang.Object.Dispose()
I/monodroid-gref(12405):    at Java.Lang.Thread+RunnableImplementor.Run()
I/monodroid-gref(12405):    at Java.Lang.IRunnableInvoker.n_Run(IntPtr jnienv, IntPtr native__this)
I/monodroid-gref(12405):    at System.Object.c200fe6f-ac33-441b-a3a0-47659e3f6750(IntPtr , IntPtr )
I/monodroid-gref(27679): +w+ grefc 1916 gwrefc 296 obj-handle 0x406b2b98/G -> new-handle 0xde68f4bf/W from take_weak_global_ref_jni
I/monodroid-gref(27679): -w- grefc 1915 gwrefc 294 handle 0xde691aaf/W from take_global_ref_jni

The handle or obj-handle value is the JNI handle value, and the character after the ' /' is the type of handle value: /L for local reference, /G for global references, and /W for weak global references.

Now let's take a look into various scenarios with this note in mind:

# Java instance is created and wrapped by a MCW
I/monodroid-gref(27679): +g+ grefc 2211 gwrefc 0 obj-handle 0x4066df10/L -> new-handle 0x4066df10/L from ...
I/monodroid-gref(27679): handle 0x4066df10; key_handle 0x4066df10: Java Type: `android/graphics/drawable/TransitionDrawable`; MCW type: `Android.Graphics.Drawables.TransitionDrawable`

# A GC is being performed...
I/monodroid-gref(27679): +w+ grefc 1953 gwrefc 259 obj-handle 0x4066df10/G -> new-handle 0xde68f95f/W from take_weak_global_ref_jni
I/monodroid-gref(27679): -g- grefc 1952 gwrefc 259 handle 0x4066df10/G from take_weak_global_ref_jni

# Object is still alive, as handle != null
# wref turned back into a gref
I/monodroid-gref(27679): *try_take_global obj=0x4976f080 -> wref=0xde68f95f handle=0x4066df10
I/monodroid-gref(27679): +g+ grefc 1930 gwrefc 39 obj-handle 0xde68f95f/W -> new-handle 0x4066df10/G from take_global_ref_jni
I/monodroid-gref(27679): -w- grefc 1930 gwrefc 38 handle 0xde68f95f/W from take_global_ref_jni

# Object is dead, as handle == null
# wref is freed, no new gref created
I/monodroid-gref(27679): *try_take_global obj=0x4976f080 -> wref=0xde68f95f handle=0x0
I/monodroid-gref(27679): -w- grefc 1914 gwrefc 296 handle 0xde68f95f/W from take_global_ref_jni

You can see my other answer on the Xamarin.Android Garbage Collection Algorithm to see exactly when these handles get changed.

So now that you have an idea of what patterns you can see during various scenarios, it will help you figure out what is going on at the time of your invalid jobject.

Now is the fun part, but also can be the hardest part:

You need to now replicate the crash while this logging is enabled.

Once you have done that, you need to take the new error message you received and the handle given to you. In your original post it refers to:

JNI DETECTED ERROR IN APPLICATION: use of invalid jobject 0xd4fd90e0

However it's possible that this handle will change throughout different replications of the issue. However once you have that handle, you can use a tool like grep to search for the handle string:

0xd4fd90e0

Once you've done this, you can take a look at what state this handle is in via the sample snippet above and make a fix in the respective area. (Premature GC, Object manually being disposed, etc)

Reference: https://developer.xamarin.com/guides/android/troubleshooting/troubleshooting/#Global_Reference_Messages