ESP-IDF v5.1.5 - BLE Crashes after connection parameter update (IDFGH-12607) #13605

expresspotato · 2024-04-13T20:59:48Z

Answers checklist.

I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
I have searched the issue tracker for a similar issue and not found a similar issue.

IDF version.

v4.3.7, v5.1.5

Espressif SoC revision.

ESP32-Pico-V3-02

Operating System used.

macOS

How did you build your project?

Command line with idf.py

If you are using Windows, please specify command line type.

None

Development Kit.

LyraT

Power Supply used.

USB

What is the expected behavior?

Not crash

What is the actual behavior?

Crashes

Steps to reproduce.

Build a co-ex project
Connect via HFP, A2D, AVRC, BLE
Change the connection parameters, relatively often (1-2 times per minute) as needed between an idle / active state
Observe crash

Debug Logs.

Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x40015788  PS      : 0x00060d30  A0      : 0x80049eba  A1      : 0x3ffdc7c0  
A2      : 0x3ffdc7f0  A3      : 0x3ffdc808  A4      : 0x000000ff  A5      : 0x00000001  
A6      : 0x00000003  A7      : 0x00000001  A8      : 0x0014f00f  A9      : 0x00000000  
A10     : 0x000000a6  A11     : 0x000000a6  A12     : 0x00000000  A13     : 0x000000c0  
A14     : 0x3ffd9f04  A15     : 0x00000001  SAR     : 0x0000001d  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x0014f013  LBEG    : 0x4000c46c  LEND    : 0x4000c477  LCOUNT  : 0xffffffff  

Backtrace:0x40015785:0x3ffdc7c0 0x40049eb7:0x3ffdc7f0 0x40164cf6:0x3ffdc840 0x40042386:0x3ffdc870 0x40089766:0x3ffdc890 0x40019d11:0x3ffdc8c0 0x40055b4d:0x3ffdc8e0 0x4015b547:0x3ffdc900 0x4015bbca:0x3ffdc920
0x40164cf6: hci_le_rem_con_param_req_reply_cmd_handler at llc_hci.c:?

0x40089766: ke_task_schedule at ke_task.c:?

0x4015b547: r_rw_schedule at ??:?

0x4015bbca: btdm_controller_task at ??:?



ELF file SHA256: 7f571c4f7e7eff18

I (1469) esp_core_dump_flash: Save core dump to flash...
I (1475) esp_core_dump_flash: Erase flash 36864 bytes @ 0x7e0000
I (1701) esp_core_dump_flash: Write end offset 0x86a4, check sum length 4
I (1701) esp_core_dump_flash: Core dump has been saved to flash.

More Information.

Forum topic: https://esp32.com/viewtopic.php?f=28&t=37739

Edit: I've also noticed this issue without changing the connection params myself...

The text was updated successfully, but these errors were encountered:

esp-zhp · 2024-04-16T09:05:44Z

@expresspotato
thanks for reporting the bug,we will check it.

expresspotato · 2024-04-28T04:29:38Z

@expresspotato thanks for reporting the bug,we will check it.

Hi @zhp0406,

Were you able to determine the root cause and a fix for this issue?

esp-zhp · 2024-04-29T09:19:13Z

Version 4.3 is no longer under active maintenance, so I've utilized the latest master branch to replicate your issue. I've employed two examples (esp-idf/examples/bluetooth/bluedroid/coex/a2dp_gatts_coex and esp-idf/examples/bluetooth/bluedroid/ble/gatt_client).

In the gatt_client example, I irregularly initiate connection parameter updates. No alterations have been made to a2dp_gatts_coex. However, I haven't been able to reproduce the issue you described.

log in a2dp_gatts_coex:

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:7192
load:0x40078000,len:15564
ho 0 tail 12 room 4
load:0x40080400,len:4
load:0x40080404,len:3904
entry 0x40080640
�[0;32mI (31) boot: ESP-IDF v5.4-dev-120-g1b95af2096-dirty 2nd stage bootloader�[0m
�[0;32mI (31) boot: compile time Apr 29 2024 15:59:36�[0m
�[0;32mI (33) boot: Multicore bootloader�[0m
�[0;32mI (37) boot: chip revision: v3.1�[0m
�[0;32mI (41) boot.esp32: SPI Speed      : 40MHz�[0m
�[0;32mI (46) boot.esp32: SPI Mode       : DIO�[0m
�[0;32mI (50) boot.esp32: SPI Flash Size : 2MB�[0m
�[0;32mI (55) boot: Enabling RNG early entropy source...�[0m
�[0;32mI (60) boot: Partition Table:�[0m
�[0;32mI (64) boot: ## Label            Usage          Type ST Offset   Length�[0m
�[0;32mI (71) boot:  0 nvs              WiFi data        01 02 00009000 00006000�[0m
�[0;32mI (79) boot:  1 phy_init         RF data          01 01 0000f000 00001000�[0m
�[0;32mI (86) boot:  2 factory          factory app      00 00 00010000 00100000�[0m
�[0;32mI (94) boot: End of partition table�[0m
�[0;32mI (98) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=2f310h (193296) map�[0m
�[0;32mI (173) esp_image: segment 1: paddr=0003f338 vaddr=3ffbdb60 size=00ce0h (  3296) load�[0m
�[0;32mI (174) esp_image: segment 2: paddr=00040020 vaddr=400d0020 size=a9564h (693604) map�[0m
�[0;32mI (416) esp_image: segment 3: paddr=000e958c vaddr=3ffbe840 size=04274h ( 17012) load�[0m
�[0;32mI (423) esp_image: segment 4: paddr=000ed808 vaddr=40080000 size=1aa94h (109204) load�[0m
�[0;32mI (479) boot: Loaded app from partition at offset 0x10000�[0m
�[0;32mI (479) boot: Disabling RNG early entropy source...�[0m
�[0;32mI (491) cpu_start: Multicore app�[0m
�[0;32mI (500) cpu_start: Pro cpu start user code�[0m
�[0;32mI (500) cpu_start: cpu freq: 160000000 Hz�[0m
�[0;32mI (500) app_init: Application information:�[0m
�[0;32mI (503) app_init: Project name:     bt_ble_coex�[0m
�[0;32mI (508) app_init: App version:      v5.4-dev-120-g1b95af2096-dirty�[0m
�[0;32mI (515) app_init: Compile time:     Apr 29 2024 15:59:32�[0m
�[0;32mI (521) app_init: ELF file SHA256:  7c4f2dacf...�[0m
�[0;32mI (526) app_init: ESP-IDF:          v5.4-dev-120-g1b95af2096-dirty�[0m
�[0;32mI (533) efuse_init: Min chip rev:     v0.0�[0m
�[0;32mI (538) efuse_init: Max chip rev:     v3.99 �[0m
�[0;32mI (542) efuse_init: Chip rev:         v3.1�[0m
�[0;32mI (548) heap_init: Initializing. RAM available for dynamic allocation:�[0m
�[0;32mI (555) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM�[0m
�[0;32mI (561) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM�[0m
�[0;32mI (567) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM�[0m
�[0;32mI (573) heap_init: At 3FFCC258 len 00013DA8 (79 KiB): DRAM�[0m
�[0;32mI (579) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM�[0m
�[0;32mI (585) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM�[0m
�[0;32mI (592) heap_init: At 4009AA94 len 0000556C (21 KiB): IRAM�[0m
�[0;32mI (600) spi_flash: detected chip: generic�[0m
�[0;32mI (603) spi_flash: flash io: dio�[0m
�[0;33mW (606) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.�[0m
�[0;32mI (621) coexist: coex firmware version: 7fff68fa5�[0m
�[0;32mI (626) main_task: Started on CPU0�[0m
�[0;32mI (636) main_task: Calling app_main()�[0m
�[0;32mI (646) BTDM_INIT: BT controller compile version [4012cfb]�[0m
�[0;32mI (646) BTDM_INIT: Bluetooth MAC: 08:3a:8d:15:0b:5e�[0m
�[0;32mI (656) phy_init: phy_version 4791,2c4672b,Dec 20 2023,16:06:06�[0m
�[0;33mW (1346) BT_BTC: A2DP Enable with AVRC�[0m
�[0;32mI (1356) BT_AV: A2DP PROF STATE: Init Complete�[0m
�[0;32mI (1366) BT_BLE_COEX: event: 10�[0m
�[0;32mI (1366) BT_BLE_COEX: event: 10�[0m
�[0;32mI (1366) BT_BLE_COEX: event: 10�[0m
�[0;32mI (1366) BT_AV: Get delay report value: delay_value: 1200 * 1/10 ms�[0m
�[0;32mI (1376) BT_BLE_COEX: REGISTER_APP_EVT, status 0, app_id 0�[0m
�[0;32mI (1386) BT_AV: Set delay report value: success, delay_value: 1250 * 1/10 ms�[0m
�[0;32mI (1386) BT_BLE_COEX: CREATE_SERVICE_EVT, status 0,  service_handle 40�[0m
�[0;32mI (1396) main_task: Returned from app_main()�[0m
�[0;32mI (1406) BT_BLE_COEX: Start adv successfully�[0m
�[0;32mI (1406) BT_BLE_COEX: SERVICE_START_EVT, status 0, service_handle 40�[0m
�[0;32mI (1416) BT_BLE_COEX: ADD_CHAR_EVT, status 0,  attr_handle 42, service_handle 40�[0m
�[0;32mI (1416) BT_BLE_COEX: REGISTER_APP_EVT, status 0, app_id 1�[0m
�[0;32mI (1426) BT_BLE_COEX: ADD_DESCR_EVT, status 0, attr_handle 43, service_handle 40�[0m
�[0;32mI (1436) BT_BLE_COEX: CREATE_SERVICE_EVT, status 0,  service_handle 44�[0m
�[0;32mI (1446) BT_BLE_COEX: SERVICE_START_EVT, status 0, service_handle 44�[0m
�[0;32mI (1446) BT_BLE_COEX: ADD_CHAR_EVT, status 0,  attr_handle 46, service_handle 44�[0m
�[0;32mI (1456) BT_BLE_COEX: ADD_DESCR_EVT, status 0, attr_handle 47, service_handle 44�[0m
�[0;32mI (22366) BT_BLE_COEX: CONNECT_EVT, conn_id 0, remote 30:ae:a4:80:56:0e:�[0m
�[0;32mI (23156) BT_BLE_COEX: ESP_GATTS_MTU_EVT, MTU 500�[0m
�[0;32mI (23156) BT_BLE_COEX: ESP_GATTS_MTU_EVT, MTU 500�[0m
�[0;32mI (23246) BT_BLE_COEX: GATT_WRITE_EVT, conn_id 0, trans_id 2, handle 43�[0m
�[0;32mI (23246) BT_BLE_COEX: GATT_WRITE_EVT, value len 2, value :�[0m
�[0;32mI (23246) BT_BLE_COEX: 01 00 �[0m
�[0;32mI (23256) BT_BLE_COEX: notify enable�[0m
�[0;32mI (23256) BT_BLE_COEX: ESP_GATTS_CONF_EVT, status 0�[0m
�[0;32mI (23306) BT_BLE_COEX: GATT_WRITE_EVT, conn_id 0, trans_id 3, handle 42�[0m
�[0;32mI (23306) BT_BLE_COEX: GATT_WRITE_EVT, value len 35, value :�[0m
�[0;32mI (23306) BT_BLE_COEX: 00 01 02 03 04 05 06 07 08 09 0a 0b 0c 0d 0e 0f �[0m
�[0;32mI (23316) BT_BLE_COEX: 10 11 12 13 14 15 16 17 18 19 1a 1b 1c 1d 1e 1f �[0m
�[0;32mI (23326) BT_BLE_COEX: 20 21 22 �[0m
�[0;32mI (32096) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 32,latency = 0, timeout = 400�[0m
�[0;32mI (33326) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 33,latency = 0, timeout = 400�[0m
�[0;32mI (34276) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 34,latency = 0, timeout = 400�[0m
�[0;32mI (35346) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 35,latency = 0, timeout = 400�[0m
�[0;32mI (36446) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 36,latency = 0, timeout = 400�[0m
�[0;32mI (64226) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 37,latency = 0, timeout = 400�[0m
�[0;32mI (65246) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 38,latency = 0, timeout = 400�[0m
�[0;32mI (66256) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 39,latency = 0, timeout = 400�[0m
�[0;32mI (67336) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 40,latency = 0, timeout = 400�[0m
�[0;32mI (68246) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 41,latency = 0, timeout = 400�[0m
�[0;32mI (73376) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 42,latency = 0, timeout = 400�[0m
�[0;32mI (74376) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 43,latency = 0, timeout = 400�[0m
�[0;32mI (75406) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 44,latency = 0, timeout = 400�[0m
�[0;32mI (78486) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 45,latency = 0, timeout = 400�[0m
�[0;32mI (94586) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 46,latency = 0, timeout = 400�[0m
�[0;32mI (95516) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 47,latency = 0, timeout = 400�[0m
�[0;32mI (105156) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 48,latency = 0, timeout = 400�[0m
�[0;32mI (132046) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 49,latency = 0, timeout = 400�[0m
�[0;32mI (133216) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 50,latency = 0, timeout = 400�[0m
�[0;32mI (142476) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 51,latency = 0, timeout = 400�[0m
�[0;32mI (143436) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 52,latency = 0, timeout = 400�[0m
�[0;32mI (173476) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 53,latency = 0, timeout = 400�[0m
�[0;32mI (188856) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 54,latency = 0, timeout = 400�[0m
�[0;32mI (212896) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 55,latency = 0, timeout = 400�[0m
�[0;32mI (213926) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 56,latency = 0, timeout = 400�[0m
�[0;32mI (214916) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 57,latency = 0, timeout = 400�[0m
�[0;32mI (235446) BT_BLE_COEX: update connection params status = 0, min_int = 0, max_int = 0,conn_int = 58,latency = 0, timeout = 400�[0m

esp-zhp · 2024-04-29T09:26:43Z

Could you test with the latest version to see if the issue persists? If it still exists, could you provide an example that reproduces the problem?

expresspotato · 2024-04-30T05:02:42Z

Well there are other issues that are unresolved in 4.4.x, namely #11315, and a few others...

Our project is very large, so it's not easy to switch between 4.3.7 and 4.4.x (nor 5.x anything for that matter) without extensive testing. To my knowledge v.4.3.5 didn't have this issue.

I see in your test that A2DP, HFP and AVRC aren't connected yet. Can you try and connect those first?

esp-zhp · 2024-04-30T06:47:54Z

Do you mean this issue only occurs when A2DP, HFP, and AVRC are connected? I don't have A2DP, HFP, and AVRC connected here, only BLE connections.
Can you test whether the issue can be reproduced with only BLE connections?

esp-zhp · 2024-04-30T06:49:01Z

If you have a demo that reproduces the issue , it would be helpful for me to resolve the problem.”

expresspotato · 2024-05-08T14:28:11Z

Do you mean this issue only occurs when A2DP, HFP, and AVRC are connected? I don't have A2DP, HFP, and AVRC connected here, only BLE connections. Can you test whether the issue can be reproduced with only BLE connections?

Upon further observation, the crash occurs during an indicate. The parameters are not yet changed, and an indicate is sent from the ESP32 (GATTS) -> to an Android phone (GATTC) during the update process.

One instance:

I (74413) LIBERTY: 8 Bit --> 4077935
I (74418) LIBERTY: Internal --> 82228
I (74423) LIBERTY: SPI RAM --> 3999095
I (74428) LIBERTY: Largest free block in Internal --> 69620
I (74433) LIBERTY: Largest free block in SPI RAM --> 3932148
W (74438) LIBERTY: --> Memory used (After POST connection tasks): 0 / 20
W (74448) LIBERTY: --> BLE connection params set: Idle
E (74453) LIBERTY: --> Finished, sending back item... is threaded (1)
E (74463) LIBERTY: --> Dispatch callback!
E (74468) LIBERTY: --> CBBP Command Response Sent (1)
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x40015788  PS      : 0x00060830  A0      : 0x80049eba  A1      : 0x3ffdc720  
A2      : 0x3ffdc750  A3      : 0x3ffdc768  A4      : 0x000000ff  A5      : 0x00000001  
A6      : 0x00000003  A7      : 0x00000001  A8      : 0x0014f00f  A9      : 0x00000000  
A10     : 0x0000008f  A11     : 0x0000008f  A12     : 0x00000000  A13     : 0x000000c0  
A14     : 0x3ffd9e18  A15     : 0x00000001  SAR     : 0x0000001d  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x0014f013  LBEG    : 0x4000c46c  LEND    : 0x4000c477  LCOUNT  : 0xffffffff  

Backtrace:0x40015785:0x3ffdc720 0x40049eb7:0x3ffdc750 0x40162492:0x3ffdc7a0 0x40042386:0x3ffdc7d0 0x40087ece:0x3ffdc7f0 0x40019d11:0x3ffdc820 0x40055b4d:0x3ffdc840 0x40158ce7:0x3ffdc860 0x4015936a:0x3ffdc880
0x40162492: hci_le_rem_con_param_req_reply_cmd_handler at llc_hci.c:?

0x40087ece: ke_task_schedule at ke_task.c:?

0x40158ce7: r_rw_schedule at ??:?

0x4015936a: btdm_controller_task at ??:?

ELF file SHA256: 83803e802dc23644

I (2981) esp_core_dump_flash: Save core dump to flash...
I (2987) esp_core_dump_flash: Erase flash 28672 bytes @ 0x7e0000
I (3186) esp_core_dump_flash: Write end offset 0x6b44, check sum length 4
I (3186) esp_core_dump_flash: Core dump has been saved to flash.
Rebooting...
ets Jul 29 2019 12:21:46

rst:0xc (SW_CPU_RESET),boot:0x1f (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0030,len:7592
load:0x40078000,len:15860
load:0x40080400,len:4416
0x40080400: _init at ??:?

Another:

E (307599) LIBERTY: --> BLE request active
W (307599) LIBERTY: --> BLE connection params set: Active
E (307649) LIBERTY: --> CBBP Request over BT (87684 bytes)
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x40015788  PS      : 0x00060a30  A0      : 0x80049eba  A1      : 0x3ffdc720  
A2      : 0x3ffdc750  A3      : 0x3ffdc768  A4      : 0x000000ff  A5      : 0x00000001  
A6      : 0x00000003  A7      : 0x00000001  A8      : 0x0014f00f  A9      : 0x00000000  
A10     : 0x0000000f  A11     : 0x0000000f  A12     : 0x00000000  A13     : 0x00000018  
A14     : 0x3ffd9e18  A15     : 0x00000001  SAR     : 0x0000001d  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x0014f013  LBEG    : 0x4000c46c  LEND    : 0x4000c477  LCOUNT  : 0xffffffff  

Backtrace:0x40015785:0x3ffdc720 0x40049eb7:0x3ffdc750 0x40162492:0x3ffdc7a0 0x40042386:0x3ffdc7d0 0x40087ece:0x3ffdc7f0 0x40019d11:0x3ffdc820 0x40055b4d:0x3ffdc840 0x40158ce7:0x3ffdc860 0x4015936a:0x3ffdc880
0x40162492: hci_le_rem_con_param_req_reply_cmd_handler at llc_hci.c:?

0x40087ece: ke_task_schedule at ke_task.c:?

0x40158ce7: r_rw_schedule at ??:?

0x4015936a: btdm_controller_task at ??:?



ELF file SHA256: 83803e802dc23644

I (4085) esp_core_dump_flash: Save core dump to flash...
I (4091) esp_core_dump_flash: Erase flash 28672 bytes @ 0x7e0000
I (4284) esp_core_dump_flash: Write end offset 0x6ec4, check sum length 4
I (4284) esp_core_dump_flash: Core dump has been saved to flash.
Rebooting...
ets Jul 29 2019 12:21:46

rst:0xc (SW_CPU_RESET),boot:0x1f (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0030,len:7592
load:0x40078000,len:15860
load:0x40080400,len:4416
0x40080400: _init at ??:?

entry 0x400806a0

expresspotato · 2024-09-30T03:01:57Z

Hey @esp-zhp , so this is not fixed on v4.4.8... We checked and we really don't do anything bizzare in the code leading up to, or after the connection parameter update.

We simply make the request and even wait for the callback with the updated parameters before sending another GATT indicate.

Poking around, L2CA_UpdateBleConnParams does return true from the call stack, so it seems like the bug is on Espressif's side.

Since the source code is closed, I can't debug it further... What happens in hci_le_rem_con_param_req_reply_cmd_handler?

Without HFP connected, I'm unable to reproduce this bug, but I gave up after 50 attempts. With HFP connected, it will crash in in 15 - 20 attempts.

Can you try with HFP connected and send data over a ble characteristic through writes?

Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x40015788  PS      : 0x00060430  A0      : 0x80049eba  A1      : 0x3ffdf690  
A2      : 0x3ffdf6c0  A3      : 0x3ffdf6d8  A4      : 0x000000ff  A5      : 0x00000001  
A6      : 0x00000003  A7      : 0x00000001  A8      : 0xfcabba12  A9      : 0x00000000  
A10     : 0x00000064  A11     : 0x00000064  A12     : 0x00000000  A13     : 0x000000c0  
A14     : 0x3ffd1f80  A15     : 0x00000001  SAR     : 0x0000001d  EXCCAUSE: 0x0000001c  
EXCVADDR: 0xfcabba16  LBEG    : 0x4000c46c  LEND    : 0x4000c477  LCOUNT  : 0xffffffff  


Backtrace: 0x40015785:0x3ffdf690 0x40049eb7:0x3ffdf6c0 0x4021ed8e:0x3ffdf710 0x40042386:0x3ffdf740 0x40090256:0x3ffdf760 0x40019d11:0x3ffdf790 0x40055b4d:0x3ffdf7b0 0x40214103:0x3ffdf7d0 0x40214761:0x3ffdf7f0
0x4021ed8e: hci_le_rem_con_param_req_reply_cmd_handler at llc_hci.c:?

0x40090256: ke_task_schedule at ke_task.c:?

0x40214103: r_rw_schedule at ??:?

0x40214761: btdm_controller_task at ??:?

The interesting thing to note is that EXCVADDR is often 0x0014f013 (in my original post and now) along with the following addresses:

0x0014f013
0x0058a55e
0x0001e73c
0xfcabba16

esp-zhp · 2024-10-09T08:36:26Z

@expresspotato
From your log, it is clear that the crash was caused by accessing an invalid address, specifically:

EXCVADDR: 0xfcabba16
EXCVADDR: 0x0014f013

Were these two logs generated using different versions of the IDF?
could you give me a demo to reproduces the issue?

expresspotato · 2024-11-20T22:39:50Z

Interesting. So I've updated to v5.1.5 and the issue persists, in a slightly different manner. The stack still refers to hci_le_rem_con_param_req_reply_cmd_handler

Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x40015788  PS      : 0x00060430  A0      : 0x802286c5  A1      : 0x3ffe2cd0  
--- 0x40015788: r_ea_offset_req in ROM

A2      : 0x3ffe2d20  A3      : 0x3ffe2d38  A4      : 0x000000ff  A5      : 0x00000001  
A6      : 0x00000003  A7      : 0x00000001  A8      : 0x0014f00f  A9      : 0x00000000  
A10     : 0x00000017  A11     : 0x00000017  A12     : 0x00000000  A13     : 0x00000018  
A14     : 0x3ffdfc30  A15     : 0x3ffdff80  SAR     : 0x0000001d  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x0014f013  LBEG    : 0x4000c46c  LEND    : 0x4000c477  LCOUNT  : 0xffffffff  
--- 0x4000c46c: memset in ROM
0x4000c477: memset in ROM



Backtrace: 0x40015785:0x3ffe2cd0 0x402286c2:0x3ffe2d00 0x40049eb7:0x3ffe2d20 0x40231972:0x3ffe2d70 0x40042386:0x3ffe2da0 0x400919ca:0x3ffe2dc0 0x40019d11:0x3ffe2df0 0x40055b4d:0x3ffe2e10 0x402266bf:0x3ffe2e30 0x40226d21:0x3ffe2e50 0x4009ea05:0x3ffe2e80
--- 0x40015785: r_ea_offset_req in ROM
0x402286c2: r_ea_offset_req_hack at ??:?
0x40049eb7: r_lld_con_param_rsp in ROM
0x40231972: hci_le_rem_con_param_req_reply_cmd_handler at llc_hci.c:?
0x40042386: llc_hci_command_handler in ROM
0x400919ca: ke_task_schedule at ke_task.c:?
0x40019d11: r_ke_event_schedule in ROM
0x40055b4d: r_rwip_schedule in ROM
0x402266bf: r_rw_schedule at ??:?
0x40226d21: btdm_controller_task at ??:?
0x4009ea05: vPortTaskWrapper at /Users/kevin/esp/esp-idf-v5.1.5/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

esp-zhp · 2024-11-21T02:57:55Z

Yes, we haven’t resolved this issue yet. I urgently need a demo from you to reproduce the problem.

expresspotato · 2024-12-26T07:00:01Z

So I've finally had the time to produce an example for you. The code does crash infrequently, so you may have to reboot the device and make several attempts.

Overall, there isn't anything special going on.

Download the code and compile it for ESP32 (testing here on production board, ESP-32-Pico-V3-02). LyraT v4.3 shows the same.
Flash the example
Download nRF Connect for Android
Pair the device using Android, to ESP_COEX_A2DP_DEMO. Be sure to connect to A2D from the OS.
Open nRF
Scan and find ESP_COEX_BLE_DEMO
Connect
Open Unknown Service (0x00EE)
Hit the down arrow (read) on UUID 0xEE01 once
Notice the characteristic indications taking place
Wait for crash, sometimes it's instant (< 3 sec, sometimes it never happens). You'll have to reset and try several times and wait several minutes.
Disconnect / Connect A2D several times, it may speed up the process
Observe crash

a2dp_gatts_coex.zip

kevin@Kevin-Parkers-MacBook-Pro a2dp_gatts_coex % idf.py build && idf.py flash -p /dev/tty.usbserial-1120 && idf.py monitor -p /dev/tty.usbserial-1120
Executing action: all (aliases: build)
Running ninja in directory /Users/kevin/esp/esp-idf-v5.1.5/examples/bluetooth/bluedroid/coex/a2dp_gatts_coex/build
Executing "ninja all"...
[1/1] cd /Users/kevin/esp/esp-idf-v5.1.5/examples/bluetooth/bluedroid/coex/a2dp_gatts_coex/build/bootloader/esp-idf/e...000 /Users/kevin/esp/esp-idf-v5.1.5/examples/bluetooth/bluedroid/coex/a2dp_gatts_coex/build/bootloader/bootloader.binBootloader binary size 0x6860 bytes. 0x7a0 bytes (7%) free.
[8/9] Generating binary image from built executableesptool.py v4.7.0
Creating esp32 image...
Merged 27 ELF sections
Successfully created esp32 image.
Generated /Users/kevin/esp/esp-idf-v5.1.5/examples/bluetooth/bluedroid/coex/a2dp_gatts_coex/build/bt_ble_coex.bin
[9/9] cd /Users/kevin/esp/esp-idf-v5.1.5/examples/bluetooth/bluedroid/coex/a2dp_gatts_coex/build/esp-idf/esptool_py &...ion-table.bin /Users/kevin/esp/esp-idf-v5.1.5/examples/bluetooth/bluedroid/coex/a2dp_gatts_coex/build/bt_ble_coex.binbt_ble_coex.bin binary size 0xf42c0 bytes. Smallest app partition is 0x100000 bytes. 0xbd40 bytes (5%) free.
Warning: The smallest app partition is nearly full (5% free space left)!

Project build complete. To flash, run this command:
/Users/kevin/.espressif/python_env/idf5.1_py3.10_env/bin/python ../../../../../../esp-idf/components/esptool_py/esptool/esptool.py -p (PORT) -b 460800 --before default_reset --after hard_reset --chip esp32  write_flash --flash_mode dio --flash_size 2MB --flash_freq 40m 0x1000 build/bootloader/bootloader.bin 0x8000 build/partition_table/partition-table.bin 0x10000 build/bt_ble_coex.bin
or run 'idf.py -p (PORT) flash'
Executing action: flash
Running ninja in directory /Users/kevin/esp/esp-idf-v5.1.5/examples/bluetooth/bluedroid/coex/a2dp_gatts_coex/build
Executing "ninja flash"...
[1/5] cd /Users/kevin/esp/esp-idf-v5.1.5/examples/bluetooth/bluedroid/coex/a2dp_gatts_coex/build/esp-idf/esptool_py && /Users/kevin/.espressif/python_env/idf5.1_py3.10_env/bin/python /Users/kevin/esp/esp-idf-v5.1.5/components/partition_table/check_sizes.py --offset 0x8000 partition --type app /Users/kevin/esp/esp-idf-v5.1.5/examples/bluetooth/bluedroid/coex/a2dp_gatts_coex/build/partition_table/partition-table.bin /Users/kevin/esp/esp-idf-v5.1.5/examples/bluetooth/bluedroid/coex/a2dp_gatts_coex/build/bt_ble_coex.bin
bt_ble_coex.bin binary size 0xf42c0 bytes. Smallest app partition is 0x100000 bytes. 0xbd40 bytes (5%) free.
Warning: The smallest app partition is nearly full (5% free space left)!
[2/5] Performing build step for 'bootloader'
[1/1] cd /Users/kevin/esp/esp-idf-v5.1.5/examples/bluetooth/bluedroid/coex/a2dp_gatts_coex/build/bootloader/esp-idf/esptool_py && /Users/kevin/.espressif/python_env/idf5.1_py3.10_env/bin/python /Users/kevin/esp/esp-idf-v5.1.5/components/partition_table/check_sizes.py --offset 0x8000 bootloader 0x1000 /Users/kevin/esp/esp-idf-v5.1.5/examples/bluetooth/bluedroid/coex/a2dp_gatts_coex/build/bootloader/bootloader.bin
Bootloader binary size 0x6860 bytes. 0x7a0 bytes (7%) free.
[3/5] No install step for 'bootloader'
[4/5] Completed 'bootloader'
[4/5] cd /Users/kevin/esp/esp-idf-v5.1.5/components/esptool_py && /opt/homebrew/bin/cmake -D IDF_PATH=/Users/kevin/esp/esp-idf-v5.1.5 -D "SERIAL_TOOL=/Users/kevin/.espressif/python_env/idf5.1_py3.10_env/bin/python;;/Users/kevin/esp/esp-idf-v5.1.5/components/esptool_py/esptool/esptool.py;--chip;esp32" -D "SERIAL_TOOL_ARGS=--before=default_reset;--after=hard_reset;write_flash;@flash_args" -D WORKING_DIRECTORY=/Users/kevin/esp/esp-idf-v5.1.5/examples/bluetooth/bluedroid/coex/a2dp_gatts_coex/build -P /Users/kevin/esp/esp-idf-v5.1.5/components/esptool_py/run_serial_tool.cmake
esptool.py --chip esp32 -p /dev/tty.usbserial-1120 -b 460800 --before=default_reset --after=hard_reset write_flash --flash_mode dio --flash_freq 40m --flash_size 2MB 0x1000 bootloader/bootloader.bin 0x10000 bt_ble_coex.bin 0x8000 partition_table/partition-table.bin
esptool.py v4.7.0
Serial port /dev/tty.usbserial-1120
Connecting......
Chip is ESP32-PICO-V3-02 (revision v3.1)
Features: WiFi, BT, Dual Core, 240MHz, Embedded Flash, Embedded PSRAM, VRef calibration in efuse, Coding Scheme None
Crystal is 40MHz
MAC: 10:06:1c:17:b3:90
Uploading stub...
Running stub...
Stub running...
Changing baud rate to 460800
Changed.
Configuring flash size...
Flash will be erased from 0x00001000 to 0x00007fff...
Flash will be erased from 0x00010000 to 0x00104fff...
Flash will be erased from 0x00008000 to 0x00008fff...
Compressed 26720 bytes to 16732...
Writing at 0x00001000... (50 %)
Writing at 0x000076a1... (100 %)
Wrote 26720 bytes (16732 compressed) at 0x00001000 in 0.9 seconds (effective 226.7 kbit/s)...
Hash of data verified.
Compressed 1000128 bytes to 593057...
Writing at 0x00010000... (2 %)
Writing at 0x0001d747... (5 %)
Writing at 0x0002cb57... (8 %)
Writing at 0x0003936a... (10 %)
Writing at 0x0004357f... (13 %)
Writing at 0x00048dd0... (16 %)
Writing at 0x0004eccb... (18 %)
Writing at 0x00054c3c... (21 %)
Writing at 0x0005a5b5... (24 %)
Writing at 0x0005feea... (27 %)
Writing at 0x000653ef... (29 %)
Writing at 0x0006b130... (32 %)
Writing at 0x00071aa5... (35 %)
Writing at 0x00077603... (37 %)
Writing at 0x0007d249... (40 %)
Writing at 0x00083573... (43 %)
Writing at 0x00089352... (45 %)
Writing at 0x0008ee88... (48 %)
Writing at 0x0009497b... (51 %)
Writing at 0x0009a36f... (54 %)
Writing at 0x0009fc5d... (56 %)
Writing at 0x000a559c... (59 %)
Writing at 0x000ab6b5... (62 %)
Writing at 0x000b133b... (64 %)
Writing at 0x000b6b21... (67 %)
Writing at 0x000bce19... (70 %)
Writing at 0x000c2be9... (72 %)
Writing at 0x000c9020... (75 %)
Writing at 0x000cee13... (78 %)
Writing at 0x000d56e8... (81 %)
Writing at 0x000dd890... (83 %)
Writing at 0x000e5960... (86 %)
Writing at 0x000ec2fb... (89 %)
Writing at 0x000f1dbc... (91 %)
Writing at 0x000f7274... (94 %)
Writing at 0x000fd1bf... (97 %)
Writing at 0x00102e1e... (100 %)
Wrote 1000128 bytes (593057 compressed) at 0x00010000 in 15.7 seconds (effective 508.7 kbit/s)...
Hash of data verified.
Compressed 3072 bytes to 103...
Writing at 0x00008000... (100 %)
Wrote 3072 bytes (103 compressed) at 0x00008000 in 0.1 seconds (effective 298.7 kbit/s)...
Hash of data verified.

Leaving...
Hard resetting via RTS pin...
Done
Executing action: monitor
Running idf_monitor in directory /Users/kevin/esp/esp-idf-v5.1.5/examples/bluetooth/bluedroid/coex/a2dp_gatts_coex
Executing "/Users/kevin/.espressif/python_env/idf5.1_py3.10_env/bin/python /Users/kevin/esp/esp-idf/tools/idf_monitor.py -p /dev/tty.usbserial-1120 -b 115200 --toolchain-prefix xtensa-esp32-elf- --target esp32 --revision 0 /Users/kevin/esp/esp-idf-v5.1.5/examples/bluetooth/bluedroid/coex/a2dp_gatts_coex/build/bt_ble_coex.elf -m '/Users/kevin/.espressif/python_env/idf5.1_py3.10_env/bin/python' '/Users/kevin/esp/esp-idf/tools/idf.py'"...
--- Warning: Serial ports accessed as /dev/tty.* will hang gdb if launched.
--- Using /dev/cu.usbserial-1120 instead...
--- esp-idf-monitor 1.5.0 on /dev/cu.usbserial-1120 115200
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H
checksum failure, mode(0)
I (13) boot: ESP-IDF v5.1.5-dirty 2nd stage bootloader
I (13) boot: compile time Dec 25 2024 20:54:14
I (14) boot: Multicore bootloader
I (17) boot: chip revision: v3.1
I (21) boot.esp32: SPI Speed      : 40MHz
I (26) boot.esp32: SPI Mode       : DIO
I (30) boot.esp32: SPI Flash Size : 2MB
I (35) boot: Enabling RNG early entropy source...
I (40) boot: Partition Table:
I (44) boot: ## Label            Usage          Type ST Offset   Length
I (51) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (58) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (66) boot:  2 factory          factory app      00 00 00010000 00100000
I (73) boot: End of partition table
I (78) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=2c6b0h (181936) map
I (152) esp_image: segment 1: paddr=0003c6d8 vaddr=3ffbdb60 size=03940h ( 14656) load
I (158) esp_image: segment 2: paddr=00040020 vaddr=400d0020 size=a9308h (693000) map
I (408) esp_image: segment 3: paddr=000e9330 vaddr=3ffc14a0 size=012b4h (  4788) load
I (410) esp_image: segment 4: paddr=000ea5ec vaddr=40080000 size=19cach (105644) load
I (471) boot: Loaded app from partition at offset 0x10000
I (471) boot: Disabling RNG early entropy source...
I (483) cpu_start: Multicore app
I (484) cpu_start: Pro cpu up.
I (484) cpu_start: Starting app cpu, entry point is 0x400814c8
--- 0x400814c8: call_start_cpu1 at /Users/kevin/esp/esp-idf-v5.1.5/components/esp_system/port/cpu_start.c:159

I (0) cpu_start: App cpu up.
I (503) cpu_start: Pro cpu start user code
I (503) cpu_start: cpu freq: 160000000 Hz
I (503) cpu_start: Application information:
I (508) cpu_start: Project name:     bt_ble_coex
I (513) cpu_start: App version:      v5.1.5-dirty
I (519) cpu_start: Compile time:     Dec 25 2024 20:53:58
I (525) cpu_start: ELF file SHA256:  3047316bc6c709ba...
I (531) cpu_start: ESP-IDF:          v5.1.5-dirty
I (536) cpu_start: Min chip rev:     v0.0
I (541) cpu_start: Max chip rev:     v3.99 
I (546) cpu_start: Chip rev:         v3.1
I (550) heap_init: Initializing. RAM available for dynamic allocation:
I (558) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (563) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (570) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (576) heap_init: At 3FFCBE18 len 000141E8 (80 KiB): DRAM
I (582) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (588) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (595) heap_init: At 40099CAC len 00006354 (24 KiB): IRAM
I (602) spi_flash: detected chip: generic
I (606) spi_flash: flash io: dio
W (609) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (623) coexist: coex firmware version: 27d8387
I (628) app_start: Starting scheduler on CPU0
I (633) app_start: Starting scheduler on CPU1
I (633) main_task: Started on CPU0
I (643) main_task: Calling app_main()
I (663) BTDM_INIT: BT controller compile version [bc393dd]
I (663) BTDM_INIT: Bluetooth MAC: 10:06:1c:17:b3:92
I (663) phy_init: phy_version 4840,02e0d70,Sep  2 2024,19:39:07
W (1333) BT_BTC: A2DP Enable with AVRC
I (1353) BT_AV: A2DP PROF STATE: Init Complete
I (1353) BT_BLE_COEX: event: 10
I (1353) BT_BLE_COEX: event: 10
I (1363) BT_BLE_COEX: event: 10
I (1363) BT_BLE_COEX: event: 10
I (1363) BT_AV: Get delay report value: delay_value: 1200 * 1/10 ms
I (1363) BT_BLE_COEX: REGISTER_APP_EVT, status 0, app_id 0

I (1383) BT_BLE_COEX: REGISTER_APP_EVT, status 0, app_id 1

I (1383) BT_AV: Set delay report value: success, delay_value: 1250 * 1/10 ms
I (1383) BT_BLE_COEX: CREATE_SERVICE_EVT, status 0,  service_handle 40

I (1403) BT_BLE_COEX: CREATE_SERVICE_EVT, status 0,  service_handle 44

I (1363) main_task: Returned from app_main()
I (1413) BT_BLE_COEX: Start adv successfully

I (1413) BT_BLE_COEX: SERVICE_START_EVT, status 0, service_handle 40

I (1423) BT_BLE_COEX: ADD_CHAR_EVT, status 0,  attr_handle 42, service_handle 40

I (1433) BT_BLE_COEX: SERVICE_START_EVT, status 0, service_handle 44

I (1443) BT_BLE_COEX: ADD_CHAR_EVT, status 0,  attr_handle 46, service_handle 44

I (1443) BT_BLE_COEX: ADD_DESCR_EVT, status 0, attr_handle 43, service_handle 40

I (1453) BT_BLE_COEX: ADD_DESCR_EVT, status 0, attr_handle 47, service_handle 44

W (22743) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (22743) BT_BLE_COEX: event: 16
W (22763) BT_HCI: hcif link supv_to changed: hdl 0x80, supv_to 8000
I (23013) BT_AV: A2DP connection state: Connecting, [6c:ac:c2:54:8b:f8]
I (23083) BT_AV: A2DP audio stream configuration, codec type: 0
I (23083) BT_AV: Configure audio player: 21-15-2-35
I (23083) BT_AV: Audio player configured, sample rate: 44100
I (23093) BT_AV: protocol service capabilities configured: 0x1 
I (23093) BT_AV: Peer device support delay reporting
W (23143) BT_APPL: new conn_srvc id:19, app_id:0
I (23143) BT_AV: A2DP connection state: Connected, [6c:ac:c2:54:8b:f8]
I (23143) BT_APP_CORE: ringbuffer data empty! mode changed: RINGBUFFER_MODE_PREFETCHING
I (23233) RC_CT: AVRC conn_state event: state 1, [6c:ac:c2:54:8b:f8]
I (23233) RC_TG: AVRC conn_state evt: state 1, [6c:ac:c2:54:8b:f8]
I (23243) RC_CT: AVRC remote features 25b, TG features 51
I (23243) RC_TG: AVRC remote features: 25b, CT features: 2
I (23243) RC_TG: start volume change simulation
I (23253) RC_CT: remote rn_cap: count 7, bitmask 0xf26
I (23313) RC_TG: AVRC register event notification: 13, param: 0x0
I (23333) RC_CT: AVRC event notification: 1
I (23333) BT_AV: Playback status changed: 0x0
I (23333) RC_CT: AVRC metadata rsp: attribute id 0x1, Not Provided
I (23333) RC_CT: AVRC metadata rsp: attribute id 0x2, 
I (23343) RC_CT: AVRC metadata rsp: attribute id 0x4, 
I (23343) RC_CT: AVRC metadata rsp: attribute id 0x20, 
I (23353) RC_TG: AVRC set absolute volume: 70%
I (23353) RC_TG: Volume is set by remote controller to: 70%
W (26343) BT_HCI: hci cmd send: sniff: hdl 0x80, intv(400 800)
W (26383) BT_HCI: hcif mode change: hdl 0x80, mode 2, intv 768, status 0x0
I (26383) BT_BLE_COEX: ESP_BT_GAP_MODE_CHG_EVT mode: 2
I (33263) RC_TG: Volume is set locally to: 74%
I (33913) RC_TG: AVRC register event notification: 13, param: 0x0
I (43263) RC_TG: Volume is set locally to: 78%
I (43993) RC_TG: AVRC register event notification: 13, param: 0x0
I (53263) RC_TG: Volume is set locally to: 82%
I (54073) RC_TG: AVRC register event notification: 13, param: 0x0
I (13) boot: ESP-IDF v5.1.5-dirty 2nd stage bootloader
I (13) boot: compile time Dec 25 2024 20:54:14
I (14) boot: Multicore bootloader
I (17) boot: chip revision: v3.1
I (21) boot.esp32: SPI Speed      : 40MHz
I (26) boot.esp32: SPI Mode       : DIO
I (30) boot.esp32: SPI Flash Size : 2MB
I (35) boot: Enabling RNG early entropy source...
I (40) boot: Partition Table:
I (44) boot: ## Label            Usage          Type ST Offset   Length
I (51) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (58) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (66) boot:  2 factory          factory app      00 00 00010000 00100000
I (73) boot: End of partition table
I (78) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=2c6b0h (181936) map
I (152) esp_image: segment 1: paddr=0003c6d8 vaddr=3ffbdb60 size=03940h ( 14656) load
I (158) esp_image: segment 2: paddr=00040020 vaddr=400d0020 size=a9308h (693000) map
I (408) esp_image: segment 3: paddr=000e9330 vaddr=3ffc14a0 size=012b4h (  4788) load
I (410) esp_image: segment 4: paddr=000ea5ec vaddr=40080000 size=19cach (105644) load
I (471) boot: Loaded app from partition at offset 0x10000
I (471) boot: Disabling RNG early entropy source...
I (483) cpu_start: Multicore app
I (484) cpu_start: Pro cpu up.
I (484) cpu_start: Starting app cpu, entry point is 0x400814c8
--- 0x400814c8: call_start_cpu1 at /Users/kevin/esp/esp-idf-v5.1.5/components/esp_system/port/cpu_start.c:159

I (0) cpu_start: App cpu up.
I (503) cpu_start: Pro cpu start user code
I (503) cpu_start: cpu freq: 160000000 Hz
I (503) cpu_start: Application information:
I (508) cpu_start: Project name:     bt_ble_coex
I (513) cpu_start: App version:      v5.1.5-dirty
I (519) cpu_start: Compile time:     Dec 25 2024 20:53:58
I (525) cpu_start: ELF file SHA256:  3047316bc6c709ba...
I (531) cpu_start: ESP-IDF:          v5.1.5-dirty
I (536) cpu_start: Min chip rev:     v0.0
I (541) cpu_start: Max chip rev:     v3.99 
I (546) cpu_start: Chip rev:         v3.1
I (550) heap_init: Initializing. RAM available for dynamic allocation:
I (558) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (563) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (570) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (576) heap_init: At 3FFCBE18 len 000141E8 (80 KiB): DRAM
I (582) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (588) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (595) heap_init: At 40099CAC len 00006354 (24 KiB): IRAM
I (602) spi_flash: detected chip: generic
I (606) spi_flash: flash io: dio
W (609) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (623) coexist: coex firmware version: 27d8387
I (628) app_start: Starting scheduler on CPU0
I (633) app_start: Starting scheduler on CPU1
I (633) main_task: Started on CPU0
I (643) main_task: Calling app_main()
I (653) BTDM_INIT: BT controller compile version [bc393dd]
I (653) BTDM_INIT: Bluetooth MAC: 10:06:1c:17:b3:92
I (663) phy_init: phy_version 4840,02e0d70,Sep  2 2024,19:39:07
W (743) phy_init: saving new calibration data because of checksum failure, mode(0)
W (1353) BT_BTC: A2DP Enable with AVRC
I (1363) BT_AV: A2DP PROF STATE: Init Complete
I (1363) BT_BLE_COEX: event: 10
I (1373) BT_BLE_COEX: event: 10
I (1373) BT_BLE_COEX: event: 10
I (1373) BT_AV: Get delay report value: delay_value: 1200 * 1/10 ms
I (1373) BT_BLE_COEX: REGISTER_APP_EVT, status 0, app_id 0

I (1393) BT_BLE_COEX: REGISTER_APP_EVT, status 0, app_id 1

I (1393) BT_AV: Set delay report value: success, delay_value: 1250 * 1/10 ms
I (1393) BT_BLE_COEX: CREATE_SERVICE_EVT, status 0,  service_handle 40

I (1413) BT_BLE_COEX: CREATE_SERVICE_EVT, status 0,  service_handle 44

I (1373) main_task: Returned from app_main()
I (1423) BT_BLE_COEX: Start adv successfully

I (1423) BT_BLE_COEX: SERVICE_START_EVT, status 0, service_handle 40

I (1433) BT_BLE_COEX: ADD_CHAR_EVT, status 0,  attr_handle 42, service_handle 40

I (1443) BT_BLE_COEX: SERVICE_START_EVT, status 0, service_handle 44

I (1443) BT_BLE_COEX: ADD_CHAR_EVT, status 0,  attr_handle 46, service_handle 44

I (1453) BT_BLE_COEX: ADD_DESCR_EVT, status 0, attr_handle 43, service_handle 40

I (1463) BT_BLE_COEX: ADD_DESCR_EVT, status 0, attr_handle 47, service_handle 44

I (9073) BT_BLE_COEX: CONNECT_EVT, conn_id 0, remote 66:31:09:28:5a:3f:
I (9553) BT_BLE_COEX: update connection params status = 0, conn_int = 6, latency = 0, timeout = 500
I (9903) BT_BLE_COEX: update connection params status = 0, conn_int = 24, latency = 0, timeout = 500
W (14093) BT_HCI: hcif conn complete: hdl 0x80, st 0x0
I (14103) BT_BLE_COEX: event: 16
I (14593) BT_AV: A2DP connection state: Connecting, [6c:ac:c2:54:8b:f8]
E (14803) BT_BTM: tBTM_SEC_DEV:0x3ffd6348 rs_disc_pending=0

W (14823) BT_HCI: hcif link supv_to changed: hdl 0x80, supv_to 8000
I (14843) BT_AV: A2DP audio stream configuration, codec type: 0
I (14843) BT_AV: Configure audio player: 21-15-2-35
I (14843) BT_AV: Audio player configured, sample rate: 44100
I (14853) BT_AV: protocol service capabilities configured: 0x1 
I (14863) BT_AV: Peer device support delay reporting
W (14913) BT_APPL: new conn_srvc id:19, app_id:0
I (14913) BT_AV: A2DP connection state: Connected, [6c:ac:c2:54:8b:f8]
I (14913) BT_APP_CORE: ringbuffer data empty! mode changed: RINGBUFFER_MODE_PREFETCHING
I (15023) RC_CT: AVRC conn_state event: state 1, [6c:ac:c2:54:8b:f8]
I (15023) RC_TG: AVRC conn_state evt: state 1, [6c:ac:c2:54:8b:f8]
I (15023) RC_CT: AVRC remote features 25b, TG features 51
I (15023) RC_TG: start volume change simulation
I (15033) RC_TG: AVRC remote features: 25b, CT features: 2
I (15043) RC_CT: remote rn_cap: count 7, bitmask 0xf26
I (15073) RC_CT: AVRC metadata rsp: attribute id 0x1, Not Provided
I (15073) RC_CT: AVRC metadata rsp: attribute id 0x2, 
I (15073) RC_CT: AVRC metadata rsp: attribute id 0x4, 
I (15083) RC_CT: AVRC metadata rsp: attribute id 0x20, 
I (15083) RC_TG: AVRC register event notification: 13, param: 0x0
I (15123) RC_TG: AVRC set absolute volume: 82%
I (15123) RC_TG: Volume is set by remote controller to: 82%
I (15543) BT_LOG: bta_av_link_role_ok hndl:x41 role:1 conn_audio:x1 bits:1 features:x864b

W (15553) BT_APPL: new conn_srvc id:19, app_id:1
I (15553) BT_AV: A2DP audio state: Started
I (15623) RC_CT: AVRC event notification: 1
I (15623) BT_AV: Playback status changed: 0x1
I (15773) BT_APP_CORE: ringbuffer data increased! mode changed: RINGBUFFER_MODE_PROCESSING
I (17983) BT_AV: Audio packet count: 100
I (19473) BT_AV: A2DP audio state: Suspended
I (19533) RC_CT: AVRC event notification: 5
I (19533) BT_AV: Play position changed: 0-ms
I (19533) RC_CT: AVRC event notification: 1
I (19543) BT_APP_CORE: ringbuffer underflowed! mode changed: RINGBUFFER_MODE_PREFETCHING
I (19553) BT_AV: Playback status changed: 0x0
I (19923) BT_BLE_COEX: GATT_READ_EVT, conn_id 0, trans_id 1, handle 46

W (19923) BT_BLE_COEX: --> BLE connection params set: Active
I (20283) BT_BLE_COEX: update connection params status = 0, conn_int = 12, latency = 0, timeout = 300
I (21743) BT_BLE_COEX: GATT_READ_EVT, conn_id 0, trans_id 2, handle 46

W (21743) BT_BLE_COEX: --> BLE connection params set: Active
W (21743) BT_L2CAP: L2CA_UpdateBleConnParams connection parameter already set
I (21753) BT_BLE_COEX: update connection params status = 0, conn_int = 12, latency = 0, timeout = 300
W (22673) BT_HCI: hci cmd send: sniff: hdl 0x80, intv(30 54)
W (22693) BT_HCI: hcif mode change: hdl 0x80, mode 0, intv 0, status 0x20
E (22693) BT_APPL: bta_dm_pm_btm_status hci_status=32
I (22693) BT_BLE_COEX: ESP_BT_GAP_MODE_CHG_EVT mode: 0
I (25043) RC_TG: Volume is set locally to: 86%
I (25083) RC_TG: AVRC register event notification: 13, param: 0x0
I (26843) BT_BLE_COEX: GATT_READ_EVT, conn_id 0, trans_id 3, handle 46

W (26843) BT_BLE_COEX: --> BLE connection params set: Active
W (26843) BT_L2CAP: L2CA_UpdateBleConnParams connection parameter already set
I (26853) BT_BLE_COEX: update connection params status = 0, conn_int = 12, latency = 0, timeout = 300
I (27653) BT_BLE_COEX: GATT_READ_EVT, conn_id 0, trans_id 4, handle 46

W (27653) BT_BLE_COEX: --> BLE connection params set: Active
W (27653) BT_L2CAP: L2CA_UpdateBleConnParams connection parameter already set
I (27663) BT_BLE_COEX: update connection params status = 0, conn_int = 12, latency = 0, timeout = 300
I (29823) BT_BLE_COEX: GATT_READ_EVT, conn_id 0, trans_id 5, handle 46

W (29823) BT_BLE_COEX: --> BLE connection params set: Active
W (29823) BT_L2CAP: L2CA_UpdateBleConnParams connection parameter already set
I (29833) BT_BLE_COEX: update connection params status = 0, conn_int = 12, latency = 0, timeout = 300
W (29923) BT_BLE_COEX: --> BLE connection params set: Idle
I (29933) BT_BLE_COEX: ESP_GATTS_CONF_EVT status 0
I (29933) BT_BLE_COEX: ESP_GATTS_CONF_EVT status 0
I (29933) BT_BLE_COEX: ESP_GATTS_CONF_EVT status 0
I (29943) BT_BLE_COEX: ESP_GATTS_CONF_EVT status 0
I (29943) BT_BLE_COEX: ESP_GATTS_CONF_EVT status 0
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x4014a4b1  PS      : 0x00060530  A0      : 0x80049e4c  A1      : 0x3ffd0410  
--- 0x4014a4b1: r_ea_interval_duration_req at ??:?

A2      : 0x3ffd0430  A3      : 0x3ffd0448  A4      : 0x00060520  A5      : 0x00000021  
A6      : 0x00000098  A7      : 0x00000000  A8      : 0x00000000  A9      : 0x000cf00f  
A10     : 0x000000c0  A11     : 0x00000000  A12     : 0x00000002  A13     : 0x000000a0  
A14     : 0x00003ffc  A15     : 0xb33fffff  SAR     : 0x0000001d  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x000cf019  LBEG    : 0x4000c46c  LEND    : 0x4000c477  LCOUNT  : 0xffffffff  
--- 0x4000c46c: memset in ROM
0x4000c477: memset in ROM



Backtrace: 0x4014a4ae:0x3ffd0410 0x40049e49:0x3ffd0430 0x401537fa:0x3ffd0480 0x40042386:0x3ffd04b0 0x40089f1e:0x3ffd04d0 0x40019d11:0x3ffd0500 0x40055b4d:0x3ffd0520 0x401485af:0x3ffd0540 0x40148c11:0x3ffd0560 0x40094ffd:0x3ffd0590
--- 0x4014a4ae: r_ea_interval_duration_req at ??:?
0x40049e49: r_lld_con_param_rsp in ROM
0x401537fa: hci_le_rem_con_param_req_reply_cmd_handler at llc_hci.c:?
0x40042386: llc_hci_command_handler in ROM
0x40089f1e: ke_task_schedule at ke_task.c:?
0x40019d11: r_ke_event_schedule in ROM
0x40055b4d: r_rwip_schedule in ROM
0x401485af: r_rw_schedule at ??:?
0x40148c11: btdm_controller_task at ??:?
0x40094ffd: vPortTaskWrapper at /Users/kevin/esp/esp-idf-v5.1.5/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162





ELF file SHA256: 3047316bc6c709ba

Rebooting...

At ~ 3 minutes:

I (151075) BT_BLE_COEX: 3c 48 fc 3f 3c 48 Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x4014cfe9  PS      : 0x00060730  A0      : 0x80049e4c  A1      : 0x3ffc8e20  
--- 0x4014cfe9: r_ea_interval_duration_req at ??:?

A2      : 0x3ffc8e40  A3      : 0x3ffc8e58  A4      : 0x00060720  A5      : 0x00000021  
A6      : 0x00000098  A7      : 0x00000000  A8      : 0x00000000  A9      : 0x0014f00f  
A10     : 0x000000c0  A11     : 0x00000000  A12     : 0x00000002  A13     : 0x000000a0  
A14     : 0x00000000  A15     : 0xb33fffff  SAR     : 0x0000001d  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x0014f019  LBEG    : 0x4000c46c  LEND    : 0x4000c477  LCOUNT  : 0xffffffff  
--- 0x4000c46c: memset in ROM
0x4000c477: memset in ROM



Backtrace: 0x4014cfe6:0x3ffc8e20 0x40049e49:0x3ffc8e40 0x40156326:0x3ffc8e90 0x40042386:0x3ffc8ec0 0x4008a03e:0x3ffc8ee0 0x40019d11:0x3ffc8f10 0x40055b4d:0x3ffc8f30 0x4014b0e7:0x3ffc8f50 0x4014b749:0x3ffc8f70 0x4009511d:0x3ffc8fa0
--- 0x4014cfe6: r_ea_interval_duration_req at ??:?
0x40049e49: r_lld_con_param_rsp in ROM
0x40156326: hci_le_rem_con_param_req_reply_cmd_handler at llc_hci.c:?
0x40042386: llc_hci_command_handler in ROM
0x4008a03e: ke_task_schedule at ke_task.c:?
0x40019d11: r_ke_event_schedule in ROM
0x40055b4d: r_rwip_schedule in ROM
0x4014b0e7: r_rw_schedule at ??:?
0x4014b749: btdm_controller_task at ??:?
0x4009511d: vPortTaskWrapper at /Users/kevin/esp/esp-idf-v5.1.5/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162


ELF file SHA256: 317f3b93c77352d2

Rebooting...

At ~ 4 minutes

I (206975) BT_BLE_COEX: ESP_GATTS_CONF_EVT status 0
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x4014cfe9  PS      : 0x00060730  A0      : 0x8015030e  A1      : 0x3ffc8e20  
--- 0x4014cfe9: r_ea_interval_duration_req at ??:?

A2      : 0x3ffc8e40  A3      : 0x3ffc8e58  A4      : 0x3ffb8360  A5      : 0x071b0000  
A6      : 0x00000000  A7      : 0x00000002  A8      : 0x000000c0  A9      : 0x0014f00f  
A10     : 0x00000320  A11     : 0x000000c0  A12     : 0x00000002  A13     : 0x00000190  
A14     : 0x00000000  A15     : 0x00000000  SAR     : 0x0000001b  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x0014f019  LBEG    : 0x4000c46c  LEND    : 0x4000c477  LCOUNT  : 0x00000000  
--- 0x4000c46c: memset in ROM
0x4000c477: memset in ROM



Backtrace: 0x4014cfe6:0x3ffc8e20 0x4015030b:0x3ffc8e40 0x40028d42:0x3ffc8ea0 0x4008a03e:0x3ffc8ee0 0x40019d11:0x3ffc8f10 0x40055b4d:0x3ffc8f30 0x4014b0e7:0x3ffc8f50 0x4014b749:0x3ffc8f70 0x4009511d:0x3ffc8fa0
--- 0x4014cfe6: r_ea_interval_duration_req at ??:?
0x4015030b: r_LM_AddSniff at ??:?
0x40028d42: lc_op_loc_sniff_req_handler in ROM
0x4008a03e: ke_task_schedule at ke_task.c:?
0x40019d11: r_ke_event_schedule in ROM
0x40055b4d: r_rwip_schedule in ROM
0x4014b0e7: r_rw_schedule at ??:?
0x4014b749: btdm_controller_task at ??:?
0x4009511d: vPortTaskWrapper at /Users/kevin/esp/esp-idf-v5.1.5/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162





ELF file SHA256: 317f3b93c77352d2

Rebooting...

At 17 sec:

I (/) BT_BLE_COEX: ESP_GATTS_CONF_EVT status 132
I (177Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x4014cfb1  PS      : 0x00060230  A0      : 0x80049e4c  A1      : 0x3ffc8e20  
--- 0x4014cfb1: r_ea_interval_duration_req at ??:?

A2      : 0x3ffc8e40  A3      : 0x3ffc8e58  A4      : 0x80088b69  A5      : 0x3ffbef00  
A6      : 0x00000000  A7      : 0x3ff4e0c4  A8      : 0x00000000  A9      : 0x0014f00f  
A10     : 0x000000c0  A11     : 0x00000000  A12     : 0x00000002  A13     : 0x000000a0  
A14     : 0x00000000  A15     : 0x00000001  SAR     : 0x0000001d  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x0014f019  LBEG    : 0x4000c46c  LEND    : 0x4000c477  LCOUNT  : 0xffffffff  
--- 0x4000c46c: memset in ROM
0x4000c477: memset in ROM



Backtrace: 0x4014cfae:0x3ffc8e20 0x40049e49:0x3ffc8e40 0x401562ee:0x3ffc8e90 0x40042386:0x3ffc8ec0 0x4008a03e:0x3ffc8ee0 0x40019d11:0x3ffc8f10 0x40055b4d:0x3ffc8f30 0x4014b0af:0x3ffc8f50 0x4014b711:0x3ffc8f70 0x4009511d:0x3ffc8fa0
--- 0x4014cfae: r_ea_interval_duration_req at ??:?
0x40049e49: r_lld_con_param_rsp in ROM
0x401562ee: hci_le_rem_con_param_req_reply_cmd_handler at llc_hci.c:?
0x40042386: llc_hci_command_handler in ROM
0x4008a03e: ke_task_schedule at ke_task.c:?
0x40019d11: r_ke_event_schedule in ROM
0x40055b4d: r_rwip_schedule in ROM
0x4014b0af: r_rw_schedule at ??:?
0x4014b711: btdm_controller_task at ??:?
0x4009511d: vPortTaskWrapper at /Users/kevin/esp/esp-idf-v5.1.5/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162





ELF file SHA256: 0f74c65b09e1c3ba

Rebooting...

expresspotato · 2025-01-04T19:10:16Z

Hi @esp-zhp, any progress on fixing this?

esp-zhp · 2025-01-10T09:48:44Z

@expresspotato nogoing...will fix

expresspotato added the Type: Bug bugs in IDF label Apr 13, 2024

espressif-bot added the Status: Opened Issue is new label Apr 13, 2024

github-actions bot changed the title ~~ESP-IDF v4.3.7 - BLE Crashes during connection parameter update~~ ESP-IDF v4.3.7 - BLE Crashes during connection parameter update (IDFGH-12607) Apr 13, 2024

espressif-bot assigned wmy-espressif Apr 16, 2024

espressif-bot assigned esp-zhp and unassigned wmy-espressif Apr 16, 2024

expresspotato changed the title ~~ESP-IDF v4.3.7 - BLE Crashes during connection parameter update (IDFGH-12607)~~ ESP-IDF v4.3.7 - BLE Crashes after connection parameter update (IDFGH-12607) May 8, 2024

expresspotato changed the title ~~ESP-IDF v4.3.7 - BLE Crashes after connection parameter update (IDFGH-12607)~~ ESP-IDF v5.1.5 - BLE Crashes after connection parameter update (IDFGH-12607) Nov 21, 2024

espressif-bot added Status: In Progress Work is in progress and removed Status: Opened Issue is new labels Dec 3, 2024

expresspotato mentioned this issue Jan 7, 2025

v5.1.5 - Bluetooth controller crash in btdm_sleep_check_duration (IDFGH-14338) #15128

Open

3 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

ESP-IDF v5.1.5 - BLE Crashes after connection parameter update (IDFGH-12607) #13605

ESP-IDF v5.1.5 - BLE Crashes after connection parameter update (IDFGH-12607) #13605

expresspotato commented Apr 13, 2024 •

edited

Loading

esp-zhp commented Apr 16, 2024

expresspotato commented Apr 28, 2024

esp-zhp commented Apr 29, 2024 •

edited

Loading

esp-zhp commented Apr 29, 2024

expresspotato commented Apr 30, 2024

esp-zhp commented Apr 30, 2024

esp-zhp commented Apr 30, 2024

expresspotato commented May 8, 2024 •

edited

Loading

expresspotato commented Sep 30, 2024 •

edited

Loading

esp-zhp commented Oct 9, 2024 •

edited

Loading

expresspotato commented Nov 20, 2024

esp-zhp commented Nov 21, 2024

expresspotato commented Dec 26, 2024 •

edited

Loading

expresspotato commented Jan 4, 2025

esp-zhp commented Jan 10, 2025

ESP-IDF v5.1.5 - BLE Crashes after connection parameter update (IDFGH-12607) #13605

ESP-IDF v5.1.5 - BLE Crashes after connection parameter update (IDFGH-12607) #13605

Comments

expresspotato commented Apr 13, 2024 • edited Loading

Answers checklist.

IDF version.

Espressif SoC revision.

Operating System used.

How did you build your project?

If you are using Windows, please specify command line type.

Development Kit.

Power Supply used.

What is the expected behavior?

What is the actual behavior?

Steps to reproduce.

Debug Logs.

More Information.

esp-zhp commented Apr 16, 2024

expresspotato commented Apr 28, 2024

esp-zhp commented Apr 29, 2024 • edited Loading

esp-zhp commented Apr 29, 2024

expresspotato commented Apr 30, 2024

esp-zhp commented Apr 30, 2024

esp-zhp commented Apr 30, 2024

expresspotato commented May 8, 2024 • edited Loading

expresspotato commented Sep 30, 2024 • edited Loading

esp-zhp commented Oct 9, 2024 • edited Loading

expresspotato commented Nov 20, 2024

esp-zhp commented Nov 21, 2024

expresspotato commented Dec 26, 2024 • edited Loading

expresspotato commented Jan 4, 2025

esp-zhp commented Jan 10, 2025

expresspotato commented Apr 13, 2024 •

edited

Loading

esp-zhp commented Apr 29, 2024 •

edited

Loading

expresspotato commented May 8, 2024 •

edited

Loading

expresspotato commented Sep 30, 2024 •

edited

Loading

esp-zhp commented Oct 9, 2024 •

edited

Loading

expresspotato commented Dec 26, 2024 •

edited

Loading