androidbluetoothcrashjava-native-interfacehfp

When hfpclient is enabled in android's config.xml and then when trying to pair a device I am seeing a crash in the hfpclient's JNI interface


--- a/res/values/config.xml
+++ b/res/values/config.xml
@@ -17,7 +17,7 @@
     <bool name="profile_supported_a2dp_sink">false</bool>
     <bool name="profile_supported_hdp">true</bool>
     <bool name="profile_supported_hs_hfp">true</bool>
-    <bool name="profile_supported_hfpclient">false</bool>
+    <bool name="profile_supported_hfpclient">true</bool>

08-29 14:16:35.703 4697 4697 I crash_dump64: obtaining output fd from tombstoned, type: kDebuggerdTombstone

08-29 14:16:35.704 3147 3147 I /system/bin/tombstoned: received crash request for pid 3559 08-29 14:16:35.704 4697 4697 I crash_dump64: performing dump of process 3450 (target tid = 3559) 08-29 14:16:35.711 3636 3636 D StrictMode: StrictMode policy violation: android.os.strictmode.InstanceCountViolation: class com.android.settings.SubSettings; instances=2; limit=1 08-29 14:16:35.711 3636 3636 D StrictMode: at android.os.StrictMode.setClassInstanceLimit(StrictMode.java:1)

08-29 14:16:35.722 4697 4697 F DEBUG :


08-29 14:16:35.722 4697 4697 F DEBUG : Build fingerprint: 'Android/proline_basic_proto3/proline_basic_proto3:9/2.0.0-ga-rc4/root08230119:eng/dev-keys' 08-29 14:16:35.722 4697 4697 F DEBUG : Revision: '0' 08-29 14:16:35.722 4697 4697 F DEBUG : ABI: 'arm64' 08-29 14:16:35.722 4697 4697 F DEBUG : pid: 3450, tid: 3559, name: BT Service Call >>> com.android.bluetooth <<< 08-29 14:16:35.723 4697 4697 F DEBUG : signal 6 (SIGABRT), code -6 (SI_TKILL), fault addr --------

08-29 14:16:35.723 4697 4697 F DEBUG : Abort message: 'java_vm_ext.cc:542] JNI DETECTED ERROR IN APPLICATION: can't call void com.android.bluetooth.hfpclient.NativeInterface.onConnectionStateChanged(int, int, int, byte[]) on instance of java.lang.Class'

08-29 14:16:35.723 4697 4697 F DEBUG : x0 0000000000000000 x1 0000000000000de7 x2 0000000000000006 x3 0000000000000008

08-29 14:16:35.723 4697 4697 F DEBUG : x4 fefff69db9b60667 x5 fefff69db9b60667 x6 fefff69db9b60667 x7 7f7fffffffff7f7f

08-29 14:16:35.723 4697 4697 F DEBUG : x8 0000000000000083 x9 0000f79eba2b7a68 x10 fffffff87ffffbdf x11 0000000000000001

08-29 14:16:35.723 4697 4697 F DEBUG : x12 0000f79ea06813[ 172.909846] alloc_contig_range: [a7f00, a8285) PFNs busy 38 x13 ffffffffffffffff x14 ffffffffff000000 x15 ffffffffffffffff

08-29 14:16:35.723 4697 4697 F DEBUG : x16 0000f79eba2f02c8 x17 0000f79eba22e2d8 [ 172.929388] alloc_contig_range: [a7f00, a8285) PFNs busy x18 0000f79ea0680b0a x19 0000000000000d7a

08-29 14:16:35.723 4697 4697 F DEBUG : x20 0000000000000de7 x21 0000000000000083 x22 0000f79eb32fd400 x23 0000f79e9e23c000

08-29 14:16:35.723 4697 4697 F DEBUG : x24 0000000000000000 x25 0000000000000012 x26 0000000000000005 x27 0000f79eb9906c13

08-29 14:16:35.723 4697 4697 F DEBUG : x28 0000f79eb9906ac7 x29 0000f79ea0681890

08-29 14:16:35.723 4697 4697 F DEBUG : sp 0000f79ea0681850 lr 0000f79eba222a90 pc 0000f79eba222abc

08-29 14:16:35.765 4697 4697 F DEBUG :

08-29 14:16:35.765 4697 4697 F DEBUG : backtrace:

08-29 14:16:35.765 4697 4697 F DEBUG : #00 pc 0000000000021abc /system/lib64/libc.so (abort+124)

08-29 14:16:35.765 4697 4697 F DEBUG : #01 pc 000000000046adb0 /system/lib64/libart.so (art::Runtime::Abort(char const*)+1208)

08-29 14:16:35.765 4697 4697 F DEBUG : #02 pc 0000000000008d2c /system/lib64/libbase.so (android::base::LogMessage::~LogMessage()+724)

08-29 14:16:35.765 4697 4697 F DEBUG : #03 pc 00000000002e8908 /system/lib64/libart.so (art::JavaVMExt::JniAbort(char const*, char const*)+1656)

08-29 14:16:35.765 4697 4697 F DEBUG : #04 pc 00000000002e8a7c /system/lib64/libart.so (art::JavaVMExt::JniAbortV(char const*, char const*, std::__va_list)+108)

08-29 14:16:35.765 4697 4697 F DEBUG : #05 pc 00000000000fd5f8 /system/lib64/libart.so (art::(anonymous namespace)::ScopedCheck::AbortF(char const*, ...)+144)

08-29 14:16:35.765 4697 4697 F DEBUG : #06 pc 00000000001015a8 /system/lib64/libart.so (art::(anonymous namespace)::ScopedCheck::CheckMethodAndSig(art::ScopedObjectAccess&, _jobject*, _jclass*, _jmethodID*, art::Primitive::Type, art::InvokeType)+1920)

08-29 14:16:35.765 4697 4697 F DEBUG : #07 pc 00000000000ffcb4 /system/lib64/libart.so (art::(anonymous namespace)::CheckJNI::CallMethodV(char const*, _JNIEnv*, _jobject*, _jclass*, _jmethodID*, std::__va_list, art::Primitive::Type, art::InvokeType)+756)

08-29 14:16:35.765 4697 4697 F DEBUG : #08 pc 00000000000ed5d4 /system/lib64/libart.so (art::(anonymous namespace)::CheckJNI::CallVoidMethodV(_JNIEnv*, _jobject*, _jmethodID*, std::__va_list)+84)

08-29 14:16:35.765 4697 4697 F DEBUG : #09 pc 0000000000017ec0 /system/lib64/libbluetooth_jni.so (_JNIEnv::CallVoidMethod(_jobject*, _jmethodID*, ...)+120)

08-29 14:16:35.765 4697 4697 F DEBUG : #10 pc 000000000001d71c /system/lib64/libbluetooth_jni.so (android::connection_state_cb(RawAddress const*, bthf_client_connection_state_t, unsigned int, unsigned int)+268)

08-29 14:16:35.765 4697 4697 F DEBUG : #11 pc 000000000012b8d8 /system/lib64/libbluetooth.so (btif_hf_client_upstreams_evt(unsigned short, char*)+3488)

08-29 14:16:35.765 4697 4697 F DEBUG : #12 pc 0000000000116124 /system/lib64/libbluetooth.so (bt_jni_msg_ready(void*)+116)

08-29 14:16:35.765 4697 4697 F DEBUG : #13 pc 0000000000096aec /system/lib64/libchrome.so (base::debug::TaskAnnotator::RunTask(char const*, base::PendingTask*)+244)

08-29 14:16:35.766 4697 4697 F DEBUG : #14 pc 00000000000b0388 /system/lib64/libchrome.so (base::MessageLoop::RunTask(base::PendingTask*)+416)

08-29 14:16:35.766 4697 4697 F DEBUG : #15 pc 00000000000b0634 /system/lib64/libchrome.so (base::MessageLoop::DeferOrRunPendingTask(base::PendingTask)+52)

08-29 14:16:35.766 4697 4697 F DEBUG : #16 pc 00000000000b0a7c /system/lib64/libchrome.so (base::MessageLoop::DoWork()+380)

08-29 14:16:35.766 4697 4697 F DEBUG : #17 pc 00000000000b1e44 /system/lib64/libchrome.so (base::MessagePumpDefault::Run(base::MessagePump::Delegate*)+180)

08-29 14:16:35.766 4697 4697 F DEBUG : #18 pc 00000000000b0070 /system/lib64/libchrome.so (base::MessageLoop::RunHandler()+112)

08-29 14:16:35.766 4697 4697 F DEBUG : #19 pc 00000000000cd200 /system/lib64/libchrome.so (base::RunLoop::Run()+136)

08-29 14:16:35.766 4697 4697 F DEBUG : #20 pc 0000000000114334 /system/lib64/libbluetooth.so (run_message_loop(void*)+284)

08-29 14:16:35.766 4697 4697 F DEBUG : #21 pc 0000000000232874 /system/lib64/libbluetooth.so (work_queue_read_cb(void*)+92)

08-29 14:16:35.766 4697 4697 F DEBUG : #22 pc 0000000000230a90 /system/lib64/libbluetooth.so (run_reactor(reactor_t*, int)+320)

08-29 14:16:35.766 4697 4697 F DEBUG : #23 pc 0000000000230924 /system/lib64/libbluetooth.so (reactor_start(reactor_t*)+84)

08-29 14:16:35.766 4697 4697 F DEBUG : #24 pc 00000000002322f8 /system/lib64/libbluetooth.so (run_thread(void*)+184)

08-29 14:16:35.766 4697 4697 F DEBUG : #25 pc 0000000000083194 /system/lib64/libc.so (__pthread_start(void*)+36)

08-29 14:16:35.766 4697 4697 F DEBUG : #26 pc 00000000000233bc /system/lib64/libc.so (__start_thread+68)

08-29 14:16:35.776 4697 4697 I crash_dump64: type=1400 audit(0.0:53): avc: denied { read } for name="btopp.db-shm" dev="mmcblk2p12" ino=758 scontext=u:r:crash_dump:s0

Once the flag to start the service for hfpclient is enabled in Bluetooth Apk of Android and then when the image with the flag enabled in loaded onto the device and when pairing is initiated with the device, I am seeing a crash in the JNI interface.

The main reason I could see from the crash logs is this: JNI DETECTED ERROR IN APPLICATION: can't call void com.android.bluetooth.hfpclient.NativeInterface.onConnectionStateChanged(int, int, int, byte[]) on instance of java.lang.Class'

@@ -350,6 +368,14 @@ static bthf_client_callbacks_t sBluetoothHfpClientCallbacks = {
 static void classInitNative(JNIEnv* env, jclass clazz) {
   method_onConnectionStateChanged =
       env->GetMethodID(clazz, "onConnectionStateChanged", "(III[B)V");
+  if(method_onConnectionStateChanged == 0)
+  {
+         ALOGE("%s : FAILED TO INIT OBJ",__func__);
+  }
+  else
+  {
+         ALOGE("%s : INIT OBJ",__func__);
+  }

I am able to verify from the above code that the MethodID is assigned to the variable.

@@ -68,13 +72,27 @@ static void connection_state_cb(const RawAddress* bd_addr,
                                 bthf_client_connection_state_t state,
                                 unsigned int peer_feat,
                                 unsigned int chld_feat) {
+  std::shared_lock<std::shared_timed_mutex> lock(callbacks_mutex);
   CallbackEnv sCallbackEnv(__func__);
-  if (!sCallbackEnv.valid()) return;
+  if (!sCallbackEnv.valid() || !mCallbacksObj)
+  {
+         ALOGE("****ERRORR****");
+         return;
+  }

   ScopedLocalRef<jbyteArray> addr(sCallbackEnv.get(), marshall_bda(bd_addr));
+
   if (!addr.get()) return;

   ALOGD("%s: state %d peer_feat %d chld_feat %d", __func__, state, peer_feat, chld_feat);
+  if(method_onConnectionStateChanged == 0)
+{
+        ALOGE("%s : FAILED TO INIT OBJ",__func__);
+}
+else
+{
+        ALOGE("%s : INIT OBJ",__func__);
+}
   sCallbackEnv->CallVoidMethod(mCallbacksObj, method_onConnectionStateChanged,
                                (jint)state, (jint)peer_feat, (jint)chld_feat,
                                addr.get());

Also, I have verified the same in the place where the CallVoidMethod() is called and even there I could see that the method_onConnectionStateChanged has not lost its scope.

So, I am not sure what is causing this error: JNI DETECTED ERROR IN APPLICATION: can't call void com.android.bluetooth.hfpclient.NativeInterface.onConnectionStateChanged(int, int, int, byte[]) on instance of java.lang.Class


Solution

  • I got the same issue and found that is was actually fixed in android: see https://android.googlesource.com/platform/packages/apps/Bluetooth/+/c8e910d0393d2d7f3bf46d90746819d024ec7510

    Also note that if JNI checks are not enabled (eg: build in user mode) the issue will not occur.