android large mtu.pcapnghp pavilion ble 5.pcapng
After the MTU size exchange of 247 bytes with Android LL_LENGTH_REQ/LL_LENGTH_RSP are exchanged with 123 byte octets for TX and RX. Data flows properly after that.
But with Windows, after the MTU size exchange of 247 bytes an LL_LENGTH_REQ is sent with 251 byte octet. No LL_LENGTH_RSP is sent by Nordic from the nRF52832
and no further data exchange takes place.
HI Mark,
the slave is sending a ATT_EXCHANGE_MTU_REQ in the same connection event as the master sends the LL_FEATURE_REQ. Our nrf_ble_gatt.c module will initiate a ATT MTU exchange, i.e. call sd_ble_gattc_exchange_mtu_request() if the NRF_SDH_BLE_GATT_MAX_MTU_SIZE is larger than the BLE_GATT_ATT_MTU_DEFAULT.
So it would seem that the nRF is waiting for the ATT_EXCHANGE_MTU_RSP, while the central is waiting for the LL_LENGTH_RSP. I am not quite sure which request that should have priority, need to check the spec / confer with the SoftDevice team.
Meanwhile, could you try to set NRF_SDH_BLE_GATT_MAX_MTU_SIZE == BLE_GATT_ATT_MTU_DEFAULT and see if that resolves the "deadlock"?
Best regards
Bjørn
Do you get the BLE_GAP_EVT_DATA_LENGTH_UPDATE_REQUEST event on the nRF side? Could you check whether the NRF device is calling sd_ble_gap_data_length_update() to respond to the LL_LENGTH_REQ as shown in the Data Length Update Procedure Message sequence chart.
OK, that is interesting. I see that the MTU exchange procedure now occurs after all the LL transactions and is triggered by the master , instead of immediatly after the connection establishment triggered by the slave as before. So it could be that the time and place of the MTU exchange has a role to play here.
Did you try leaving the MTU size at 247 on the Nordic side and then just delay the sd_ble_gattc_exchange_mtu_request() call that triggers the BLE_GATTS_EVT_EXCHANGE_MTU_REQUEST from the slave? In my previous reply I stated that a delay should be added before the on_exchange_mtu_request_evt() call in nrf_ble_gatt_on_ble_evt(). THis is incorrect, it should have been the on_connected_evt() call under the BLE_GAP_EVT_CONNECTED case in nrf_ble_gatt_on_ble_evt() in nrf_ble_gatt.c
Added a 500ms delay in on_connected_evt() just before the call to sd_ble_gattc_exchange_mtu_request(). It still did not work. I will be able to take an OTA trace in the morning and attach it.
Great. I'll wait for the OTA trace and then analyze it with the SoftDevice team to figure out what the cause of the issue is.
0743.hp pavilion large mtu 02-25-20.pcapng
0> REBOOT (9) 0> Bluetooth Name NM04-000008 0> Board Type D045 0> Model Type ETM 0> FPGA Ver Model 4 Version 4 0> Firmware Ver 1.8.330 0> Firmware Type FIELD_BLE_UART 0> SoftDevice Ver 6.1.0 0> BootLoader Ver 6 (INSTALLED) 0> Mfg Data Ver 4 0> Sys Config Ver 10 0> API Versions OK 0> Bluetooth Enabled 0> UART Enabled 0> Stimulation Enabled 0> Acceleration Disabled (0) 0> Force Error Disabled (0) 0> Electrode Map Field 8 Contact 0> Reboot Reason Watchdog Timeout (Bootloader) 0> 0> wdt_register_long_timer: 2 for 191177 0> BLE: Local BDADDR xEFF00F3689C3 0> wdt_register_long_timer: 0 for 242305 0> 0:00:01.439 PWR: Entering normal power 0> WDT: enable 0 0> Register TTAP: added handler[0]=x2C59D 0> WDT: enable 0 0> 0:00:01.442 STIM STATE: SEARCHING 0> 0:00:01.443 ADV: Sys=FFFFFFFF Dev=0 VBat=4140 Amp=0 Err=00 Col=02 Prg=F Ins=0 Post=0 Stim=1 LowP=0 LowB=0 Sess=0 Buzz=1 0> WDT: enable 1 0> 0:00:01.556 STIM EVENT: DEVICE FOUND 0> 0:00:01.556 STIM STATE: VERIFYING 0> SD: 26 BLE_GAP_EVT_ADV_SET_TERMINATED 0> 0:00:02.092 Detected Device ID=x00000325 (not registered) 0> 0:00:02.093 Registered trim data not found. 0> 0:00:02.094 Connected to device x00000325 0> 0:00:02.095 STIM EVENT: IPG CONNECTED 0> 0:00:02.095 STIM STATE: CONNECTED IDLE 0> Unregister TTAP: handler not found: x45435 0> 0:00:02.140 ADV: Sys=FFFFFFFF Dev=0 VBat=4097 Amp=0 Err=00 Col=02 Prg=F Ins=3 Post=0 Stim=2 LowP=0 LowB=0 Sess=0 Buzz=1 0> SD: 26 BLE_GAP_EVT_ADV_SET_TERMINATED 0> BootLoader Ver 6 (INSTALLED) 0> Mfg Data Ver 4 0> Sys Config Ver 10 0> API Versions OK 0> Bluetooth Enabled 0> UART Enabled 0> Stimulation Enabled 0> Acceleration Disabled (0) 0> Force Error Disabled (0) 0> Electrode Map Field 8 Contact 0> Reboot Reason Watchdog Timeout (Bootloader) 0> 0> wdt_register_long_timer: 2 for 191177 0> BLE: Local BDADDR xEFF00F3689C3 0> wdt_register_long_timer: 0 for 242305 0> 0:00:01.432 PWR: Entering normal power 0> WDT: enable 0 0> Register TTAP: added handler[0]=x2C59D 0> WDT: enable 0 0> 0:00:01.435 STIM STATE: SEARCHING 0> 0:00:01.436 ADV: Sys=FFFFFFFF Dev=0 VBat=4145 Amp=0 Err=00 Col=02 Prg=F Ins=0 Post=0 Stim=1 LowP=0 LowB=0 Sess=0 Buzz=1 0> WDT: enable 1 0> 0:00:01.549 STIM EVENT: DEVICE FOUND 0> 0:00:01.549 STIM STATE: VERIFYING 0> SD: 26 BLE_GAP_EVT_ADV_SET_TERMINATED 0> 0:00:02.085 Detected Device ID=x00000325 (not registered) 0> 0:00:02.086 Registered trim data not found. 0> 0:00:02.087 Connected to device x00000325 0> 0:00:02.088 STIM EVENT: IPG CONNECTED 0> 0:00:02.088 STIM STATE: CONNECTED IDLE 0> Unregister TTAP: handler not found: x45435 0> 0:00:02.133 ADV: Sys=FFFFFFFF Dev=0 VBat=4099 Amp=0 Err=00 Col=02 Prg=F Ins=3 Post=0 Stim=2 LowP=0 LowB=0 Sess=0 Buzz=1 0> SD: 26 BLE_GAP_EVT_ADV_SET_TERMINATED 0> 0:02:02.362 ADV: Sys=FFFFFFFF Dev=0 VBat=4062 Amp=0 Err=00 Col=02 Prg=F Ins=3 Post=0 Stim=2 LowP=0 LowB=0 Sess=0 Buzz=1 0> SD: 26 BLE_GAP_EVT_ADV_SET_TERMINATED 0> 0:03:02.426 ADV: Sys=FFFFFFFF Dev=0 VBat=4033 Amp=0 Err=00 Col=02 Prg=F Ins=3 Post=0 Stim=2 LowP=0 LowB=0 Sess=0 Buzz=1 0> SD: 26 BLE_GAP_EVT_ADV_SET_TERMINATED 0> 0:04:02.391 ADV: Sys=FFFFFFFF Dev=0 VBat=4005 Amp=0 Err=00 Col=02 Prg=F Ins=3 Post=0 Stim=2 LowP=0 LowB=0 Sess=0 Buzz=1 0> SD: 26 BLE_GAP_EVT_ADV_SET_TERMINATED 0> SD: 10 BLE_GAP_EVT_CONNECTED 0> BLE: Remote x087190696FE9 0> NCE: bd_addr1 xEFF00F3689C3 0> NCE: bd_addr2 x087190696FE9 0> BLE: GAP connected. Unauthenticated timer restarted 0> SD: 23 BLE_GAP_EVT_DATA_LENGTH_UPDATE_REQUEST 0> 0:07:00.134 ADV: Sys=FFFFFFFF Dev=0 VBat=4005 Amp=0 Err=00 Col=02 Prg=F Ins=3 Post=0 Stim=2 LowP=0 LowB=0 Sess=0 Buzz=1 0> SD: 26 BLE_GAP_EVT_ADV_SET_TERMINATED 0> 0:07:29.636 BLE: Inactivity timeout. Connection Lockout timer started 0> SD: 3B 0> BLE_GATTC_EVT_TIMEOUT 0> WDT Event 0x0000000000000000 0> WDT Channel 0 0x0000000800070889 0> WDT Channel 1 0x0000000800070854 0> WDT Channel 2 0x0000000800070553 0> WDT Thread 3 0> 0> wdt_register_long_timer: 1 for 200165 0> 0> REBOOT (9) 0> Bluetooth Name NM04-000008 0> Board Type D045 0> Model Type ETM 0> FPGA Ver Model 4 Version 4 0> Firmware Ver 1.8.330 0> Firmware Type FIELD_BLE_UART 0> SoftDevice Ver 6.1.0 0> BootLoader Ver 6 (INSTALLED) 0> Mfg Data Ver 4 0> Sys Config Ver 10 0> API Versions OK 0> Bluetooth Enabled 0> UART Enabled 0> Stimulation Enabled 0> Acceleration Disabled (0) 0> Force Error Disabled (0) 0> Electrode Map Field 8 Contact 0> Reboot Reason Watchdog Timeout (Bootloader)
Hi Mark,
thanks for the trace. I forgot to ask which S132 version are you using? Looking at the trace its pretty clear that the nRF is not replying to the LL_LENGTH_REQ.
Can you confirm that sd_ble_gap_data_length_update() returns NRF_SUCCESS when its called on the BLE_GAP_EVT_DATA_LENGTH_UPDATE_REQUEST event? I assume that you do not get the BLE_GAP_EVT_DATA_LENGTH_UPDATE event after calling sd_ble_gap_data_length_update()?
I also noticed that things break when its the nRF that sends the MTU Exchange Request, but when the Intel device( Central) initiates the MTU Exchange, then things proceed as normal.
Comparing 0743.hp pavilion large mtu 02-25-20.pcapng with default mtu size.pcapng, I cant really see why the nRF does not respond to the LL_LENGTH_REQ in the 0743.hp pavilion large mtu 02-25-20.pcapng when it does this in the default mtu size.pcapn. The LL PDU order is exactly the same in both traces.
Is this behavior 100% consistent, i.e. if you leave set the ATT MTU size higher than the default value then the negotiation Data length or ATT MTU negotioation halts every time?
Could you try to add an even longer delay in on_connected_evt() just before the call to sd_ble_gattc_exchange_mtu_request()? Like a full second or more? We want to see if the nRF replies to the LL_LENGTH_REQ then and if the Intel device then initiates the MTU Exchange procedure.
Hi Mark,
thanks for the trace. I forgot to ask which S132 version are you using? Looking at the trace its pretty clear that the nRF is not replying to the LL_LENGTH_REQ.
Can you confirm that sd_ble_gap_data_length_update() returns NRF_SUCCESS when its called on the BLE_GAP_EVT_DATA_LENGTH_UPDATE_REQUEST event? I assume that you do not get the BLE_GAP_EVT_DATA_LENGTH_UPDATE event after calling sd_ble_gap_data_length_update()?
I also noticed that things break when its the nRF that sends the MTU Exchange Request, but when the Intel device( Central) initiates the MTU Exchange, then things proceed as normal.
Comparing 0743.hp pavilion large mtu 02-25-20.pcapng with default mtu size.pcapng, I cant really see why the nRF does not respond to the LL_LENGTH_REQ in the 0743.hp pavilion large mtu 02-25-20.pcapng when it does this in the default mtu size.pcapn. The LL PDU order is exactly the same in both traces.
Is this behavior 100% consistent, i.e. if you leave set the ATT MTU size higher than the default value then the negotiation Data length or ATT MTU negotioation halts every time?
Could you try to add an even longer delay in on_connected_evt() just before the call to sd_ble_gattc_exchange_mtu_request()? Like a full second or more? We want to see if the nRF replies to the LL_LENGTH_REQ then and if the Intel device then initiates the MTU Exchange procedure.
The sd_ble_gap_data_length_update() was not being called because it was in the wrong place in the code. We still printed the fact that we received the BLE_GAP_EVT_DATA_LENGTH_UPDATE_REQUEST in the log. Now that we are calling sd_ble_gap_data_length_update() in response to the BLE_GAP_EVT_DATA_LENGTH_UPDATE_REQUEST the negotiations are working and we can make a connection and transfer our file over DFU. Thanks
