Hi ,
I have compiled in Heart rat relay into my app; can scan and connect to simulator and garmin HR straps; but fail to connect to polar.
My debug log shows...
So security is encryption, no auth and I get an "unspecified" error.
I have done a BLE wireshark trace; but cannot see anything in the trace to indicate the issue.
Would be grateful if someon could look and give me a clue to whats going wrong.
Here is wireshark trace....
polarHrmActiveScanConnectFail.pcapng
Regards,
Owain
Hi Owain,
Have you tried to test using the central_uart example to connect to the Polar ?
Do you use CONFIG_BT_SMP_SC_ONLY in your project configuration ?
This will force the pairing to only Secure Connection. It doesn't seem the Polar band support Secure Connection.
There is some discussion here with the same error BT_SECURITY_ERR_UNSPECIFIED and related to nRF53 and legacy pairing:
https://github.com/zephyrproject-rtos/zephyr/issues/37228
Could you try CONFIG_BT_TINYCRYPT_ECC=y to see if it work. Note that you may need to rebuild and reflash hci_rmsg
I would suggest to double check using nRF52 which doesn't seems to have this error.
Config for the App does not have CONFIG_BT_SMP_SC_ONLY set; and has CONFIG_BT_TINYCRYPT_ECC set.
I will attach the .config. Can you anything wrong in the BLE trace or does all look good?
The 37228 issue sounds pretty much like what I am getting....
0042.config.txt
Here more debug but with CONFIG_BT_DEBUG_SMP=y
033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:12.016,998] \033[0m<inf> app: connected: Central: connected to F0:C9:75:7D:CB:FF (random)
\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:12.017,059] \033[0m<inf> app: connected: security is currently 1
\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:12.017,150] \033[0m<dbg> bt_smp: smp_send_pairing_req: \033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:12.018,615] \033[0m<dbg> bt_smp: smp_init: prnd 2ec0d9a9193c2b1b54b14f14734e4279\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:12.018,768] \033[0m<inf> app: connected: security set to BT_SECURITY_L2
\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:12.020,782] \033[0m<inf> app: systemProcessThread: System got EVENT_BLE_PERIPHERAL_CONNECTED\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:12.517,974] \033[0m<dbg> bt_smp: bt_smp_recv: Received SMP code 0x02 len 6\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:12.518,035] \033[0m<dbg> bt_smp: smp_pairing_rsp: \033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:12.518,127] \033[0m<dbg> bt_smp: legacy_pairing_rsp: \033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:12.518,280] \033[0m<dbg> bt_smp: smp_c1: k 00000000000000000000000000000000\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:12.518,371] \033[0m<dbg> bt_smp: smp_c1: r 2ec0d9a9193c2b1b54b14f14734e4279\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:12.518,554] \033[0m<dbg> bt_smp: smp_c1: ia 40:68:15:E7:B9:37 (random)\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:12.518,737] \033[0m<dbg> bt_smp: smp_c1: ra F0:C9:75:7D:CB:FF (random)\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:12.518,829] \033[0m<dbg> bt_smp: smp_c1: preq 0100000d100707\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:12.518,890] \033[0m<dbg> bt_smp: smp_c1: pres 02030001100303\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:12.518,981] \033[0m<dbg> bt_smp: smp_c1: p1 01010100000d10070702030001100303\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:12.519,256] \033[0m<dbg> bt_smp: smp_c1: p2 ffcb7d75c9f037b9e715684000000000\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:13.018,035] \033[0m<dbg> bt_smp: bt_smp_recv: Received SMP code 0x03 len 16\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:13.018,127] \033[0m<dbg> bt_smp: smp_pairing_confirm: \033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:13.518,066] \033[0m<dbg> bt_smp: bt_smp_recv: Received SMP code 0x04 len 16\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:13.518,127] \033[0m<dbg> bt_smp: smp_pairing_random: \033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:13.518,188] \033[0m<dbg> bt_smp: legacy_pairing_random: \033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:13.518,280] \033[0m<dbg> bt_smp: smp_c1: k 00000000000000000000000000000000\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:13.518,371] \033[0m<dbg> bt_smp: smp_c1: r d316e0f3d51aaefd4c0a38df9f5ec1cb\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:13.518,554] \033[0m<dbg> bt_smp: smp_c1: ia 40:68:15:E7:B9:37 (random)\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:13.518,737] \033[0m<dbg> bt_smp: smp_c1: ra F0:C9:75:7D:CB:FF (random)\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:13.518,829] \033[0m<dbg> bt_smp: smp_c1: preq 0100000d100707\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:13.518,890] \033[0m<dbg> bt_smp: smp_c1: pres 02030001100303\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:13.519,012] \033[0m<dbg> bt_smp: smp_c1: p1 01010100000d10070702030001100303\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:13.519,287] \033[0m<dbg> bt_smp: smp_c1: p2 ffcb7d75c9f037b9e715684000000000\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:13.519,531] \033[0m<dbg> bt_smp: legacy_pairing_random: pcnf 2e7254e2fc169911f174a35f9f321152\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:13.519,622] \033[0m<dbg> bt_smp: legacy_pairing_random: cfm 2e7254e2fc169911f174a35f9f321152\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:28.018,096] \033[0m<dbg> bt_smp: bt_smp_disconnected: chan 0x20009bec cid 0x0006\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:28.018,188] \033[0m<dbg> bt_smp: smp_pairing_complete: status 0x8\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:28.024,200] \033[0m<dbg> bt_smp: bt_smp_encrypt_change: chan 0x20009bec conn 0x20009790 handle 0 encrypt 0x00 hci status 0x1f\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:28.024,261] \033[0m<dbg> bt_smp: smp_pairing_complete: status 0x8\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:28.024,444] \033[0m<inf> app: authPairingFailed: Pairing failed: F0:C9:75:7D:CB:FF (random) reason: 9
\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:28.024,719] \033[0m<inf> app: securityChanged: Security failed: F0:C9:75:7D:CB:FF (random) level 1 err 9
\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:28.024,780] \033[1;31m<err> bt_gatt_dm: bt_gatt_dm_start: Discover failed, error: -128.\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:28.024,841] \033[0m<inf> app: gatt_discover: Could not start the discovery procedure, error code: -128
\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:28.030,883] \033[0m<inf> app: disconnected: Peripheral disconnected (reason 0x08)
\033[0m
\033[1;32mnovaPro>\033[m\033[8D\033[J\033[1;32mnovaPro>\033[m\033[8D\033[J[00:01:28.031,372] \033[0m<inf> app: systemProcessThread: System got EVENT_BLE_PERIPHERAL_DISCONNECTED\033[0m
\
Hi Owain,
Have you tried to test using the central_uart example to connect to the Polar ?
Hi Hung,
central uart or central heart rate example?
Our device is both a central and a peripheral. One can connect from a mobile to manage our device; but it can connect to peripherals.
Looking at the central heartrate example it works quite differntly to the uart example; it also does not change the security level. Note the Garmin strap works fine changing level to 2.
Regards,
Owain
Hi Owain,
Sorry my mistake. My idea is to use central_uart because it has similar behavior as your application to require L2 when connected. But I forgot that it won't connect to the polar HR because it's different UUID.
What you can do is to change the scan_init() to filter the HRS UUID instead of the NUS UUID. The goal is to make it connect and pair to the Polar HR. You can remove any code related to NUS client.
I just want to have a very simple application that connect and pair and do nothing else. The prj.conf should be kept the same as in the sample. If it works we can try to compare it with your application to see what cause the issue.
Hi Owain,
Sorry my mistake. My idea is to use central_uart because it has similar behavior as your application to require L2 when connected. But I forgot that it won't connect to the polar HR because it's different UUID.
What you can do is to change the scan_init() to filter the HRS UUID instead of the NUS UUID. The goal is to make it connect and pair to the Polar HR. You can remove any code related to NUS client.
I just want to have a very simple application that connect and pair and do nothing else. The prj.conf should be kept the same as in the sample. If it works we can try to compare it with your application to see what cause the issue.
Hi Hung,
I have taken the uart example as you suggest; I have had to make some small changes to ensure HCI RPMSG is used rather than HCI H4.
This the outpu from the test on the console; looks that same as my own project; fails on the security change.
*** Booting Zephyr OS build v3.2.99-ncs1 *** [00:00:00.259,552] \033[0m<inf> fs_nvs: 2 Sectors of 4096 bytes\033[0m [00:00:00.259,552] \033[0m<inf> fs_nvs: alloc wra: 0, ec0\033[0m [00:00:00.259,552] \033[0m<inf> fs_nvs: data wra: 0, 154\033[0m [00:00:00.284,606] \033[0m<inf> bt_hci_core: No ID address. App must call settings_load()\033[0m [00:00:00.284,637] \033[0m<inf> central_hr: Bluetooth initialized\033[0m [00:00:00.286,254] \033[1;31m<err> settings: set-value failure. key: bt/name error(-2)\033[0m [00:00:00.287,139] \033[0m<inf> central_hr: Scan module initialized\033[0m Starting Bluetooth Central HR example [00:00:00.289,978] \033[0m<inf> central_hr: Scanning successfully started\033[0m [00:00:01.612,976] \033[0m<inf> central_hr: Filters matched. Address: E0:EF:E7:CA:6A:68 (random) connectable: 1\033[0m [00:00:02.115,417] \033[0m<inf> central_hr: Connected: E0:EF:E7:CA:6A:68 (random)\033[0m [00:00:02.167,572] \033[0m<inf> central_hr: MTU exchange done\033[0m [00:00:17.817,810] \033[1;33m<wrn> central_hr: Pairing failed conn: E0:EF:E7:CA:6A:68 (random), rea[00:01:05.502,258] \033[1;33m<wrn> central_hr: Pairing failed conn: E0:EF:E7:CA:6A:68 (random), reason 9\033[0m [00:01:05.502,410] \033[1;33m<wrn> central_hr: Security failed: E0:EF:E7:CA:6A:68 (random) level 1 err 9\033[0m [00:01:05.502,441] \033[1;31m<err> bt_gatt_dm: Discover failed, error: -128.\033[0m [00:01:05.502,441] \033[1;31m<err> central_hr: could not start the discovery procedure, error code: -128\033[0m [00:01:05.503,570] \033[0m<inf> central_hr: Disconnected: E0:EF:E7:CA:6A:68 (random) (reason 8)\033[0m
Hi Owain,
Thanks for the update.
I would assume there is some configuration with your board that chose HCI H4 ?
By default if you compile with nRF5340 hci_rpmsg will be selected for the netcore.
Could you try compile for nRF5340dk_nrf5340_cpuapp ?
Also if you have a nRF52 board please try to do a cross check. We need to see if the issue only happens on the nRF53 or also on the nRF52. Then we can narrow down it to the dual core setting that cause the issue.
I also assume that you only try to pair with one device ? By default CONFIG_BT_MAX_PAIRED = 1 so you can't pair with 2 devices or more.
I looked at the trace again and have to correct myself that it was not "The nRF5 didn't send the pairing confirm and then the slave disconnected. " but the pairing confirms were sent and pairing randoms received but the confirm value from the POLAR was not match and it explain why the central terminate the pairing process.
I will check internally to have the confirmation, but it's strange that the POLAR works with other central but not the DUT. I assume it works fine with a phone ?
Please also try testing the nRF5340 to pair with a nRF5 running peripheral_hr to see if the pairing would work or not. From what you described, it worked with the Garmin ?
I did a quick test with your firmware and it paired fine with a nRF52 running peripheral_hr.
Hi again Owain,
After checking with the team, I think we found something suspicious here. In both of your sniffer trace the slave didn't respond to the LL_PHY_REQ from the central.
This could be the reason the central couldn't send the LL_ENC_REQ. The central can't send the encryption request before the previous request has been responded.
Could you please try modify the central so that it doesn't request 2Mbps PHY change to see if it would let the pairing complete ?
You may want to call bt_conn_get_remote_info() to get the information to know about the peer's BLE stack. If it's very old it may doesn't support PHY request change.
simplePolarNotL2Secure.pcap.pcapngI Can try that, but this Polar H10 heartstrap works if I do not request the security change to L2.
This Polar Hear Strap the H10 is one of the most widely used heart monitors in the world. This and the Garmin are the devices used by 99% of athletes using a monitor.
As I think I have said I have tinkered with the peripheral uart example to change uuid etc; and I have tried with a standard 5340 dk (non-secure).
I get the same behaviour.
Here a trace without the switch to L2; and we do see the update for the PHY update in this trace. And they do agree to use 2M phy.
Hi Owain,
Could you let us know the result if 2Mbps was not requested ?
There could be a chance that it still support 2Mbps but the PHY request came at the wrong time and it trigger a corner case causing the problem.
And please provide us the trace when you use central uart to connect to the HR. I would assume PHY request was not sent (?).
As far as I know the Polar H10 may actually use Nordic's Softdevice on it and we did have an issue earlier with these old Softdevices that they doesn't support PHY request change.
