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

Question

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

EDIT:

With gref enabled log (no crash): https://gist.github.com/sanandrea/b9a837b8c885ac037c4f4bc6e8030d10

Without gref enabled (crash): https://gist.github.com/sanandrea/d2c5c895b4bc15f45381421c9c21b859

EDIT 2 This can be tagged as #HeisenBug

Solution 1

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

Solution 2

$ 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.

I had Exactly the same!!!

In Android properties,

Turning off Shared Runtime helped me.

Solution 3

I just got this issue and the problem was not an object management issue.

The issue was a C calling back into a java method with the wrong number of arguments.

If the C code doesn't provide enough arguments the java code will have garbage in the objects passed in and using them will create the "JNI DETECTED ERROR IN APPLICATION: use of invalid jobject" error, but the value shown is not related to any object that has been created before.

If this error arise from a C/C++ call into java, make sure all the arguments are provided as the compilers will not check the type or number of arguments.

Comments

[Sanandrea]

Thank you for your thorough answer. It is a clearer to me know how to debug, the only problem I have, is that I cannot replicate the crash :(. Any idea why it might happen when logging is enabled?

[Jon Douglas]

gref logging makes it a little slower to "debug" your application, but it should overall behave the same exact way as if it didn't have that logging enabled. Merely just time to write the log messages AFAIK.

[Sanandrea]

Yep, but if it is a matter of disposing an object because of limit of refs it should not depend on the speed of debugging, or no? :)

[Jon Douglas]

If you have a test case where it fails reliably without gref logging, and then it doesn't with gref logging. Please attach it to your post.

[Jon Douglas]

Logs won't be enough to help out. A test case would be needed at this point.

[Almo]

Where is this "android properties" you speak of.

[Pierre]

@Almo This is Xamarin for VS. So right-click on the Android Project in Solution Explorer and select Properties.

[Almo]

Ok, so I'm not using Xamarin, which is why I couldn't find it. :D