I am working on firmware that acts as a BLE sensor hub to pipe BLE data from connected sensors to a PC over USB (using the CDC ACM UART interface). The peripheral sensors ship data to the hub via the NUS service. The hub implementation works perfectly on the nRF52840-DK and nRF5340-DK, but when I try to flash the same firmware to the Thingy:53 I run into an issue where the device takes a long time (30s to over a minute) to establish a BLE connection with the sensor, constantly disconnecting with a message saying it couldn't find the NUS service. This doesn't happen on the nRF5340-DK, which I figured should be comparable, or the nRF52840-DK. I looked around at the board configurations for the DK and the Thingy but I didn't see anything glaringly obvious that should affect the performance. I actually would have expected an improvement with the better FEM on the thingy, but that has not been the case.
Any ideas what is going on? The project configuration is here, with the hci_ipc config here.
And below is a sample log. You see after connecting it has GATT issues. In general the BLE connectivity also doesn't seem to be very reliable, on this run when it finally connected it wasn't actually receiving any data, and when I turned the peripheral sensor off it thought it was still connected for at least ten minutes before I turned it off. I should mention that this firmware runs reliably for multiple sensors on custom nRF52832 and nRF52840 devices, as well as the nRF5340-DK, which is maybe why I'm having some trouble tracking down why the Thingy is behaving differently.
SEGGER J-Link V7.94e - Real time terminal output
SEGGER J-Link (unknown) V1.0, SN=1050238983
Process: JLinkExe
*** Booting nRF Connect SDK 3758bcbfa5cd ***
[00:00:00.002,441] <inf> posey_platform: Initializing platform...
[00:00:00.002,441] <inf> posey_platform: Initializing CDC ACM...
[00:00:00.502,655] <inf> posey_platform: Initializing NUS...
[00:00:00.502,655] <inf> posey_nus: Initializing BLE and NUS...
[00:00:00.509,399] <inf> fs_nvs: 8 Sectors of 4096 bytes
[00:00:00.509,399] <inf> fs_nvs: alloc wra: 0, fd0
[00:00:00.509,399] <inf> fs_nvs: data wra: 0, 1c
[00:00:00.525,695] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
[00:00:00.525,726] <inf> bt_hci_core: HW Variant: nRF53x (0x0003)
[00:00:00.525,756] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 54.58864 Build 1214809870
[00:00:00.526,824] <inf> bt_hci_core: No ID address. App must call settings_load()
[00:00:00.526,824] <inf> posey_nus: Bluetooth initialized
[00:00:00.528,076] <inf> bt_hci_core: Identi[00:00:21.616,241] <inf> posey_task_hub: Connected sensors: 0
[00:00:31.659,454] <inf> posey_task_hub: Connected sensors: 0
[00:00:37.745,178] <inf> posey_nus: NordicNUSDriver::scan_filter_match
[00:00:37.745,391] <inf> posey_nus: Filters matched. Name: Posey r2405 Lily (slot 1) Address: D6:81:5C:04:F1:2E (random) connectable: 1
[00:00:37.746,520] <inf> posey_nus: scan_connecting
[00:00:37.853,363] <inf> posey_nus: NordicNUSDriver::connected
[00:00:37.853,515] <inf> posey_nus: Name: Posey r2405 Lily
[00:00:37.853,546] <inf> posey_nus: Connected to Posey r2405 Lily at D6:81:5C:04:F1:2E (random)
[00:00:37.853,637] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:37.853,637] <inf> posey_nus: NordicNUSDriver::gatt_discover
[00:00:37.853,668] <inf> posey_nus: Running NUS discovery for Posey r2405 Lily
[00:00:37.853,729] <inf> posey_nus: 1 of 4 sensors connected.
[00:00:38.054,504] <inf> posey_nus: MTU exchange done
[00:00:38.703,918] <inf> posey_nus: LE PHY updated: TX PHY LE 2M, RX PHY LE 2M
[00:00:38.954,376] <inf> posey_nus: NUS service discovery completed.
[00:00:38.954,559] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:38.954,559] <inf> posey_nus: BLE scanning: Connected to 1 sensors. Active scanning.
[00:00:41.698,547] <inf> posey_task_hub: Connected sensors: 1
[00:00:42.754,364] <inf> posey_nus: NordicNUSDriver::disconnected
[00:00:42.754,547] <wrn> posey_nus: Disconnected from Posey r2405 Lily at D6:81:5C:04:F1:2E (random) (reason: 13 - Unknown)
[00:00:42.754,577] <inf> posey_nus: 0 of 4 sensors connected.
[00:00:42.754,577] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:42.755,065] <inf> posey_nus: BLE scanning: Connected to 0 sensors. Active scanning.
[00:00:42.760,070] <inf> posey_nus: NordicNUSDriver::scan_filter_match
[00:00:42.760,253] <inf> posey_nus: Filters matched. Name: Posey r2405 Lily (slot 1) Address: D6:81:5C:04:F1:2E (random) connectable: 1
[00:00:42.761,840] <inf> posey_nus: scan_connecting
[00:00:42.975,219] <inf> posey_nus: NordicNUSDriver::connected
[00:00:42.975,372] <inf> posey_nus: Name: Posey r2405 Lily
[00:00:42.975,433] <inf> posey_nus: Connected to Posey r2405 Lily at D6:81:5C:04:F1:2E (random)
[00:00:42.975,524] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:42.975,524] <inf> posey_nus: NordicNUSDriver::gatt_discover
[00:00:42.975,555] <inf> posey_nus: Running NUS discovery for Posey r2405 Lily
[00:00:42.975,616] <inf> posey_nus: 1 of 4 sensors connected.
[00:00:43.176,361] <inf> posey_nus: MTU exchange done
[00:00:43.775,756] <inf> posey_nus: LE PHY updated: TX PHY LE 2M, RX PHY LE 2M
[00:00:44.076,232] <inf> posey_nus: NUS service discovery completed.
[00:00:44.076,416] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:44.076,416] <inf> posey_nus: BLE scanning: Connected to 1 sensors. Active scanning.
[00:00:44.276,214] <inf> posey_nus: NordicNUSDriver::disconnected
[00:00:44.276,397] <wrn> posey_nus: Disconnected from Posey r2405 Lily at D6:81:5C:04:F1:2E (random) (reason: 13 - Unknown)
[00:00:44.276,428] <inf> posey_nus: 0 of 4 sensors connected.
[00:00:44.276,428] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:44.276,947] <inf> posey_nus: BLE scanning: Connected to 0 sensors. Active scanning.
[00:00:44.283,325] <inf> posey_nus: NordicNUSDriver::scan_filter_match
[00:00:44.283,508] <inf> posey_nus: Filters matched. Name: Posey r2405 Lily (slot 1) Address: D6:81:5C:04:F1:2E (random) connectable: 1
[00:00:44.285,064] <inf> posey_nus: scan_connecting
[00:00:44.495,849] <inf> posey_nus: NordicNUSDriver::connected
[00:00:44.496,002] <inf> posey_nus: Name: Posey r2405 Lily
[00:00:44.496,063] <inf> posey_nus: Connected to Posey r2405 Lily at D6:81:5C:04:F1:2E (random)
[00:00:44.496,154] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:44.496,154] <inf> posey_nus: NordicNUSDriver::gatt_discover
[00:00:44.496,185] <inf> posey_nus: Running NUS discovery for Posey r2405 Lily
[00:00:44.496,246] <inf> posey_nus: 1 of 4 sensors connected.
[00:00:44.897,003] <inf> posey_nus: MTU exchange done
[00:00:45.096,801] <inf> posey_nus: NUS service discovery completed.
[00:00:45.096,832] <err> nus_c: Missing NUS TX characteristic.
[00:00:45.096,832] <err> nus_c: Subscribe failed (err -128)
[00:00:45.096,862] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:45.096,893] <inf> posey_nus: BLE scanning: Connected to 1 sensors. Active scanning.
[00:00:45.097,991] <inf> posey_nus: NordicNUSDriver::disconnected
[00:00:45.098,205] <wrn> posey_nus: Disconnected from Posey r2405 Lily at D6:81:5C:04:F1:2E (random) (reason: 13 - Unknown)
[00:00:45.098,205] <inf> posey_nus: 0 of 4 sensors connected.
[00:00:45.098,205] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:45.098,693] <inf> posey_nus: BLE scanning: Connected to 0 sensors. Active scanning.
[00:00:45.529,907] <inf> posey_nus: NordicNUSDriver::scan_filter_match
[00:00:45.530,120] <inf> posey_nus: Filters matched. Name: Posey r2405 Lily (slot 1) Address: D6:81:5C:04:F1:2E (random) connectable: 1
[00:00:45.531,677] <inf> posey_nus: scan_connecting
[00:00:45.846,221] <inf> posey_nus: NordicNUSDriver::connected
[00:00:45.846,374] <inf> posey_nus: Name: Posey r2405 Lily
[00:00:45.846,435] <inf> posey_nus: Connected to Posey r2405 Lily at D6:81:5C:04:F1:2E (random)
[00:00:45.846,496] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:45.846,527] <inf> posey_nus: NordicNUSDriver::gatt_discover
[00:00:45.846,557] <inf> posey_nus: Running NUS discovery for Posey r2405 Lily
[00:00:45.846,588] <inf> posey_nus: 1 of 4 sensors connected.
[00:00:46.047,363] <inf> posey_nus: MTU exchange done
[00:00:46.597,167] <err> bt_gatt_dm: Characteristic discover failed, error: -128.
[00:00:46.597,229] <wrn> posey_nus: Error while discovering GATT service: (-128 - )
[00:00:46.597,320] <inf> posey_nus: NordicNUSDriver::disconnected
[00:00:46.597,534] <wrn> posey_nus: Disconnected from Posey r2405 Lily at D6:81:5C:04:F1:2E (random) (reason: 13 - Unknown)
[00:00:46.597,564] <inf> posey_nus: 0 of 4 sensors connected.
[00:00:46.597,564] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:46.597,595] <inf> posey_nus: BLE scanning: Connected to 0 sensors. Active scanning.
[00:00:46.610,626] <inf> posey_nus: NordicNUSDriver::scan_filter_match
[00:00:46.610,809] <inf> posey_nus: Filters matched. Name: Posey r2405 Lily (slot 1) Address: D6:81:5C:04:F1:2E (random) connectable: 1
[00:00:46.612,396] <inf> posey_nus: scan_connecting
[00:00:46.717,254] <inf> posey_nus: NordicNUSDriver::connected
[00:00:46.717,437] <inf> posey_nus: Name: Posey r2405 Lily
[00:00:46.717,468] <inf> posey_nus: Connected to Posey r2405 Lily at D6:81:5C:04:F1:2E (random)
[00:00:46.717,559] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:46.717,559] <inf> posey_nus: NordicNUSDriver::gatt_discover
[00:00:46.717,590] <inf> posey_nus: Running NUS discovery for Posey r2405 Lily
[00:00:46.717,651] <inf> posey_nus: 1 of 4 sensors connected.
[00:00:47.018,402] <inf> posey_nus: MTU exchange done
[00:00:47.567,810] <inf> posey_nus: LE PHY updated: TX PHY LE 2M, RX PHY LE 2M
[00:00:47.718,200] <inf> posey_nus: NUS service discovery completed.
[00:00:47.718,231] <err> nus_c: Missing NUS TX characteristic.
[00:00:47.718,231] <err> nus_c: Subscribe failed (err -128)
[00:00:47.718,261] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:47.718,261] <inf> posey_nus: BLE scanning: Connected to 1 sensors. Active scanning.
[00:00:47.719,329] <inf> posey_nus: NordicNUSDriver::disconnected
[00:00:47.719,543] <wrn> posey_nus: Disconnected from Posey r2405 Lily at D6:81:5C:04:F1:2E (random) (reason: 13 - Unknown)
[00:00:47.719,543] <inf> posey_nus: 0 of 4 sensors connected.
[00:00:47.719,543] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:47.720,062] <inf> posey_nus: BLE scanning: Connected to 0 sensors. Active scanning.
[00:00:50.871,154] <inf> posey_nus: NordicNUSDriver::scan_filter_match
[00:00:50.871,368] <inf> posey_nus: Filters matched. Name: Posey r2405 Lily (slot 1) Address: D6:81:5C:04:F1:2E (random) connectable: 1
[00:00:50.872,924] <inf> posey_nus: scan_connecting
[00:00:50.982,574] <inf> posey_nus: NordicNUSDriver::connected
[00:00:50.982,727] <inf> posey_nus: Name: Posey r2405 Lily
[00:00:50.982,788] <inf> posey_nus: Connected to Posey r2405 Lily at D6:81:5C:04:F1:2E (random)
[00:00:50.982,849] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:50.982,879] <inf> posey_nus: NordicNUSDriver::gatt_discover
[00:00:50.982,910] <inf> posey_nus: Running NUS discovery for Posey r2405 Lily
[00:00:50.982,940] <inf> posey_nus: 1 of 4 sensors connected.
[00:00:51.183,715] <inf> posey_nus: MTU exchange done
[00:00:51.738,464] <inf> posey_task_hub: Connected sensors: 1
[00:00:51.883,361] <inf> posey_nus: LE PHY updated: TX PHY LE 2M, RX PHY LE 2M
[00:00:51.883,666] <err> bt_gatt_dm: Characteristic discover failed, error: -128.
[00:00:51.883,728] <wrn> posey_nus: Error while discovering GATT service: (-128 - )
[00:00:51.883,819] <inf> posey_nus: NordicNUSDriver::disconnected
[00:00:51.884,002] <wrn> posey_nus: Disconnected from Posey r2405 Lily at D6:81:5C:04:F1:2E (random) (reason: 13 - Unknown)
[00:00:51.884,002] <inf> posey_nus: 0 of 4 sensors connected.
[00:00:51.884,033] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:51.884,033] <inf> posey_nus: BLE scanning: Connected to 0 sensors. Active scanning.
[00:00:51.894,226] <inf> posey_nus: NordicNUSDriver::scan_filter_match
[00:00:51.894,439] <inf> posey_nus: Filters matched. Name: Posey r2405 Lily (slot 1) Address: D6:81:5C:04:F1:2E (random) connectable: 1
[00:00:51.895,996] <inf> posey_nus: scan_connecting
[00:00:52.004,302] <inf> posey_nus: NordicNUSDriver::connected
[00:00:52.004,455] <inf> posey_nus: Name: Posey r2405 Lily
[00:00:52.004,486] <inf> posey_nus: Connected to Posey r2405 Lily at D6:81:5C:04:F1:2E (random)
[00:00:52.004,577] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:52.004,577] <inf> posey_nus: NordicNUSDriver::gatt_discover
[00:00:52.004,608] <inf> posey_nus: Running NUS discovery for Posey r2405 Lily
[00:00:52.004,669] <inf> posey_nus: 1 of 4 sensors connected.
[00:00:52.255,432] <inf> posey_nus: MTU exchange done
[00:00:52.804,809] <inf> posey_nus: LE PHY updated: TX PHY LE 2M, RX PHY LE 2M
[00:00:53.055,297] <inf> posey_nus: NUS service discovery completed.
[00:00:53.055,480] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:53.055,480] <inf> posey_nus: BLE scanning: Connected to 1 sensors. Active scanning.
[00:00:53.160,552] <inf> posey_nus: Slot 0 bandwidth: 12797 B in 14.10s - 0.89 KBps
[00:00:53.405,303] <inf> posey_nus: NordicNUSDriver::disconnected
[00:00:53.405,517] <wrn> posey_nus: Disconnected from Posey r2405 Lily at D6:81:5C:04:F1:2E (random) (reason: 13 - Unknown)
[00:00:53.405,517] <inf> posey_nus: 0 of 4 sensors connected.
[00:00:53.405,517] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:53.406,036] <inf> posey_nus: BLE scanning: Connected to 0 sensors. Active scanning.
[00:00:53.418,060] <inf> posey_nus: NordicNUSDriver::scan_filter_match
[00:00:53.418,243] <inf> posey_nus: Filters matched. Name: Posey r2405 Lily (slot 1) Address: D6:81:5C:04:F1:2E (random) connectable: 1
[00:00:53.419,616] <inf> posey_nus: scan_connecting
[00:00:54.966,156] <inf> posey_nus: NordicNUSDriver::connected
[00:00:54.966,308] <inf> posey_nus: Name: Posey r2405 Lily
[00:00:54.966,369] <inf> posey_nus: Connected to Posey r2405 Lily at D6:81:5C:04:F1:2E (random)
[00:00:54.966,430] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:54.966,461] <inf> posey_nus: NordicNUSDriver::gatt_discover
[00:00:54.966,491] <inf> posey_nus: Running NUS discovery for Posey r2405 Lily
[00:00:54.966,522] <inf> posey_nus: 1 of 4 sensors connected.
[00:00:55.167,266] <inf> posey_nus: MTU exchange done
[00:00:55.766,693] <inf> posey_nus: LE PHY updated: TX PHY LE 2M, RX PHY LE 2M
[00:00:55.867,065] <err> bt_gatt_dm: Characteristic discover failed, error: -128.
[00:00:55.867,126] <wrn> posey_nus: Error while discovering GATT service: (-128 - )
[00:00:55.867,218] <inf> posey_nus: NordicNUSDriver::disconnected
[00:00:55.867,401] <wrn> posey_nus: Disconnected from Posey r2405 Lily at D6:81:5C:04:F1:2E (random) (reason: 13 - Unknown)
[00:00:55.867,431] <inf> posey_nus: 0 of 4 sensors connected.
[00:00:55.867,431] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:55.867,431] <inf> posey_nus: BLE scanning: Connected to 0 sensors. Active scanning.
[00:00:56.194,580] <inf> posey_nus: NordicNUSDriver::scan_filter_match
[00:00:56.194,763] <inf> posey_nus: Filters matched. Name: Posey r2405 Lily (slot 1) Address: D6:81:5C:04:F1:2E (random) connectable: 1
[00:00:56.196,319] <inf> posey_nus: scan_connecting
[00:00:56.507,629] <inf> posey_nus: NordicNUSDriver::connected
[00:00:56.507,781] <inf> posey_nus: Name: Posey r2405 Lily
[00:00:56.507,843] <inf> posey_nus: Connected to Posey r2405 Lily at D6:81:5C:04:F1:2E (random)
[00:00:56.507,904] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:56.507,934] <inf> posey_nus: NordicNUSDriver::gatt_discover
[00:00:56.507,965] <inf> posey_nus: Running NUS discovery for Posey r2405 Lily
[00:00:56.507,995] <inf> posey_nus: 1 of 4 sensors connected.
[00:00:56.708,831] <inf> posey_nus: MTU exchange done
[00:00:57.308,410] <inf> posey_nus: LE PHY updated: TX PHY LE 2M, RX PHY LE 2M
[00:00:57.308,715] <err> bt_gatt_dm: Characteristic discover failed, error: -128.
[00:00:57.308,776] <wrn> posey_nus: Error while discovering GATT service: (-128 - )
[00:00:57.308,868] <inf> posey_nus: NordicNUSDriver::disconnected
[00:00:57.309,051] <wrn> posey_nus: Disconnected from Posey r2405 Lily at D6:81:5C:04:F1:2E (random) (reason: 13 - Unknown)
[00:00:57.309,051] <inf> posey_nus: 0 of 4 sensors connected.
[00:00:57.309,082] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:57.309,082] <inf> posey_nus: BLE scanning: Connected to 0 sensors. Active scanning.
[00:00:57.743,408] <inf> posey_nus: NordicNUSDriver::scan_filter_match
[00:00:57.743,621] <inf> posey_nus: Filters matched. Name: Posey r2405 Lily (slot 1) Address: D6:81:5C:04:F1:2E (random) connectable: 1
[00:00:57.745,178] <inf> posey_nus: scan_connecting
[00:00:57.850,830] <inf> posey_nus: NordicNUSDriver::connected
[00:00:57.850,982] <inf> posey_nus: Name: Posey r2405 Lily
[00:00:57.851,043] <inf> posey_nus: Connected to Posey r2405 Lily at D6:81:5C:04:F1:2E (random)
[00:00:57.851,104] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:57.851,135] <inf> posey_nus: NordicNUSDriver::gatt_discover
[00:00:57.851,165] <inf> posey_nus: Running NUS discovery for Posey r2405 Lily
[00:00:57.851,226] <inf> posey_nus: 1 of 4 sensors connected.
[00:00:58.301,971] <inf> posey_nus: MTU exchange done
[00:00:58.851,379] <inf> posey_nus: LE PHY updated: TX PHY LE 2M, RX PHY LE 2M
[00:00:59.101,837] <inf> posey_nus: NUS service discovery completed.
[00:00:59.102,020] <inf> posey_nus: NordicNUSDriver::scan_stop
[00:00:59.102,020] <inf> posey_nus: BLE scanning: Connected to 1 sensors. Active scanning.
[00:00:59.256,774] <inf> posey_nus: Slot 0 bandwidth: 488 B in 6.10s - 0.08 KBps
[00:01:01.781,066] <inf> posey_task_hub: Connected sensors: 1
[00:01:11.823,089] <inf> posey_task_hub: Connected sensors: 1
[00:01:21.864,715] <inf> posey_task_hub: Connected sensors: 1
[00:01:31.906,951] <inf> posey_task_hub: Connected sensors: 1
[00:01:41.948,699] <inf> posey_task_hub: Connected sensors: 1
[00:01:51.991,638] <inf> posey_task_hub: Connected sensors: 1
[00:02:02.033,355] <inf> posey_task_hub: Connected sensors: 1
[00:02:12.075,256] <inf> posey_task_hub: Connected sensors: 1
[00:02:22.117,675] <inf> posey_task_hub: Connected sensors: 1
[00:02:32.161,804] <inf> posey_task_hub: Connected sensors: 1
