disconnecting while operations are in progress never gives BLE_GAP_EVT_DISCONNECTED event

[Paul Bradford]

2020-01-24-092119EST-ProductStoppedGettingEventsFromNordicDK.txtImprivataTestNordicEventsNotReceived.zipCalls_to_pc_ble_driver.cpp0285.2020-02-24-TestProgramUploadedToNordicSupport.zipFeb25TestProgramUploadedToNordicSupport.zipImprivata_bgTestApp.zipbgSDKTestAppMay4.zip2020-05-05-035347-NordicDK_USB840M_200505_ClockInternal_2in1.hex.txt.txtbgSDKTestAppMay6.zipI’m developing an application based on pc-ble-driver to talk to an nRF52840-based dongle (from Fanstel).

I’m having trouble disconnecting cleanly when a connection has operations in progress.  For example, I call ‘sd_ble_gattc_write’, which returns NRF_SUCCESS, but I don’t receive event BLE_GATTC_EVT_WRITE_RSP (after waiting 60 seconds), so I decide to disconnect. When this happens, sd_ble_gap_disconnect returns NRF_SUCCESS, but I do not receive BLE_GAP_EVT_DISCONNECTED even after waiting 30 seconds. The connection supervision timeout is 4 seconds.  What could cause the disconnect to not generate any BLE_GAP_EVT_DISCONNECTED event?

What I’m trying to accomplish here: if a connection is not responsive, I want to end that connection, without disturbing other connections I have open.

Thanks,

Paul Bradford

[Paul Bradford]

I have created a test program that reproduces this problem: failure to receive events after a write or read request.  I have posted test program ImprivataTestNordicEventsNotReceived.zip and the main source file NordicTest-pc-ble-driver.cpp.   My intention is that you use the test program binaries, as described in the README.txt n the zip file. I included the source just so you can see what I'm doing, but I didn't include all headers to make it buildable.

[Jørgen Holmefjord]

Thanks for providing the example and detailed instructions. I have managed to run the test, and I have observed a few errors:

2020-02-05 17:18:11.814: sd_ble_gattc_read failed during characteristic_metadata_discovery_start error 0x0008 NRF_ERROR_INVALID_STATE, conn_handle = 0
2020-02-05 17:20:07.410: current GATTC read/write timed out
2020-02-05 17:20:07.410: sd_ble_gattc_read to keep connection alive got BLE_GATTC_EVT_TIMEOUT (which is allowable), so we must disconnect
2020-02-05 17:20:07.439: ERROR: sd_ble_gap_disconnect failed handle 0 error 0x3002 BLE_ERROR_INVALID_CONN_HANDLE
2020-02-05 17:20:43.446: current GATTC read/write timed out
2020-02-05 17:20:43.446: sd_ble_gattc_read to keep connection alive got BLE_GATTC_EVT_TIMEOUT (which is allowable), so we must disconnect
2020-02-05 17:20:43.507: ERROR: sd_ble_gap_disconnect failed handle 0 error 0x3002 BLE_ERROR_INVALID_CONN_HANDLE
2020-02-05 17:22:03.067: current GATTC read/write timed out
2020-02-05 17:22:03.067: sd_ble_gattc_write for characteristic notification got BLE_GATTC_EVT_TIMEOUT (which is allowable), so we must disconnect
2020-02-05 17:22:06.154: sd_ble_gattc_read failed during characteristic_metadata_discovery_start error 0x0008 NRF_ERROR_INVALID_STATE, conn_handle = 0
2020-02-05 17:22:39.167: current GATTC read/write timed out
2020-02-05 17:22:39.167: sd_ble_gattc_read to keep connection alive got BLE_GATTC_EVT_TIMEOUT (which is allowable), so we must disconnect
2020-02-05 17:22:39.254: ERROR: sd_ble_gap_disconnect failed handle 0 error 0x3002 BLE_ERROR_INVALID_CONN_HANDLE

I'm not sure if any of these are related to the issues you are seeing? How long does it normally take before the issue occurs with a single connection?

[Paul Bradford]

No, those errors are not related to the issue. If I run several copies of the test program on different Windows machines contacting the same peripheral (Android phone), it usually happens on at least one of them within a few hours. That's in my company's office, where there is a lot of BLE traffic due to lots of smart phones. When I ran it at my home, where there are only two smart phones in the vicinity, it ran for a day and a half without reproducing the problem.

[Paul Bradford]

I suggest you run multiple copies of the test program on the same WIndows 10 machine. Plug in 3 or 4 nRF52840 USB devices, open 3 or 4 command prompts, and run the test program from from each, with different -COMx command-line parameters. I had been running one copy and it didn't repro overnight. I ran three copies, and it happened on two of them in less than an hour.

[Paul Bradford]

I have now reproduced this problem several times in a very quiet BLE environment (my home).  I plug in in 3 nRF52840 USB devices into one Windows 10 computer, run 3 copies of the test program, all using the UUID of the one Android phone set up as a peripheral. Within a few hours, 2 or 3 have reproduced the problem.

[LeoChen]

I installed 4 dongle and captures the log.

The PC tool output  "never got BLE_GATT_EVT_WRITE_RSP ...." after three hour test.

Attached the log and screenshot.

The last WRITE event on line 7866.

SD_BLE_GATTC_WRITE #7866
BLE_GAP_EVT_DISCONNECTED #7874

BLE_GAP_EVT_CONNECTED #8432
BLE_GAP_EVT_DISCONNECTED #8460

Hope this log can do some help.

Log200212.log

[Jørgen Holmefjord]

Do you always see a DISCONNECTED event after the READ/WRITE when the RSP event is not received? I too am seeing this in my tests, and in this case, I would not expect the softdevice to give any more events for this connection. I can double-check this with the softdevice team if this is the case.

I see the disconnected reason being set to 8 (BLE_HCI_CONNECTION_TIMEOUT) in my tests.

[Paul Bradford]

You're responding to Leo Chen's comment, but I'll add my observations: In my Jan. 22 comment I wrote "I never receive another event for that connection, as shown by USB capture." So after I do a write (or a read), I do not get an event to end that write (or read). In the product, I go ahead and call sd_ble_gap_disconnect, but never receive the disconnect event.   Once I get in this state, I don't receive any more events. (In the test program I don't bother to call sd_ble_gap_disconnect, I exit as soon as the error is detected).

[Jørgen Holmefjord]

Ok, in that case, I do not think I have managed to reproduce the issue properly at all. When I get the error and your program exits, I still see a lot of scan/advertising and events happening in the log (I guess for the next 65 seconds until the error is detected).

I will keep working on it and see if I can get into the state you are describing.

[LeoChen]

When I am using SamSung S7 to test.

I always got the similar result.

The READ/WRITE, then far end disconnected after couple hour testing.

The tool exit after 1 minute later.

I bough a new SamSung Note 10 to test.

I can't reproduce this problem with Note 10 so far.

I installed 6 dongle and running about 20 hours testing.

The difference is Note 10 has more powerful CPU maybe can handle more connection at the same time.

I need to find other phones to compare.

Still trying.

Paul, Would you please also upload your log to Nordic to analysis.