MTU is not updated if requested by the peripheral

[dariuszseweryn]

Summary

RxBleConnectionImpl private mtu variable is not updated if the MTU request was initiated by the peripheral device

Library version

1.4.1

Steps to reproduce actual result

1. connect to a peripheral

2. make the peripheral to update MTU (i.e. 56)

3. call the RxBleConnection.getMtu()

Minimum code snippet reproducing the issue

Requires peripheral action

Actual result

RxBleConnection.getMtu() returns the default MTU (23)

Expected result

RxBleConnection.getMtu() returns the updated MTU (i.e. 56)

https://stackoverflow.com/questions/46732724/how-to-get-larger-mtu-in-rxandroidble

[dariuszseweryn]

Should be fixed with #294

[petri-lipponen-suunto]

I tried 1.4.3 with this and it still doesn't work.

My data send method ends with:

     {
 .... 
        // Do the writing
        connection.createNewLongWriteBuilder()
                .setCharacteristic(device.getWriteCharasteristic())
                .setBytes(encoded)
                .setMaxBatchSize(getMaxDataSize(connection))
                .build()
                .toSingle()
                .subscribe(new Action1<byte[]>() {
                    @Override
                    public void call(byte[] bytes) {
                        Log.d(TAG, "Send complete");
                    }
                }, new ThrowableLoggingAction(TAG, "Data write failed"));

        return true;
    }
 
    private int getMaxDataSize(RxBleConnection connection) {
        int currentMTU = connection.getMtu();
        Log.d(TAG, "getMaxDataSize: connection.getMtu: " + currentMTU);
        return currentMTU - 3; // 3 bytes of lower level header before GATT data
    }

I can see the _getMaxDataSize: connection.getMtu: _ in the log every time data is sent but the value printed stays at 23.

I even tried to do requestMtu(GATT_MTU_MAXIMUM) (=517) but still nothing. Is there something I've missed? I'm using minSdkVersion 21 in my project.

[dariuszseweryn]

Have you requested the MTU before you have executed the above code? Are you sure that your peripheral supports higher MTU?

[petri-lipponen-suunto]

@dariuszseweryn Yes, I can see in peripheral devices log that the MTU is degotiated to 158 before the data transfer starts. Here's the relevant portion of it:

00:12:53 BLE event: 10 - Connection established
00:12:53 BLE GAP: onConnect to 5D:33:4C:E6:EF:C5 (Random private resolvable)
:DEBUG:onConnectedImpl(), deviceId: 0
BLE_GATT:INFO:EXCHANGE_MTU_RSP effective ATT MTU is 158 for conn_handle 0 
00:12:53 BLE event: 3A - Exchange MTU Response event
BLE_GATT:INFO:Data Length Extended (DLE) for conn_handle 0 
BLE_GATT:DEBUG:max_rx_octets 27 
BLE_GATT:DEBUG:max_rx_time 328 
BLE_GATT:DEBUG:max_tx_octets 162 
BLE_GATT:DEBUG:max_tx_time 2120 
00:12:53 BLE event: 04 - Link layer PDU length changed
00:12:54 conn_interval_configured
00:12:54 BLE event: 12 - Connection Parameters updated
00:12:54 BLE_GAP_EVT_CONN_PARAM_UPDATE. connection interval: 6

00:12:54 conn_interval_configured
00:12:54 BLE event: 12 - Connection Parameters updated
00:12:54 BLE_GAP_EVT_CONN_PARAM_UPDATE. connection interval: 36

:DEBUG:onDataReceivedImpl(), size: 20
:DEBUG:onDataReceivedImpl(), size: 20
:DEBUG:onDataReceivedImpl(), size: 4
:DEBUG:Hello: ECSD00000000 #4 v(3.10.0-0000) -> 174430000320 #32 (v3.4.1-0000)
:DEBUG:MTU change detected. new MTU: 158
:DEBUG:onSendCompletedImpl()
:DEBUG:onDataReceivedImpl(), size: 20
:DEBUG:onDataReceivedImpl(), size: 8
:DEBUG:onSendCompletedImpl()
:DEBUG:onDataReceivedImpl(), size: 20
:DEBUG:onDataReceivedImpl(), size: 6
:DEBUG:onSendCompletedImpl()

as you can see there is limitation of 20 bytes (multiple :DEBUG:onDataReceivedImpl()'s). The other direction supports 158 byte MTU just fine and they arrive to mobile app correctly.

[dariuszseweryn]

Could you add logs from the Android OS with RxBleLog.setLogLevel(RxBleLog.VERBOSE)?

[petri-lipponen-suunto]

rxandroidble_mtu.log

[dariuszseweryn]

Unfortunately in the above log there is no indication that BluetoothGattCallback.onMtuChanged() has been called so the Android application was not informed about the change of the MTU.

RxBleLog.d("onMtuChanged mtu=%d status=%d", mtu, status); does get called when the library is informed about the MTU change. There is no onMtuChanged string in the attached log. This seems to be a problem with Android BLE stack. What OS / phone model do you use?

Btw. The LongWriteBuilder does use the maximum negotiated MTU by default if not specified otherwise so you could remove this line:

    .setMaxBatchSize(getMaxDataSize(connection))

Alternatively you could try to specify .setMaxBatchSize(158-3) as a workaround. If the lower layers of the BLE stack would send the data appropriately. But it is not a bulletproof solution.

[petri-lipponen-suunto]

I'm using Sony Xperia XZ Premium with Android 8.0. I'll try both your suggestions. How does the LongWriteBuilder work in case the MTU is 23 and I set MaxBatchSize(155)? Does it truncate or deal with it internally?

[dariuszseweryn]

The library will pass the byte[] of length 155 down to the Android BLE stack. The Android BLE stack will handle it some way (it does truncate it from my experience)

If one does not specify .setMaxBatchSize() then the library sends batches of the MTU - 3 size by default. If the library is not informed by the Android BLE stack about MTU change it defaults to 23 - 3 bytes.

[petri-lipponen-suunto]

In Android BLE logs I found the following lines:

12-11 15:18:50.872 3522-4021/? E/bt_att: MTU request PDU with MTU size 158
12-11 15:18:50.872 3522-4021/? E/bt_btm: BTM_SetBleDataLength failed, peer does not support request

Looks like there is something fishy there... I'll try with another phone and will update this bugreport later.

Thanks for your help.

[dariuszseweryn]

This issue was about a situation where peripheral initiated MTU change was not correctly handled by the library. Your problem is different though related to MTU as well. Please create a new issue if needed.

[petri-lipponen-suunto]

Unfortunately this is not a phone issue, but something in the RxAndroidBle.

I created a small sample app using pure android BLE classes and I can get the onMtuChanged callback if and only if I call requestMtu first (android Oreo issue, I created one in Android issue tracker: https://issuetracker.google.com/issues/70542026). However I don't get any when running the similar code via RxAndroidBle.

I created a small sample app to demonstrate the issue. If I click the "Test Pure" the MTU change is detected, with "Test Rx" not. It could be something I do with RxAndroidBle (I'm not too fluent with Rx world) but I can't figure out what it would be.

Tested on both Samsung Galaxy A3 (8.0) as well as Sony Xperia XZ Premium (8.0)

BLEMTUTest.zip

[dariuszseweryn]

@petri-lipponen-suunto are you aware that you did not triggered the MTU change in the above example?

mSubscription = device.establishConnection(false)
                .flatMap(new Func1<RxBleConnection, Observable<RxBleDeviceServices>>() {
                    @RequiresApi(api = Build.VERSION_CODES.LOLLIPOP)
                    @Override
                    public Observable<RxBleDeviceServices> call(RxBleConnection rxBleConnection) {
                        Log.d(TAG, "BLE connected to " + bleDeviceAddr);

                        // Request for a big MTU in case the device supports it
                        Log.d(TAG, "requestMtu GATT_MTU_MAXIMUM: " + GATT_MTU_MAXIMUM);
                        rxBleConnection.requestMtu(GATT_MTU_MAXIMUM);
                        connMap.put(bleDeviceAddr, rxBleConnection );
                        return rxBleConnection.discoverServices();
                    }
                })

The result of the rxBleConnection.requestMtu(GATT_MTU_MAXIMUM) is an Observable<Integer> which needs to be subscribed as any other observable to trigger the action.

[petri-lipponen-suunto]

Ah, that might explain it, I'll give it a shot. I assumed that the current MTU (from getMtu()) would be updated regardless, since it is a connection parameter...

Tested: That did the trick! adding .subscribe() to it caused it to work. It is a bit counter intuitive that the request is not handled if it is not subscribed, at least for someone without any Rx background...