pc-ble-driver-py, mtu size, data length extensions and connectivity firmware

[john23094]

Hi,

I'm trying to develop an application that uses an nrf52840-dk board and the pc-ble-driver-py. The dk is supposed to be a central device.

Using the python driver library, I've got it to connect to another custom board (supposed to be a peripheral), that also uses an nrf52840 MCU. When it connects however, the custom board is supposed to negotiate a higher MTU size, packet data length extensions, and connection interval. It always does this when I connect to nRF connect on my smartphone, or anything else. But I can't seem to get it to do this with the dk and ble-driver-py. It connects, but never seems to negotiate anything. Should I make the dk (the central) try and negotiate?

The dk is flashed with connectivity firmware version: 4.1.4. SoftDevice API version: 5.

Is this a limitation of the driver and connectivity firwmare version? I can't find anything in the driver code relating to it. 

I'm also quite confused with the state of the pc-ble-driver and connectivity firmware. Can you confirm if the following is correct?:

• pc-ble-driver-py supports up to SD api v5 only, and s132 SD only
• Is there any way I can use SD s140 and v6 API? that's what my custom peripheral MCU is programmed with

[Hung Bui]

Hi Savvn, 

As far as I know the pc-ble-driver should support longer MTU size. Could you have a look at the workaround mentioned in this ticket and check if it work for you ? 
pc-ble-driver-py is a pretty old tool and will not have further update. But it should work with S140 with v6 API. Could you point me to where you got the information about: 

pc-ble-driver-py supports up to SD api v5 only, and s132 SD only

I would suggest to capture a sniffer trace so we know what exactly over the air. 

[john23094]

When I connect to my peripheral device, no MTU negotiation happens, only PHY update request. This is when I call the connect() function inside ble_adapter.py.

I'll take a look at that ticket now, it must have missed me when I was searching for similar posts on this topic.

I do realize it's an older tool, but we want to work in Python as its quicker for us currently to get this up and running with python. 

If you look inside pc-ble-driver-py/pc_ble_driver_py/hex/ only folders sd_api_v2 and sd_api_v5 are listed. 

Inside pc_ble_driver_py/lib you will find only nrf_ble_driver_sd_api_v2.py and nrf_ble_driver_sd_api_v5.py. Inside the code only references to 'v2' and 'v5' can be found.

On top of that, I've tried to flash my dk with connectivity fw that contains SD S140 and v6.1.1 API from here:

https://github.com/NordicSemiconductor/pc-ble-driver/tree/release/4.1.4/hex/sd_api_v6

And it wouldn't work, pc-ble-driver-py would report timeout

 

[Hung Bui]

Did you follow the workaround mentioned in the case I pointed to ? 
Of setting self.adapter.default_mtu = 247 manually ? 

Please capture a sniffer trace. If you have added in the code that the slave should request ATT MTU update, it should do that when connected, regardless which central it connects to. 

[john23094]

Ok I think I've gotten to the bottom of this.

I followed the OP's code in that other post.

This is what the adapter open code looks like:

self.adapter.driver.open()
self.adapter.default_mtu = 547

gatt_cfg = BLEConfigConnGatt()
gatt_cfg.att_mtu = 547
gatt_cfg.tag = CFG_TAG
self.adapter.driver.ble_cfg_set(BLEConfig.conn_gatt, gatt_cfg)

cfg = BLEConfigGapRoleCount(central_role_count=1, periph_role_count=0, central_sec_count=0)
cfg.conn_cfg_tag = CFG_TAG
self.adapter.driver.ble_cfg_set(BLEConfig.role_count, cfg)

cfg = BLEConfigConnGap(event_length=251)
cfg.conn_cfg_tag = CFG_TAG
self.adapter.driver.ble_cfg_set(BLEConfig.conn_gap, cfg)

self.adapter.driver.ble_enable()

After scanning, and discovering, I simply did something like this to connect:

self.adapter.connect(device_adv_data.peer_addr,conn_params=None, tag=CFG_TAG)

Now with this, it communicates the event data length and PHY (the max - 251. But NOT MTU size or conn. interval. This can be seen from wireshark:

I would have thought, like when connecting to anything else, the peripheral (server) should initiate these negotiations? I was wrong actually, it's the master that starts the MTU size negotiation. I saw this when comparing that trace, to another trace where I connect my peripheral to an iPhone X. So from OP's example in other post I added this code after the adapter connect.

logging.info('Requesting MTU exchange')
self.att_mtu = self.adapter.att_mtu_exchange(new_conn_handle, 517)

And now it negotiates the right size. So actually my knowledge of the connection process was not quite correct. But at least now I know how it's meant to go.

[john23094]

Actually, - to add, I have a new question.

Service discovery is quite slow if i initiate the connection with a longer connection interval.

Is it possible for a peripheral/server/slave device to know when service discovery is complete? I'd like the peripheral/server/slave to initiate negotiation for a higher conn. interval after the central/master/client has completed discovering the GATT table. This would be cool if possible, as I think that logic would be better on the peripheral's side in our device.

[Hung Bui]

Hi Savvn, 

We need to look into how in the slave side you request MTU exchange. There is a chance that if the central already request a bigger ATT MTU the slave will skip the request. But normally we should see the request from the slave. There isn't a way that the central can block the request from the slave from sending. 

Regarding your question about when the peripheral can detect when service discovery finished, I don't think it's possible , at least with our softdevice. 
What you can do is either change the connection interval from the central side. It's the case with many phones as the centrals. Short interval when doing service discovery and switch to long interval after that. 

Another option is to do a BLE activity, for example enable CCCD or write to a characteristic after service discovery is finished. Then the slave would have a call back and can check the connection interval and can request a longer one. 

[john23094]

The MTU size on the slave side is simply from example code, called when initing bluetooth.

/**@brief Function for initializing the GATT library. */
void gatt_init(uint16_t p_conn_handle)
{
ret_code_t err_code;

_gap_params_init();

_p_m_conn_handle = p_conn_handle;

err_code = nrf_ble_gatt_init(&m_gatt, _gatt_evt_handler);
APP_ERROR_CHECK(err_code);

err_code = nrf_ble_gatt_att_mtu_periph_set(&m_gatt, NRF_SDH_BLE_GATT_MAX_MTU_SIZE);
APP_ERROR_CHECK(err_code);

err_code = nrf_ble_gatt_data_length_set(&m_gatt, BLE_CONN_HANDLE_INVALID, NRF_SDH_BLE_GAP_DATA_LENGTH);
APP_ERROR_CHECK(err_code);
}

But like I said, with the code I posted above, after connecting, the master app using pc-ble-driver-py requests this max MTU size, and the slave now agrees (responds).

I used the sniffer and looked at the MTU negotiation procedure when connecting to nrf-connect on android, and it looked the same, master requested MTU extension first. I believe this is the correct behaviour no?

On the other point - yeah I realised that now after reading some other posts. It's fine I ended up using a timer on the slave after connection to ask for a new conn. interval.

[john23094]

Sorry with the onslaught of questions - I have one (hopefully final one):

I have another issue now.

I'm writing a cmd to my peripheral device, it puts it into a state where it should begin to rapidly spit out notifications.

For some reason, the DK running connectivity firmware locks up soon as I send write cmd. I set logging to debug, and it seems to randomly reset itself after sending the write cmd:

10:54:24,823 pc_ble_driver_py.observers INFO Setting mode to: 2
10:54:24,823 pc_ble_driver_py.observers DEBUG evt> severity(10) message(     585 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:6 payload_length:0 data_integrity:0 err_code:0x0)
10:54:24,824 pc_ble_driver_py.observers INFO Sending write cmd now
10:54:24,824 pc_ble_driver_py.ble_adapter DEBUG      586 ->  [00 9c 00 00 01 02 00 26 00 00 00 01 00 01 02 ] type:     VENDOR_SPECIFIC reliable:yes seq#:3 ack#:6 payload_length:f data_integrity:1 header_checksum:f err_code:0x0
10:54:24,825 pc_ble_driver_py.observers DEBUG evt> severity(10) message(     586 ->  [00 9c 00 00 01 02 00 26 00 00 00 01 00 01 02 ] type:     VENDOR_SPECIFIC reliable:yes seq#:3 ack#:6 payload_length:f data_integrity:1 header_checksum:f err_code:0x0)
10:54:24,826 pc_ble_driver_py.ble_adapter DEBUG   582/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:4 payload_length:0 data_integrity:0 err_code:0x0
10:54:24,826 pc_ble_driver_py.observers DEBUG evt> severity(10) message(  582/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:4 payload_length:0 data_integrity:0 err_code:0x0)
10:54:24,826 pc_ble_driver_py.ble_adapter DEBUG   583/ 0 <-  [01 9c 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:6 ack#:4 payload_length:6 data_integrity:1 header_checksum:ac err_code:0x0
10:54:24,826 pc_ble_driver_py.ble_adapter DEBUG Call ble_gattc_write: response(None) write_params(Write Params write_op(BLEGattWriteOperation.write_cmd) flags(BLEGattExecWriteFlag.prepared_cancel) handle(38) offset(0) data([2]))
10:54:24,826 pc_ble_driver_py.observers DEBUG evt> severity(10) message(  583/ 0 <-  [01 9c 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:6 ack#:4 payload_length:6 data_integrity:1 header_checksum:ac err_code:0x0)
10:54:24,839 pc_ble_driver_py.ble_adapter DEBUG      587 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:7 payload_length:0 data_integrity:0 err_code:0x0
10:54:24,839 pc_ble_driver_py.observers DEBUG evt> severity(10) message(     587 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:7 payload_length:0 data_integrity:0 err_code:0x0)
10:54:24,839 pc_ble_driver_py.ble_adapter DEBUG   584/ 0 <-  [02 3c 00 00 00 00 00 00 00 01 ] type:     VENDOR_SPECIFIC reliable:yes seq#:7 ack#:4 payload_length:a data_integrity:1 header_checksum:6b err_code:0x0
10:54:24,839 pc_ble_driver_py.observers DEBUG evt> severity(10) message(  584/ 0 <-  [02 3c 00 00 00 00 00 00 00 01 ] type:     VENDOR_SPECIFIC reliable:yes seq#:7 ack#:4 payload_length:a data_integrity:1 header_checksum:6b err_code:0x0)
10:54:24,839 pc_ble_driver_py.ble_adapter DEBUG      588 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0x0
10:54:24,839 pc_ble_driver_py.observers DEBUG evt> severity(10) message(     588 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0x0)
10:54:24,852 pc_ble_driver_py.observers DEBUG evt> gattc_evt_write_cmd_tx_complete conn(0)
 count(1)
10:54:24,866 pc_ble_driver_py.ble_adapter DEBUG   585/ 0 <-  [02 39 00 00 00 00 00 00 00 2f 00 01 01 00 02 ] type:     VENDOR_SPECIFIC reliable:yes seq#:0 ack#:4 payload_length:f data_integrity:1 header_checksum:22 err_code:0x0
10:54:24,866 pc_ble_driver_py.observers DEBUG evt> severity(10) message(  585/ 0 <-  [02 39 00 00 00 00 00 00 00 2f 00 01 01 00 02 ] type:     VENDOR_SPECIFIC reliable:yes seq#:0 ack#:4 payload_length:f data_integrity:1 header_checksum:22 err_code:0x0)
10:54:24,878 pc_ble_driver_py.ble_adapter DEBUG      589 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0x0
10:54:24,878 pc_ble_driver_py.observers DEBUG evt> severity(10) message(     589 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0x0)
10:54:24,897 pc_ble_driver_py.observers DEBUG evt> on_gattc_evt_hvx status(BLEGattStatusCode.success) conn(0)
 error_handle(0)
 attr_handle(47)
 hvx_type(BLEGattHVXType.notification)
 data([2])
10:54:25,287 pc_ble_driver_py.ble_adapter DEBUG   586/ 0 <-  [01 7e ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:2 data_integrity:0 err_code:0x0 [SYNC]
10:54:25,288 pc_ble_driver_py.observers DEBUG evt> severity(10) message(  586/ 0 <-  [01 7e ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:2 data_integrity:0 err_code:0x0 [SYNC])
10:54:25,288 pc_ble_driver_py.ble_adapter DEBUG RpcAppStatus.resetPerformed: Target Reset performed
10:54:25,289 pc_ble_driver_py.observers DEBUG evt> status code(RpcAppStatus.resetPerformed) message(Target Reset performed)
10:54:25,289 pc_ble_driver_py.ble_adapter DEBUG State change: STATE_ACTIVE -> STATE_RESET
10:54:25,289 pc_ble_driver_py.observers DEBUG evt> severity(10) message(State change: STATE_ACTIVE -> STATE_RESET)
10:54:25,289 pc_ble_driver_py.ble_adapter DEBUG      590 ->  [N/A] type:          RESERVED_5 reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0x0
10:54:25,289 pc_ble_driver_py.observers DEBUG evt> severity(10) message(     590 ->  [N/A] type:          RESERVED_5 reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0x0)
10:54:25,590 pc_ble_driver_py.ble_adapter DEBUG State change: STATE_RESET -> STATE_UNINITIALIZED
10:54:25,591 pc_ble_driver_py.observers DEBUG evt> severity(10) message(State change: STATE_RESET -> STATE_UNINITIALIZED)
10:54:25,591 pc_ble_driver_py.ble_adapter DEBUG      591 ->  [01 7e ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:2 data_integrity:0 err_code:0x0 [SYNC]
10:54:25,591 pc_ble_driver_py.observers DEBUG evt> severity(10) message(     591 ->  [01 7e ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:2 data_integrity:0 err_code:0x0 [SYNC])
10:54:25,592 pc_ble_driver_py.ble_adapter DEBUG   587/ 0 <-  [02 7d ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:2 data_integrity:0 err_code:0x0 [SYNC_RESP]
10:54:25,592 pc_ble_driver_py.observers DEBUG evt> severity(10) message(  587/ 0 <-  [02 7d ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:2 data_integrity:0 err_code:0x0 [SYNC_RESP])
10:54:25,592 pc_ble_driver_py.ble_adapter DEBUG State change: STATE_UNINITIALIZED -> STATE_INITIALIZED
10:54:25,593 pc_ble_driver_py.observers DEBUG evt> severity(10) message(State change: STATE_UNINITIALIZED -> STATE_INITIALIZED)
10:54:25,593 pc_ble_driver_py.ble_adapter DEBUG      592 ->  [03 fc 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]]
10:54:25,593 pc_ble_driver_py.observers DEBUG evt> severity(10) message(     592 ->  [03 fc 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]])
10:54:25,896 pc_ble_driver_py.ble_adapter DEBUG      593 ->  [03 fc 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]]
10:54:25,896 pc_ble_driver_py.observers DEBUG evt> severity(10) message(     593 ->  [03 fc 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]])
10:54:25,992 pc_ble_driver_py.ble_adapter DEBUG   588/ 0 <-  [01 7e ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:2 data_integrity:0 err_code:0x0 [SYNC]
10:54:25,993 pc_ble_driver_py.observers DEBUG evt> severity(10) message(  588/ 0 <-  [01 7e ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:2 data_integrity:0 err_code:0x0 [SYNC])
10:54:25,993 pc_ble_driver_py.ble_adapter DEBUG      594 ->  [02 7d ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:2 data_integrity:0 err_code:0x0 [SYNC_RESP]
10:54:25,993 pc_ble_driver_py.observers DEBUG evt> severity(10) message(     594 ->  [02 7d ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:2 data_integrity:0 err_code:0x0 [SYNC_RESP])
10:54:26,201 pc_ble_driver_py.ble_adapter DEBUG      595 ->  [03 fc 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]]
10:54:26,201 pc_ble_driver_py.observers DEBUG evt> severity(10) message(     595 ->  [03 fc 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]])
10:54:26,202 pc_ble_driver_py.ble_adapter DEBUG   589/ 0 <-  [03 fc 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]]
10:54:26,202 pc_ble_driver_py.observers DEBUG evt> severity(10) message(  589/ 0 <-  [03 fc 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]])
10:54:26,202 pc_ble_driver_py.ble_adapter DEBUG      596 ->  [04 7b 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG_RESP [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]]
10:54:26,202 pc_ble_driver_py.observers DEBUG evt> severity(10) message(     596 ->  [04 7b 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG_RESP [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]])
10:54:26,506 pc_ble_driver_py.ble_adapter DEBUG      597 ->  [03 fc 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]]
10:54:26,507 pc_ble_driver_py.observers DEBUG evt> severity(10) message(     597 ->  [03 fc 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]])
10:54:26,508 pc_ble_driver_py.ble_adapter DEBUG   590/ 0 <-  [04 7b 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG_RESP [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]]
10:54:26,508 pc_ble_driver_py.observers DEBUG evt> severity(10) message(  590/ 0 <-  [04 7b 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG_RESP [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]])
10:54:26,508 pc_ble_driver_py.ble_adapter DEBUG RpcAppStatus.connectionActive: Connection active
10:54:26,508 pc_ble_driver_py.observers DEBUG evt> status code(RpcAppStatus.connectionActive) message(Connection active)
10:54:26,509 pc_ble_driver_py.ble_adapter DEBUG State change: STATE_INITIALIZED -> STATE_ACTIVE
10:54:26,509 pc_ble_driver_py.observers DEBUG evt> severity(10) message(State change: STATE_INITIALIZED -> STATE_ACTIVE)

I'm trying to understand what's going on but I have no idea. It looks like the DK gets a LINK_CONTROL_PACKET, then for some reason it decides to reset itself? RpcAppStatus.resetPerformed: Target Reset performed

[Hung Bui]

Hi Savvn,

According to the answer from our colleague Terje here. It seems like a control message to set up the UART communication and may have something to do with lost power on the connectivity chip. It may not be the case with your setup but we need to look into why it happens. 

Have you checked if there is anything special with the write command ? Is the payload large  ? Any write command would cause the issue or only that specific command ? 

If you simply test with for example heart rate collector do you see the same problem ? 

[john23094]

Hi Hung,

(I never manage to find these other forum posts - I searched for 'pc-ble-driver Target Reset performed notification' or similar, maybe I'm not searching correctly)

My first assumption was something similar, so I did try connecting the dongle directly to a USB port on my laptop - in case it was a hub/similar causing the issue. But no avail. I literally unplugged everything from my machine and only connected the dk directly. (the peripheral device is powered off an other USB pwr source).

I've already done the MSDDisable Jlink work around.

The write cmd isn't large, it's literally 1 btye.

Any other write command seems fine, it's this exact chain of events you see in the log:

• Do a write cmd
• Recv a notification (of 1 byte) about150ms later
• For some reason PC sends LINK_CONTROL_PACKET and resets the dk

Heart rate collector example works fine.

[Hung Bui]

Hi Savvn, 

It's strange the hr collector works but yours doesn't. Could you try to check the difference between the two ? As far as I know the hr collector also do a write command to enable notification and then receive notification after that. 

Maybe you can just test by modify the hr collector to use your service&characteristic UUID and then do the same write ? 

Is there anything in the notification can cause the firmware/python to crash ?