You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@mynewt.apache.org by GitBox <gi...@apache.org> on 2021/10/13 11:29:41 UTC
[GitHub] [mynewt-nimble] flonas955 opened a new issue #1052: Crash when restoring bonding
flonas955 opened a new issue #1052:
URL: https://github.com/apache/mynewt-nimble/issues/1052
### Setup
**Phone**: iPhone Xs
**iOS version**: 14.1
**Phone app**: nRF Connect
**Target**: ESP32 (NINA-W106)
**IDF**: version 4.3
**nimble-idf branch**: latest nimble-1.3.0-idf branch
### Description
I want to be able to bond with both Android and iPhone devices. As iPhones in particular have RPA addresses, I enabled privacy using guidelines from [here](https://github.com/espressif/esp-nimble/issues/8).
### Expected behavior
The stack should be able to resolve RPA addresses. After initially bonding the phone with the ESP32, no other pairing/bonding requests should be requested when reconnecting or during the active connection.
### Problem Description
After initially bonding the iPhone with the target, the connection is stable and the bonding works. After reconnecting once or several times (the issue is not consistent), without clearing any bonding information, the board crashes and gets reset. In order to be able to reconnect again, the bonding information from the phone has to be deleted first.
Usually, after the crash, the phone manages to restore bonding, but sometimes it resets forever trying to connect. This behavior is only on the iPhone, my Android device, which uses a public address, does not trigger the crash.
I managed to reproduce the problem using the [bleprph](https://github.com/espressif/esp-idf/tree/master/examples/bluetooth/nimble/bleprph) example. I have only added RPA address resolution to that example and increased the number of stored CCCD from 8 to 32. I have attached the project files:
[bleprph.zip](https://github.com/apache/mynewt-nimble/files/7337616/bleprph.zip)
### Steps to reproduce
1. Connect the iPhone to the ESP32 using the nRF Connect app.
2. Read the encrypted characteristic so that pairing is requested.
3. After pairing is done, disconnect.
4. Try to reconnect several times until the error/crash appears.
### Logs
1. I noticed that `ble_hs_util_ensure_addr()` does not always succeed in ensuring a random (1) address and sets a public one instead.
2. The crash description is shown below:
I (2653) NimBLE: GAP procedure initiated: advertise;
I (2653) NimBLE: disc_mode=2
I (2653) NimBLE: adv_channel_map=0 own_addr_type=1 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
I (2663) NimBLE:
D (2673) NimBLE: ble_hs_hci_cmd_send: ogf=0x08 ocf=0x0006 len=15
D (2673) NimBLE: 0x06
D (2683) NimBLE: 0x20
D (2683) NimBLE: 0x0f
D (2683) NimBLE: 0x30
D (2683) NimBLE: 0x00
D (2693) NimBLE: 0x60
D (2693) NimBLE: 0x00
D (2693) NimBLE: 0x00
D (2693) NimBLE: 0x01
D (2703) NimBLE: 0x00
D (2703) NimBLE: 0x00
D (2703) NimBLE: 0x00
D (2703) NimBLE: 0x00
D (2703) NimBLE: 0x00
D (2713) NimBLE: 0x00
D (2713) NimBLE: 0x00
D (2713) NimBLE: 0x07
D (2713) NimBLE: 0x00
D (2723) NimBLE:
D (2723) NimBLE: ble_hs_hci_cmd_send: ogf=0x08 ocf=0x000a len=1
D (2733) NimBLE: 0x0a
D (2733) NimBLE: 0x20
D (2733) NimBLE: 0x01
D (2733) NimBLE: 0x01
D (2733) NimBLE:
D (11483) NimBLE: 0x9c
D (11483) NimBLE: 0x88
D (11483) NimBLE: 0x77
D (11483) NimBLE: 0x5b
D (11493) NimBLE: 0x7e
D (11493) NimBLE: 0x67
D (11493) NimBLE:
I (11503) NimBLE: connection established; status=0
D (11513) NimBLE: Revised our id addr:
D (11523) NimBLE: 0x9a
D (11523) NimBLE: 0x5b
D (11523) NimBLE: 0x47
D (11523) NimBLE: 0xc0
D (11533) NimBLE: 0xa7
D (11533) NimBLE: 0x70
D (11533) NimBLE:
I (11543) NimBLE: handle=0 our_ota_addr_type=1 our_ota_addr=
I (11553) NimBLE: 70:a7:c0:47:5b:9a
I (11553) NimBLE: our_id_addr_type=0 our_id_addr=
I (11563) NimBLE: 7c:9e:bd:c9:68:5e
I (11563) NimBLE: peer_ota_addr_type=0 peer_ota_addr=
I (11573) NimBLE: 50:7a:c5:5f:c3:38
I (11573) NimBLE: peer_id_addr_type=0 peer_id_addr=
I (11583) NimBLE: 50:7a:c5:5f:c3:38
I (11583) NimBLE: conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=0 authenticated=0 bonded=0
I (11593) NimBLE:
D (11593) NimBLE: ble_hs_hci_cmd_send: ogf=0x08 ocf=0x0016 len=2
D (11603) NimBLE: 0x16
D (11603) NimBLE: 0x20
D (11613) NimBLE: 0x02
D (11613) NimBLE: 0x00
D (11613) NimBLE: 0x00
D (11613) NimBLE:
D (13623) NimBLE: Revised our id addr:
D (13623) NimBLE: 0x9a
D (13623) NimBLE: 0x5b
D (13633) NimBLE: 0x47
D (13633) NimBLE: 0xc0
D (13633) NimBLE: 0xa7
D (13633) NimBLE: 0x70
D (13643) NimBLE:
D (13643) NimBLE: looking up our sec;
D (13653) NimBLE: peer_addr_type=0 peer_addr=
D (13653) NimBLE: 0x38
D (13653) NimBLE: 0xc3
D (13663) NimBLE: 0x5f
D (13663) NimBLE: 0xc5
D (13663) NimBLE: 0x7a
D (13663) NimBLE: 0x50
D (13673) NimBLE:
D (13673) NimBLE: ediv=0x00 rand=0x0
D (13673) NimBLE:
D (13683) NimBLE: ble_hs_hci_cmd_send: ogf=0x08 ocf=0x001a len=18
D (13693) NimBLE: 0x1a
D (13693) NimBLE: 0x20
D (13693) NimBLE: 0x12
D (13703) NimBLE: 0x00
D (13703) NimBLE: 0x00
D (13703) NimBLE: 0x98
D (13703) NimBLE: 0x54
D (13713) NimBLE: 0xa7
D (13713) NimBLE: 0xbd
D (13713) NimBLE: 0xb8
D (13713) NimBLE: 0xd2
D (13723) NimBLE: 0x80
D (13723) NimBLE: 0x1a
D (13723) NimBLE: 0x31
D (13723) NimBLE: 0x3e
D (13733) NimBLE: 0x7d
D (13733) NimBLE: 0xc7
D (13733) NimBLE: 0x58
D (13733) NimBLE: 0x2e
D (13743) NimBLE: 0x8b
D (13743) NimBLE: 0x69
D (13743) NimBLE:
D (13763) NimBLE: Revised our id addr:
D (13763) NimBLE: 0x9a
D (13763) NimBLE: 0x5b
D (13763) NimBLE: 0x47
D (13773) NimBLE: 0xc0
D (13773) NimBLE: 0xa7
D (13773) NimBLE: 0x70
D (13783) NimBLE:
I (13783) NimBLE: encryption change event; status=7
D (13803) NimBLE: Revised our id addr:
D (13813) NimBLE: 0x9a
D (13813) NimBLE: 0x5b
D (13813) NimBLE: 0x47
D (13813) NimBLE: 0xc0
D (13823) NimBLE: 0xa7
D (13823) NimBLE: 0x70
D (13823) NimBLE:
I (13833) NimBLE: handle=0 our_ota_addr_type=1 our_ota_addr=
I (13843) NimBLE: 70:a7:c0:47:5b:9a
I (13843) NimBLE: our_id_addr_type=0 our_id_addr=
I (13853) NimBLE: 7c:9e:bd:c9:68:5e
I (13853) NimBLE: peer_ota_addr_type=0 peer_ota_addr=
I (13863) NimBLE: 50:7a:c5:5f:c3:38
I (13863) NimBLE: peer_id_addr_type=0 peer_id_addr=
I (13873) NimBLE: 50:7a:c5:5f:c3:38
I (13873) NimBLE: conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=0 authenticated=0 bonded=0
I (13883) NimBLE:
I (13883) NimBLE: disconnect; reason=19
I (13893) NimBLE: handle=0 our_ota_addr_type=1 our_ota_addr=
I (13903) NimBLE: 70:a7:c0:47:5b:9a
I (13903) NimBLE: our_id_addr_type=0 our_id_addr=
I (13913) NimBLE: 7c:9e:bd:c9:68:5e
I (13913) NimBLE: peer_ota_addr_type=0 peer_ota_addr=
I (13923) NimBLE: 50:7a:c5:5f:c3:38
I (13923) NimBLE: peer_id_addr_type=0 peer_id_addr=
I (13923) NimBLE: 50:7a:c5:5f:c3:38
I (13933) NimBLE: conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=0 authenticated=0 bonded=0
I (13943) NimBLE:
E (13943) NimBLE: error setting advertisement data; rc=22
E (13953) NimBLE: Resetting state; reason=19
D (13953) NimBLE: ble_hs_hci_cmd_send: ogf=0x03 ocf=0x0003 len=0
D (13963) NimBLE: 0x03
D (13963) NimBLE: 0x0c
D (13973) NimBLE: 0x00
D (13973) NimBLE:
Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled.
Core 0 register dump:
PC : 0x400e1e21 PS : 0x00060930 A0 : 0x800e1fdd A1 : 0x3ffca880
0x400e1e21: ble_hs_hci_process_ack at C:/Users/my_account/esp2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_hci.c:213
A2 : 0x00000c03 A3 : 0x00000000 A4 : 0x00000000 A5 : 0x3ffca8a0
A6 : 0x3ffc2514 A7 : 0x3ffca760 A8 : 0x800e1e1c A9 : 0x3ffca870
A10 : 0x00000000 A11 : 0x00000000 A12 : 0x00000010 A13 : 0x3ffca8b0
A14 : 0x3ffb6149 A15 : 0x00000001 SAR : 0x00000019 EXCCAUSE: 0x0000001c
EXCVADDR: 0x00000000 LBEG : 0x4000c46c LEND : 0x4000c477 LCOUNT : 0x00000000
Backtrace:0x400e1e1e:0x3ffca880 0x400e1fda:0x3ffca8a0 0x400dd705:0x3ffca8d0 0x400dd8c7:0x3ffca8f0 0x400da77c:0x3ffca910 0x400da7fe:0x3ffca930 0x400da80b:0x3ffca950 0x400e4246:0x3ffca970 0x400d77c6:0x3ffca990 0x40093b7d:0x3ffca9b0
0x400e1e1e: ble_hs_hci_process_ack at C:/Users/my_account/esp2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_hci.c:213
0x400e1fda: ble_hs_hci_cmd_tx at C:/Users/my_account/esp2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_hci.c:315
0x400dd705: ble_hs_startup_reset_tx at C:/Users/my_account/esp2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_startup.c:301
0x400dd8c7: ble_hs_startup_go at C:/Users/my_account/esp2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_startup.c:311
0x400da77c: ble_hs_sync at C:/Users/my_account/esp2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs.c:345
0x400da7fe: ble_hs_reset at C:/Users/my_account/esp2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs.c:400
0x400da80b: ble_hs_event_reset at C:/Users/my_account/esp2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs.c:538
0x400e4246: ble_npl_event_run at C:\Users\my_account\esp2\esp-idf\examples\bluetooth\nimble\bleprph\build/../../../../../components/bt/host/nimble/nimble/porting/npl/freertos/include/nimble/nimble_npl_os.h:125
(inlined by) nimble_port_run at C:/Users/my_account/esp2/esp-idf/components/bt/host/nimble/nimble/porting/nimble/src/nimble_port.c:78
0x400d77c6: bleprph_host_task at C:\Users\my_account\esp2\esp-idf\examples\bluetooth\nimble\bleprph\build/../main/main.c:345
0x40093b7d: vPortTaskWrapper at C:/Users/my_account/esp2/esp-idf/components/freertos/port/xtensa/port.c:168
3. Occasionally, I don't get a crash, but I get this instead:
I (54627) NimBLE: connection established; status=0
I (54647) NimBLE: handle=0 our_ota_addr_type=1 our_ota_addr=
I (54647) NimBLE: 75:23:dd:67:ec:80
I (54657) NimBLE: our_id_addr_type=1 our_id_addr=
I (54657) NimBLE: 75:23:dd:67:ec:80
I (54667) NimBLE: peer_ota_addr_type=1 peer_ota_addr=
I (54667) NimBLE: 49:e8:84:9d:a6:00
I (54677) NimBLE: peer_id_addr_type=1 peer_id_addr=
I (54677) NimBLE: 49:e8:84:9d:a6:00
I (54687) NimBLE: conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=0 authenticated=0 bonded=0
I (56717) NimBLE: disconnect; reason=19
I (56717) NimBLE: handle=0 our_ota_addr_type=1 our_ota_addr=
I (56727) NimBLE: 75:23:dd:67:ec:80
I (56727) NimBLE: our_id_addr_type=1 our_id_addr=
I (56737) NimBLE: 75:23:dd:67:ec:80
I (56737) NimBLE: peer_ota_addr_type=1 peer_ota_addr=
I (56747) NimBLE: 49:e8:84:9d:a6:00
I (56747) NimBLE: peer_id_addr_type=1 peer_id_addr=
I (56757) NimBLE: 49:e8:84:9d:a6:00
I (56757) NimBLE: conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=0 authenticated=0 bonded=0
I (56767) NimBLE:
E (56777) NimBLE: error setting advertisement data; rc=22
E (56777) NimBLE: Resetting state; reason=19
E (56817) NimBLE: failed to configure restored IRK
Please let me know if you need additional information.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@mynewt.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [mynewt-nimble] stevegrau-ayla commented on issue #1052: Crash when restoring bonding
Posted by GitBox <gi...@apache.org>.
stevegrau-ayla commented on issue #1052:
URL: https://github.com/apache/mynewt-nimble/issues/1052#issuecomment-970706205
I have seen a similar issue. If the peer_dev_rec table is full, the ESP device can't resolve the remote device's random address into an identity address, which it needs to retrieve the keys for the bonded peer. This table in NVS does not get cleared by ble_store_clear. It is cleared by ble_rpa_peer_dev_rec_clear_all but this is a static function.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@mynewt.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [mynewt-nimble] flonas955 commented on issue #1052: Crash when restoring bonding
Posted by GitBox <gi...@apache.org>.
flonas955 commented on issue #1052:
URL: https://github.com/apache/mynewt-nimble/issues/1052#issuecomment-963290938
Another problem is that some phones are not able to detect the ESP32 with RPA resolution active, while advertising. The solution is to disable and then reenable the Bluetooth on the phone regularly. Any ideas on this regard?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@mynewt.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [mynewt-nimble] flonas955 commented on issue #1052: Crash when restoring bonding
Posted by GitBox <gi...@apache.org>.
flonas955 commented on issue #1052:
URL: https://github.com/apache/mynewt-nimble/issues/1052#issuecomment-945880644
The crash described at point 2 was caused by the _Debug_ logs. Lowering the log level to _Info_ fixed the bug.
However, I still get the error with the IRK key described on point number 3 and the message _"Peer removed pairing information"_.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@mynewt.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org