Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Bluetooth disconnects when calling writeCharacteristic on Android 13 #420

Closed
sara-race-neato opened this issue Sep 19, 2022 · 15 comments
Closed

Comments

@sara-race-neato
Copy link

sara-race-neato commented Sep 19, 2022

When I call BleManager.writeCharacteristic where the data has 543 bytes in the array, the call succeeds on Android 12. However, on Android 13 the bluetooth disconnects with the following logs:

2022-09-15 12:59:30.850 V/Android-BLE-Library: Writing characteristic <custom characteristic UUID> (WRITE REQUEST)
2022-09-15 12:59:30.850 D/Android-BLE-Library: gatt.writeCharacteristic(<custom characteristic UUID>)
2022-09-15 12:59:31.685 D/BluetoothAdapter: onBluetoothServiceDown
2022-09-15 12:59:31.692 D/BluetoothAdapter: onBluetoothServiceDown
2022-09-15 12:59:31.695 D/Android-BLE-Library: [Broadcast] Action received: android.bluetooth.adapter.action.STATE_CHANGED, state changed to TURNING OFF
2022-09-15 12:59:31.696 I/Android-BLE-Library: Disconnected
2022-09-15 12:59:31.712 D/Android-BLE-Library: gatt.close()
2022-09-15 12:59:31.712 D/BluetoothGatt: close()
2022-09-15 12:59:31.712 D/BluetoothGatt: unregisterApp() - mClientIf=6
2022-09-15 12:59:31.714 E/BluetoothGatt: android.os.DeadObjectException
        at android.os.BinderProxy.transactNative(Native Method)
        at android.os.BinderProxy.transact(BinderProxy.java:584)
        at android.bluetooth.IBluetoothGatt$Stub$Proxy.unregisterClient(IBluetoothGatt.java:1506)
        at android.bluetooth.BluetoothGatt.unregisterApp(BluetoothGatt.java:941)
        at android.bluetooth.BluetoothGatt.close(BluetoothGatt.java:799)
        at no.nordicsemi.android.ble.BleManagerHandler.close(BleManagerHandler.java:472)
        at no.nordicsemi.android.ble.BleManagerHandler.notifyDeviceDisconnected(BleManagerHandler.java:1633)
        at no.nordicsemi.android.ble.BleManagerHandler.access$900(BleManagerHandler.java:59)
        at no.nordicsemi.android.ble.BleManagerHandler$1.onReceive(BleManagerHandler.java:279)
        at android.app.LoadedApk$ReceiverDispatcher$Args.lambda$getRunnable$0$android-app-LoadedApk$ReceiverDispatcher$Args(LoadedApk.java:1790)
        at android.app.LoadedApk$ReceiverDispatcher$Args$$ExternalSyntheticLambda0.run(Unknown Source:2)
        at android.os.Handler.handleCallback(Handler.java:942)
        at android.os.Handler.dispatchMessage(Handler.java:99)
        at android.os.Looper.loopOnce(Looper.java:201)
        at android.os.Looper.loop(Looper.java:288)
        at android.app.ActivityThread.main(ActivityThread.java:7898)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:936)
2022-09-15 12:59:31.714 D/BleManagerGattCallback: onServicesInvalidated
2022-09-15 12:59:31.714 D/BleManagerGattCallback: onDeviceDisconnected
2022-09-15 12:59:31.995 D/BluetoothAdapter: onBluetoothServiceUp: android.bluetooth.IBluetooth$Stub$Proxy@868fc9d

There are a few earlier calls to writeCharacteristic with 1-2 bytes that succeed, it's only the call with the larger amount of data that fails due to the bluetooth disconnecting.

For reference, I'm targeting API 32 and using the following library versions:

implementation 'no.nordicsemi.android.support.v18:scanner:1.6.0'
implementation "no.nordicsemi.android:ble:2.5.1"
implementation "no.nordicsemi.android:ble-livedata:2.5.1"

Has anyone else run into this issue on Android 13?

@sara-race-neato
Copy link
Author

I found a native stack trace in the logs:

2022-09-19 16:30:48.587 2365-2365/? A/DEBUG: *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG: Build fingerprint: 'google/bluejay/bluejay:13/TP1A.220905.004.A2/9014697:user/release-keys'
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG: Revision: 'MP1.0'
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG: ABI: 'arm64'
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG: Timestamp: 2022-09-19 16:30:48.101110605-0700
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG: Process uptime: 0s
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG: Cmdline: com.android.bluetooth
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG: pid: 1584, tid: 1648, name: bt_main_thread  >>> com.android.bluetooth <<<
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG: uid: 1002
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG: tagged_addr_ctrl: 0000000000000001 (PR_TAGGED_ADDR_ENABLE)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG: signal 6 (SIGABRT), code -1 (SI_QUEUE), fault addr --------
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG: Abort message: 'FORTIFY: memcpy: prevented 546-byte write into 513-byte buffer'
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:     x0  0000000000000000  x1  0000000000000670  x2  0000000000000006  x3  00000077aad790a0
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:     x4  0000000000008080  x5  0000000000008080  x6  0000000000008080  x7  8080808080808080
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:     x8  00000000000000f0  x9  0000007ae05b19e0  x10 0000000000000001  x11 0000007ae05f25e0
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:     x12 0101010101010101  x13 000000007fffffff  x14 0000000000a435d4  x15 0000000000000038
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:     x16 0000007ae065fd58  x17 0000007ae063b120  x18 0000007796b9c058  x19 0000000000000630
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:     x20 0000000000000670  x21 00000000ffffffff  x22 00000077aad7a000  x23 00000077aad792c8
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:     x24 00000077aad7a000  x25 00000077aad79cb0  x26 00000077aad79ff8  x27 00000000000fc000
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:     x28 00000000000fe000  x29 00000077aad79120
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:     lr  0000007ae05e30c8  sp  00000077aad79080  pc  0000007ae05e30f4  pst 0000000000001000
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG: backtrace:
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #00 pc 00000000000530f4  /apex/com.android.runtime/lib64/bionic/libc.so (abort+164) (BuildId: cbc4c62a9b269839456f1d7728d8411e)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #01 pc 0000000000054f7c  /apex/com.android.runtime/lib64/bionic/libc.so (__fortify_fatal(char const*, ...)+124) (BuildId: cbc4c62a9b269839456f1d7728d8411e)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #02 pc 0000000000080128  /apex/com.android.runtime/lib64/bionic/libc.so (__check_buffer_access(char const*, char const*, unsigned long, unsigned long)+40) (BuildId: cbc4c62a9b269839456f1d7728d8411e)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #03 pc 00000000000802d4  /apex/com.android.runtime/lib64/bionic/libc.so (__memcpy_chk_fail+68) (BuildId: cbc4c62a9b269839456f1d7728d8411e)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #04 pc 0000000000081280  /apex/com.android.runtime/lib64/bionic/libc.so (__memcpy_chk+16) (BuildId: cbc4c62a9b269839456f1d7728d8411e)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #05 pc 00000000003dfbe4  /apex/com.android.btservices/lib64/libbluetooth_jni.so (bta_gattc_write(tBTA_GATTC_CLCB*, tBTA_GATTC_DATA const*)+132) (BuildId: 7001913fb2cea33f30debe52c67cfb2b)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #06 pc 00000000003e2c18  /apex/com.android.btservices/lib64/libbluetooth_jni.so (bta_gattc_sm_execute(tBTA_GATTC_CLCB*, unsigned short, tBTA_GATTC_DATA const*)+296) (BuildId: 7001913fb2cea33f30debe52c67cfb2b)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #07 pc 0000000000361c88  /apex/com.android.btservices/lib64/libbluetooth_jni.so (bta_sys_event(BT_HDR_RIGID*)+136) (BuildId: 7001913fb2cea33f30debe52c67cfb2b)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #08 pc 0000000000baeb24  /apex/com.android.btservices/lib64/libbluetooth_jni.so (base::debug::TaskAnnotator::RunTask(char const*, base::PendingTask*)+196) (BuildId: 7001913fb2cea33f30debe52c67cfb2b)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #09 pc 0000000000baddb0  /apex/com.android.btservices/lib64/libbluetooth_jni.so (base::MessageLoop::RunTask(base::PendingTask*)+352) (BuildId: 7001913fb2cea33f30debe52c67cfb2b)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #10 pc 0000000000bae174  /apex/com.android.btservices/lib64/libbluetooth_jni.so (base::MessageLoop::DoWork()+452) (BuildId: 7001913fb2cea33f30debe52c67cfb2b)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #11 pc 0000000000bb140c  /apex/com.android.btservices/lib64/libbluetooth_jni.so (base::MessagePumpDefault::Run(base::MessagePump::Delegate*)+108) (BuildId: 7001913fb2cea33f30debe52c67cfb2b)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #12 pc 0000000000bdaa08  /apex/com.android.btservices/lib64/libbluetooth_jni.so (base::RunLoop::Run()+72) (BuildId: 7001913fb2cea33f30debe52c67cfb2b)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #13 pc 000000000066a58c  /apex/com.android.btservices/lib64/libbluetooth_jni.so (bluetooth::common::MessageLoopThread::Run(std::__1::promise<void>)+348) (BuildId: 7001913fb2cea33f30debe52c67cfb2b)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #14 pc 0000000000669f80  /apex/com.android.btservices/lib64/libbluetooth_jni.so (bluetooth::common::MessageLoopThread::RunThread(bluetooth::common::MessageLoopThread*, std::__1::promise<void>)+48) (BuildId: 7001913fb2cea33f30debe52c67cfb2b)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #15 pc 000000000066aae4  /apex/com.android.btservices/lib64/libbluetooth_jni.so (void* std::__1::__thread_proxy<std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct> >, void (*)(bluetooth::common::MessageLoopThread*, std::__1::promise<void>), bluetooth::common::MessageLoopThread*, std::__1::promise<void> > >(void*)+84) (BuildId: 7001913fb2cea33f30debe52c67cfb2b)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #16 pc 00000000000c14dc  /apex/com.android.runtime/lib64/bionic/libc.so (__pthread_start(void*)+204) (BuildId: cbc4c62a9b269839456f1d7728d8411e)
2022-09-19 16:30:48.588 2365-2365/? A/DEBUG:       #17 pc 0000000000054930  /apex/com.android.runtime/lib64/bionic/libc.so (__start_thread+64) (BuildId: cbc4c62a9b269839456f1d7728d8411e)

@philips77
Copy link
Member

Are you using WRITE_DEFAULT write type?
The Long Write procedure limits the packet to... I think something around 500. Of course the crash is not a good thing, but try to limit your data. You may also use WRITE_NO_RESPONSE and use .split() method in WriteRequest, which will automatically split your packet into MTU-size packets. I think it will also work for write with response, but then the Long Write proc won't be used.

@sara-race-neato
Copy link
Author

sara-race-neato commented Sep 20, 2022

I am using WRITE_DEFAULT type, and due to that I'm unable to use .split() method in WriteRequest because it successfully splits the data into two requests, but the first request responds with an error code since the data is not complete.

@philips77
Copy link
Member

Accepting data in chunks needs to be supported on the device side. I don't know what protocol are you using. If you have influence over the peripheral side, you may modify the firmware to support it. Usually, either the first write command contains a full length, or each packet has a flag "start/continuation/end/full" based on which it can either buffer, or sent to processing.

Anyway, sending 540 bytes will not succeed even using Long Write, and I wonder how it used to work.

@sara-race-neato
Copy link
Author

In Android 12 logs I see the following lines, so it seems like Android 12 is allowing long writes over 512 bytes, but in Android 13 it's limited for some reason. Either way, it doesn't seem like something that can be fixed in this library.

2022-09-20 16:26:03.799 1902-2586/? E/bt_stack: [ERROR:gatt_cl.cc(572)] value resp op_code = ATT_RSP_PREPARE_WRITE len = 516
2022-09-20 16:26:03.931 1902-2586/? E/bt_stack: [ERROR:gatt_cl.cc(572)] value resp op_code = ATT_RSP_PREPARE_WRITE len = 38

@weliem
Copy link

weliem commented Sep 22, 2022

According to the Bluetooth specification the maximum length of a characteristic is 512 bytes. Previously, Android did not enforce this limit but that has now been corrected.

@adi-pilav-sn
Copy link

I had the same issue and resolved it once I limited the MTU to the size of 512 (or 509, given that 3 bytes are reserved). Thank you @weliem! Where can I find the specifications docs that you mentioned?

@filnik
Copy link

filnik commented Sep 28, 2022

We have made it work using split() and changing our bluetooth gatt server. Is there a standard way to define that we are splitting packets to identify the first and last packet? @philips77

@giampaolo
Copy link

Hi @philips77

Usually, either the first write command contains a full length

Do you know if the first write() is guaranteed to be fully sent as-is even if it's very small (let's say 4 bytes)? Is there a risk for it to be sent with subsequent data, when the send buffer is big enough? Basically what I'm asking is if a flush() automatically occurs after every write().

@philips77
Copy link
Member

Hi,
write() always writes all data given and doesn't split to chunks. If you use .split(), the splitter decides how to split, and each returned chunk will be sent together, not split further. The DefaultMtuSplitter cuts to MTU-3 bytes chunks.

Smallest MTU is 23, so at least 20 bytes will always be sent.

We have made it work using split() and changing our bluetooth gatt server. Is there a standard way to define that we are splitting packets to identify the first and last packet?

I am aware of only 2 ways, that I described here: #420 (comment)
Unless, of course, the length is fixed and there's no need to send any header.

@giampaolo
Copy link

giampaolo commented Sep 29, 2022

write() always writes all data given and doesn't split to chunks.
...
Smallest MTU is 23, so at least 20 bytes will always be sent.

These 2 statements appears to conflict with each other. If I send a string of 4 bytes is it guaranteed that it gets sent as a single request/packet?

@philips77
Copy link
Member

Yes, unless you're using some custom DataSplitter where you split for even smaller chunks. Unlikely that you'er doing it.

For example:

This will send a single packet of 4 bytes:

writeCharacteristic(c, byteArrayOf(1, 2, 3, 4), BluetoothGattCharacteristic.WRITE_TYPE_DEFAULT)
   .done { device, data -> /* ... */ }
   .enqueue()

This will send also a single packet, as 4 < MTU-3:

writeCharacteristic(c, byteArrayOf(1, 2, 3, 4), BluetoothGattCharacteristic.WRITE_TYPE_DEFAULT)
   .split() // Uses default MTU splitter
   .done { device, data -> /* ... */ }
   .enqueue()

This will send 4 packages, each of 1 byte:

writeCharacteristic(c, byteArrayOf(1, 2, 3, 4), BluetoothGattCharacteristic.WRITE_TYPE_DEFAULT)
   .split(DataSplitter { message, index, _ -> byteArrayOf(message[index]) }))
   .done { device, data -> /* ... */ }
   .enqueue()

@philips77
Copy link
Member

This will send only MTU-3 bytes (by default 23-3=20) in a single packet, ignoring the rest:

val array = ByteArray(1000) { it.toByte() }
writeCharacteristic(c, array, BluetoothGattCharacteristic.WRITE_TYPE_NO_RESPONSE)
   .done { device, data -> /* ... */ }
   .enqueue()

This, as it is using write with response, will send around 512 bytes or will crash:

val array = ByteArray(1000) { it.toByte() }
writeCharacteristic(c, array, BluetoothGattCharacteristic.WRITE_TYPE_DEFAULT)
   .done { device, data -> /* ... */ }
   .enqueue()

@filnik
Copy link

filnik commented Sep 29, 2022

Thank you @philips77, you were super kind in explaining us all of this :) 🤝

@giampaolo
Copy link

Thanks a lot @philips77, that was very helpful.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

6 participants