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 attached a new test program Imprivata_bgTestApp.zip. There is a file called README with instructions, and a description of the problem.   I suggest you try this on a Dell 64-bit Windows 10 laptop that has not had Nordic dev tools installed on it. Usually the problem occurs with in an hour or two.

This test program reproduces the problem on two 64-bit Windows 10 laptops and does not reproduce this on one 64-bit Windows 10 laptop. I don't know what difference between these laptops causes two to fail and one to succeed. All have the same driver usbser.sys 10.0.18362.1 winbuild 160101.0800. Problem has occurred when plugged into USB 2.0 and USB 3.0 ports.

Failing laptops: both Dell, one Windows 10 version 1903 build 18362.657, another Windows 10 version 1909 build 18363.752 (the latest public Windows 10 build)

Laptop that does not reproduce the problem: Lenovo ThinkPad, Windows 10 version 1903 build 18362.657 (exactly the same as one failing laptop). This one has had Nordic tools like nRF Connect installed. One consequence is that when I plugged in an nRF52840 it would show in Device Manager as 'nRF Connect USB CDC ACM (COMx)'. To make it like my other laptops that do not have Nordic tools, I uninstalled the driver so that the nRF52840 would show up as 'USB Serial Device (COMx)'

[Jørgen Holmefjord]

I have had the new application running on my PC with 5 parallel devices for 8 hours yesterday and 4 hours today. So far, I have not been able to reproduce the issue. I do have another PC that does not have Nordic tools installed, but this is not a Dell PC. I will try to setup the test on that one next. It's a bit harder to find equipment for testing this with the limited factors where you have managed to reproduce the issue, due most of us working from home-office due to the Corona situation. Is it still a requirement to have heavy Bluetooth activity around the device in order to reproduce the issue? This could also be a problem to facilitate during home-office.

[Jørgen Holmefjord]

Hi Paul,

The "Erase & write" function should not be available if you program the nRF52840 Dongle (PCA10059) through the USB port of the dongle. Did you connect a J-Link debugger to program the dongle through SWD? If you did a "Erase all" operation through the SWD interface, the Bootloader that comes with the dongle will have been erased. "Erase all" operations will erase all programmable flash, including UICR registers.

The MBR is part of the softdevice-hex. It will always be present whenever the softdevice is flashed to the chip. You can read more about that in the softdevice specifications.

Paul Bradford said:

So far, using these dev-dongles and new firmware, I have still seen the original 'no event' problem on two computers.

 Do you mean with the firmware with increased scheduler queue size or the one with only critical region fix?

Best regards,
Jørgen

[Paul Bradford]

I've still seen the problem using connectivity_4.1.1_usb_with_s140_6.1.1_critical_region_fix_increased_sched_queue_size.hex

[Paul Bradford]

You mentioned "UART logging". I don't know how to do that.  The only type of firmware logging I've used was with RTT Viewer and the DK. I don't know how to do logging with the dev-dongle.

[Jørgen Holmefjord]

Right, UART logging will only be available on the DK. If you are able to reproduce on a DK, please provide the logs. You can read the UART logs using a terminal software (Putty, Tera Term, RealTerm, Termite, etc). You may also be able to read UART logs from the Dongle by connecting a wire to the DK, but this would require the logging to use a different pin for UART, as the default UART TX pin is not routed out on the Dongle.

[Paul Bradford]

I'm trying to reproduce the problem with the DK. How do I get the UART output?  That shows up as JLink CDC UART Port (COM8). So if I open COM8 with Putty I should see debug output, but I see nothing. Does the baud rate matter? If so, what is it?

But if it is set to only show errors, then maybe I haven't encountered an error yet. But I don't know if I'm properly attached to the COM port.

[LeoChen]

I increased sched queue_size, enabled UART log and compiler agian.

I have  make sure the UART log has output with this BT840_USBconnectivity200430.hex.

https://www.dropbox.com/s/yqkcn95qrwto6g7/BT840_USBconnectivity200430.rar?dl=0

[Paul Bradford]

I've been testing with the firmware file "USB840_Connect200430_3in1.hex" from the DropBox link that Leo from Fanstel referenced in the support case on April 29. This firmware has the critical section fix described by Nordic on April 24, and the queue size 64 change.

With this firmware, I get errors quickly with the Fanstel dongle and Nordic dev-dongle, and after 17 hours with the Nordic Development Kit. 

Reproduced event loss problem with Nordic Development Kit on May 2 at about 8 AM eastern daylight time, after running for over 17 hours.
Test program "2020-05-02 08:02:15.759: (ERROR) no Nordic event  BLE_GATTC_EVT_WRITE_RSP  was received to complete the call to sd_ble_gattc_write"

The dropbox link below has USB trace using USBPcap and PuTTY serial port logging from the Development Kit.

The PuTTY output looks normal to me until the very end:
[00:00:58.343,695] <error> app: Fatal error
[00:00:58.710,920] <info> app: BLE connectivity 200427

www.dropbox.com/.../May2ReproNordicDK.zip

[LeoChen]

The Fanstel USB840M does not have 32K crystal.

The clock setting is different.

I change the clock setting back to default.

The application should all the same as patched SDK.

The changed were add CRITICAL_REGION_ENTER/ CRITICAL_REGION_EXIT and Scheduler queue size increase to 64.

These files can't work with USB840M.

Application + softdevice

https://www.dropbox.com/s/u77p0ub617i786e/USB840_Clock_ACCURACY_2in1.hex?dl=0

 

Application + bootloader + softdevice

https://www.dropbox.com/s/pg2hzhorhlivdoo/USB840_Clock_ACCURACY_3in1.hex?dl=0

Would you please also try these files on Nordic dongle and DK.

Leo

[Paul Bradford]

I tested the USB840_Clock_ACCURACY_3in1.hex file referenced in Leo's last post. I loaded it on the Nordic DK by dragging it to the "JLink CDC UART Port". After just a few minutes my test program got the "serial port write operation" error "The device does not recognize the command". The firmware logging over that JLink port looked the same as what I uploaded on May 2 (which was also the DK and used firmware "USB840_Connect200430_3in1.hex" ):

[00:00:13.056,233] <debug> app: event:BLE_GAP_EVT_RSSI_CHANGED

[00:00:13.061,999] <debug> sphy_hci: TX request (7 bytes)

[00:00:13.067,421] <debug> sphy_hci: Started TX packet (payload 7).

[00:00:13.074,211] <error> app: Fatal error

[00:00:13.441,628] <info> app: BLE connectivity 200427

[00:00:13.447,435] <info> app: USB power detected

[00:00:13.453,251] <info> app: USB ready

I have not been able to test this firmware with the Nordic dev-dongle. I tried loading USB840_Clock_ACCURACY_3in1.hex into the dev-dongle using nRF Connect Programmer, but that leaves the dev-dongle in a state where it does not show up as a serial port when I plug it in. If there is some other way I should try to program it, please let me know.

[Paul Bradford]

I uploaded a modified test program. The change is to have a command-line option to say how often to do the challenge/response, which is what triggers the notifications from the phone, which is what we suspect is causing this problem.   With no option, this is done every 5 minutes. I've been testing with new command-line option -f5 which means to do it every 5 seconds.