BLE Connect fail with Android-nRF-Toolbox

[Steven Chen]

Dear Mr/Mrs,

I am learning to develop an Android BLE apk. I use the nRF Connect apk and Android-nRF-Toolbox to connect with my BLE device.

nRF Connect connect to the BLE device successfully while nRF Toolbox failed.

The mobile phone I used is Nova4 with Android OS 10.0.

the failed log is as following,

2020-11-30 14:55:35.611 5443-5443/no.nordicsemi.android.nrftoolbox I/HwViewRootImpl: removeInvalidNode all the node in jank list is out of time
2020-11-30 14:55:35.628 1320-8397/? W/ActivityManager: Receiver with filter android.content.IntentFilter@c1728bd already registered for pid 5443, callerPackage is no.nordicsemi.android.nrftoolbox
2020-11-30 14:55:35.628 5443-5443/no.nordicsemi.android.nrftoolbox I/BluetoothDevice: connectGatt
2020-11-30 14:55:43.485 5443-5479/no.nordicsemi.android.nrftoolbox W/BluetoothGatt: Unhandled exception in callback
java.lang.NullPointerException: Attempt to invoke virtual method 'void no.nordicsemi.android.nrftoolbox.ble.f.a(java.lang.String, int)' on a null object reference
at no.nordicsemi.android.nrftoolbox.ble.d$d.onConnectionStateChange(:730)
at android.bluetooth.BluetoothGatt$1$4.run(BluetoothGatt.java:279)
at android.bluetooth.BluetoothGatt.runOrQueueCallback(BluetoothGatt.java:793)
at android.bluetooth.BluetoothGatt.access$200(BluetoothGatt.java:41)
at android.bluetooth.BluetoothGatt$1.onClientConnectionState(BluetoothGatt.java:274)
at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:192)
at android.os.Binder.execTransactInternal(Binder.java:1028)
at android.os.Binder.execTransact(Binder.java:1001)

I find that the nRF Connect does not call connectGatt method. 

===== nRF Connect log ====

11-20 15:58:08.717 21503 21606 I bt_stack: [INFO:gatt_api.cc(961)] GATT_Register 0bb4b748-220d-7da0-ff81-8ca6d4fb1ff3
11-20 15:58:08.717 21503 21606 I bt_stack: [INFO:gatt_api.cc(981)] allocated gatt_if=8
11-20 15:58:08.739 3105 3696 D BtStatePassiveManager: btPassive save result is true
11-20 15:58:21.053 3189 3344 D BluetoothState: stop bt uid:10254 state:BLE_SCAN total(ms):22300
11-20 15:58:21.174 634 634 I GRALLOC : getCallingPid=700, shrFd=12,fmt=0x1,intFmt=0x200000001,btStrd=4352,size=10256384,pid=634
11-20 15:58:21.188 634 634 I GRALLOC : getCallingPid=700, shrFd=12,fmt=0x1,intFmt=0x200000001,btStrd=4352,size=10256384,pid=634
11-20 15:58:21.194 634 634 I GRALLOC : getCallingPid=700, shrFd=12,fmt=0x1,intFmt=0x1,btStrd=2560,size=360448,pid=634
11-20 15:58:21.195 634 634 I GRALLOC : getCallingPid=700, shrFd=12,fmt=0x1,intFmt=0x1,btStrd=2560,size=360448,pid=634
11-20 15:58:21.196 634 634 I GRALLOC : getCallingPid=700, shrFd=12,fmt=0x1,intFmt=0x1,btStrd=2560,size=360448,pid=634
11-20 15:58:21.231 21503 21606 I bt_stack: [INFO:gatt_api.cc(961)] GATT_Register 56ab6932-7b1d-6557-21fe-5f602a6d5dbd
11-20 15:58:21.232 21503 21606 I bt_stack: [INFO:gatt_api.cc(981)] allocated gatt_if=8
11-20 15:58:21.241 21503 21606 I bt_stack: [INFO:gatt_api.cc(1119)] GATT_Connectgatt_if=8, address=ef:90:78:**:**:**
11-20 15:58:21.601 21503 21606 I bt_stack: [INFO:gatt_sr.cc(753)] MTU request PDU with MTU size 200
11-20 15:58:21.604 21503 21606 W bt_stack: [WARNING:gatt_utils.cc(745)] Call back not found for application conn_id=3
11-20 15:58:21.605 21503 21606 W bt_stack: [WARNING:gatt_utils.cc(745)] Call back not found for application conn_id=4
11-20 15:58:21.605 21503 21606 W bt_stack: [WARNING:gatt_utils.cc(745)] Call back not found for application conn_id=6
11-20 15:58:21.605 21503 21606 W bt_stack: [WARNING:gatt_utils.cc(745)] Call back not found for application conn_id=7
11-20 15:58:21.605 21503 21606 W bt_stack: [WARNING:gatt_utils.cc(745)] Call back not found for application conn_id=8
11-20 15:58:21.605 21503 21606 E bt_stack: [ERROR:bta_gattc_cache.cc(723)] bta_gattc_cache_load: can't open GATT cache file /data/misc/bluetooth/gatt_cache_ef9078563412 for reading, error: No such file or directory
11-20 15:58:21.606 21503 21606 I bt_stack: [INFO:hearing_aid.cc(1774)] GetDeviceCount: Not initialized yet
11-20 15:58:21.606 21503 21606 I bt_stack: [INFO:gatt_api.cc(647)] GATTC_Discover conn_id=0x0008, disc_type=1, s_handle=0x0001, e_handle=0xffff
11-20 15:58:21.637 3105 3696 D Nc_Chr_BT: NcBtDftManager: bt ACL state old:2, new:1, date:2020-11-20 15:58:21
11-20 15:58:21.686 21503 21606 I bt_stack: [INFO:hearing_aid.cc(1774)] GetDeviceCount: Not initialized yet
11-20 15:58:23.208 634 634 I GRALLOC : getCallingPid=700, shrFd=12,fmt=0x1,intFmt=0x1,btStrd=2304,size=323584,pid=634
11-20 15:58:23.211 634 634 I GRALLOC : getCallingPid=700, shrFd=12,fmt=0x1,intFmt=0x1,btStrd=2304,size=323584,pid=634
11-20 15:58:23.217 634 14674 I GRALLOC : getCallingPid=700, shrFd=12,fmt=0x1,intFmt=0x1,btStrd=2304,size=323584,pid=634
11-20 15:58:26.606 21503 21606 W bt_stack: [WARNING:gatt_utils.cc(595)] gatt_rsp_timeout retry discovery primary service
11-20 15:58:26.970 21503 21606 I bt_stack: [INFO:btsnoop.cc(464)] clear_l2cap_whitelist: Clearing whitelist from l2cap channel. conn_handle=0 cid=4:4
11-20 15:58:26.971 21503 21606 W bt_stack: [WARNING:l2c_ble.cc(177)] L2CA_EnableUpdateBleConnParams - unknown BD_ADDR ef:90:78:**:**:**
11-20 15:58:26.971 21503 21606 W bt_stack: [WARNING:bta_gattc_act.cc(1044)] bta_gattc_conn_cback: cif=3 connected=0 conn_id=0x0003 reason=0x0008
11-20 15:58:26.971 21503 21606 W bt_stack: [WARNING:bta_gattc_act.cc(1044)] bta_gattc_conn_cback: cif=4 connected=0 conn_id=0x0004 reason=0x0008
11-20 15:58:26.971 21503 21606 W bt_stack: [WARNING:bta_gattc_act.cc(1044)] bta_gattc_conn_cback: cif=6 connected=0 conn_id=0x0006 reason=0x0008
11-20 15:58:26.971 21503 21606 W bt_stack: [WARNING:bta_gattc_act.cc(1044)] bta_gattc_conn_cback: cif=7 connected=0 conn_id=0x0007 reason=0x0008
11-20 15:58:26.971 21503 21606 W bt_stack: [WARNING:bta_gattc_act.cc(1044)] bta_gattc_conn_cback: cif=8 connected=0 conn_id=0x0008 reason=0x0008
11-20 15:58:26.999 21503 21606 E bt_stack: [ERROR:bta_gattc_act.cc(293)] No such connection need to be cancelled
11-20 15:58:27.000 21503 21606 E bt_stack: [ERROR:bta_gattc_utils.cc(433)] bta_gattc_mark_bg_conn unable to find the bg connection mask for bd_addr=ef:90:78:**:**:**
11-20 15:58:27.059 3105 3696 D Nc_Chr_BT: NcBtDftManager: bt ACL state old:1, new:2, date:2020-11-20 15:58:27
11-20 15:58:27.070 3105 3696 E Nc_Chr_BT: NcBtDftManager: bt SCO state not changed, state:2
11-20 15:58:27.114 634 14674 I GRALLOC : getCallingPid=700, shrFd=12,fmt=0x1,intFmt=0x1,btStrd=2304,size=323584,pid=634
11-20 15:58:27.115 634 634 I GRALLOC : getCallingPid=700, shrFd=12,fmt=0x1,intFmt=0x1,btStrd=2304,size=323584,pid=634
11-20 15:58:27.116 634 634 I GRALLOC : getCallingPid=700, shrFd=12,fmt=0x1,intFmt=0x1,btStrd=2304,size=323584,pid=634

11-20 15:58:38.232 21503 21606 I bt_stack: [INFO:gatt_api.cc(961)] GATT_Register 21efe26e-716f-8b15-2af6-69d4374e8fac
11-20 15:58:38.232 21503 21606 I bt_stack: [INFO:gatt_api.cc(981)] allocated gatt_if=8
11-20 15:58:38.239 21503 21606 I bt_stack: [INFO:gatt_api.cc(1119)] GATT_Connectgatt_if=8, address=ef:90:78:**:**:**
11-20 15:58:38.707 21503 21606 I bt_stack: [INFO:gatt_sr.cc(753)] MTU request PDU with MTU size 200
11-20 15:58:38.707 21503 21606 W bt_stack: [WARNING:gatt_utils.cc(745)] Call back not found for application conn_id=3
11-20 15:58:38.707 21503 21606 W bt_stack: [WARNING:gatt_utils.cc(745)] Call back not found for application conn_id=4
11-20 15:58:38.707 21503 21606 W bt_stack: [WARNING:gatt_utils.cc(745)] Call back not found for application conn_id=6
11-20 15:58:38.707 21503 21606 W bt_stack: [WARNING:gatt_utils.cc(745)] Call back not found for application conn_id=7
11-20 15:58:38.707 21503 21606 W bt_stack: [WARNING:gatt_utils.cc(745)] Call back not found for application conn_id=8
11-20 15:58:38.708 21503 21606 E bt_stack: [ERROR:bta_gattc_cache.cc(723)] bta_gattc_cache_load: can't open GATT cache file /data/misc/bluetooth/gatt_cache_ef9078563412 for reading, error: No such file or directory
11-20 15:58:38.708 21503 21606 I bt_stack: [INFO:hearing_aid.cc(1774)] GetDeviceCount: Not initialized yet
11-20 15:58:38.708 21503 21606 I bt_stack: [INFO:gatt_api.cc(647)] GATTC_Discover conn_id=0x0008, disc_type=1, s_handle=0x0001, e_handle=0xffff
11-20 15:58:38.727 3105 3696 D Nc_Chr_BT: NcBtDftManager: bt ACL state old:2, new:1, date:2020-11-20 15:58:38
11-20 15:58:38.771 21503 21606 I bt_stack: [INFO:hearing_aid.cc(1774)] GetDeviceCount: Not initialized yet
11-20 15:58:38.863 634 634 I GRALLOC : getCallingPid=700, shrFd=12,fmt=0x1,intFmt=0x1,btStrd=2304,size=323584,pid=634
11-20 15:58:38.866 634 634 I GRALLOC : getCallingPid=700, shrFd=12,fmt=0x1,intFmt=0x1,btStrd=2304,size=323584,pid=634
11-20 15:58:39.456 21503 21606 I bt_stack: [INFO:gatt_api.cc(647)] GATTC_Discover conn_id=0x0008, disc_type=3, s_handle=0x0001, e_handle=0x000b
11-20 15:58:39.806 21503 21606 I bt_stack: [INFO:gatt_api.cc(647)] GATTC_Discover conn_id=0x0008, disc_type=4, s_handle=0x0001, e_handle=0x000b
11-20 15:58:40.507 21503 21606 I bt_stack: [INFO:gatt_api.cc(647)] GATTC_Discover conn_id=0x0008, disc_type=3, s_handle=0x000c, e_handle=0x000f
11-20 15:58:40.656 21503 21606 I bt_stack: [INFO:gatt_api.cc(647)] GATTC_Discover conn_id=0x0008, disc_type=4, s_handle=0x000c, e_handle=0x000f
11-20 15:58:41.756 21503 21606 I bt_stack: [INFO:gatt_api.cc(647)] GATTC_Discover conn_id=0x0008, disc_type=5, s_handle=0x000f, e_handle=0x000f
11-20 15:58:41.856 21503 21606 I bt_stack: [INFO:gatt_api.cc(647)] GATTC_Discover conn_id=0x0008, disc_type=3, s_handle=0x0010, e_handle=0x0013
11-20 15:58:42.456 21503 21606 I bt_stack: [INFO:gatt_api.cc(647)] GATTC_Discover conn_id=0x0008, disc_type=4, s_handle=0x0010, e_handle=0x0013
11-20 15:58:42.956 21503 21606 I bt_stack: [INFO:gatt_api.cc(647)] GATTC_Discover conn_id=0x0008, disc_type=5, s_handle=0x0013, e_handle=0x0013
11-20 15:58:43.206 21503 21606 I bt_stack: [INFO:gatt_api.cc(647)] GATTC_Discover conn_id=0x0008, disc_type=3, s_handle=0x0014, e_handle=0xffff
11-20 15:58:43.607 21503 21606 I bt_stack: [INFO:gatt_api.cc(647)] GATTC_Discover conn_id=0x0008, disc_type=4, s_handle=0x0014, e_handle=0xffff
11-20 15:58:44.257 21503 21606 I bt_stack: [INFO:gatt_api.cc(647)] GATTC_Discover conn_id=0x0008, disc_type=5, s_handle=0x0019, e_handle=0xffff
11-20 15:58:44.758 21503 21606 I bt_stack: [INFO:bta_gattc_cache.cc(178)] bta_gattc_explore_srvc_finished: service discovery finished
11-20 15:58:44.773 21503 21606 I bt_stack: [INFO:hearing_aid.cc(1774)] GetDeviceCount: Not initialized yet

Could you please help me to analysis it? Thanks a lot!

[Steven Chen]

upload full log of nRF Connect and nRF Toolbox.

nrfconnect.txt

nrftoolbox.txt

[Karl Ylvisaker]

Hello,

I am learning to develop an Android BLE apk.

Welcome!
By this you mean that you are working with our Android BLE Library, correct?

2020-11-30 14:55:35.628 5443-5443/no.nordicsemi.android.nrftoolbox I/BluetoothDevice: connectGatt
2020-11-30 14:55:43.485 5443-5479/no.nordicsemi.android.nrftoolbox W/BluetoothGatt: Unhandled exception in callback
java.lang.NullPointerException: Attempt to invoke virtual method 'void no.nordicsemi.android.nrftoolbox.ble.f.a(java.lang.String, int)' on a null object reference

It seems to me that the code might proceed with the connection after the unhandled exception in the callback. - such as calling a connection method on a NULL connection object.
Could you share the part of your code where it fails - where you initiate a connection?

What is the device you are trying to connect with, by the way?

Looking forward to resolving this issue together!

Best regards,
Karl

[Steven Chen]

Dear Karl,

Thanks for your answer. I use the code downloaded from https://github.com/NordicSemiconductor/Android-nRF-Toolbox. And I didn't do any modification. I connect the device(40:45:da:**:**:**) from the scan activity by click the bluetooth icon.

The device is a BLE module.

Android-nRF-Toolbox-master.rar

BR,

Steven

[Karl Ylvisaker]

Hello Steven,

Steven Chen said:

Thanks for your answer. I use the code downloaded from https://github.com/NordicSemiconductor/Android-nRF-Toolbox. And I didn't do any modification. I connect the device(40:45:da:**:**:**) from the scan activity by click the bluetooth icon.

Which tagged release of the repository are you using?
The .rar file you have included indicate that you might be using the master branch - I highly recommend that you only stick to using tagged releases, instead of the master branch, since the master branch is constantly being worked on, and certain things may thus not work as intended.
In the case that you were using the master branch in the test for your original ticket, could you perform the same test again with a tagged release instead ( such as the 2.9 release ) and see if the issue persists?

Steven Chen said:

The device is a BLE module.

Could you elaborate, which BLE module is it exactly?

Looking forward to resolving this issue together!

Best regards,
Karl

[Steven Chen]

Dear Karl,

I will test the tagged version 2.9.0. The module is developed based on UNISOC UIS8910DM chip, which including BT inside.