ESP IDF 5.3.2 assert ble_hs_locked_by_cur_task (IDFGH-14217)

[danfleck]

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.

v5.3.2

Espressif SoC revision.

ESP32-S3

Operating System used.

macOS

How did you build your project?

VS Code IDE

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

None

Development Kit.

Custom board

Power Supply used.

USB

What is the expected behavior?

I expect it to startup with error.

What is the actual behavior?

Assert: On Nimble BLE init. ble_hs_locked_by_cur_task

Steps to reproduce.

Run the code with nimble init from main.

Debug Logs.

13:50:04 []
13:50:04 [assert failed: ble_hs_lock ble_hs.c:217 (!ble_hs_locked_by_cur_task())]
13:50:04 [] (1)
13:50:04 [Backtrace: 0x40374c32:0x3fcd2ad0 0x40382afd:0x3fcd2af0 0x4038a891:0x3fcd2b10 0x4200fd57:0x3fcd2c40 0x42013d21:0x3fcd2c60 0x42013d5d:0x3fcd2c80 0x4201463f:0x3fcd2cb0 0x420109f4:0x3fcd2d10 0x42010422:0x3fcd2d30 0x42010b16:0x3fcd2d50 0x4200fb4e:0x3fcd2d70 0x42070fab:0x3fcd2d90 0x403769f6:0x3fcd2db0 0x42008d28:0x3fcd2dd0 0x403838d1:0x3fcd2df0]
13:50:04 [] (3)
13:50:04 [ELF file SHA256: eb9c96f2a]
13:50:04 []
13:50:04 [Entering gdb stub now.]
13:50:04 E TRACE 0x40374c32: /Users/d/esp/v5.3.2/esp-idf/components/esp_system/panic.c:463
13:50:04 E TRACE 0x40382afd: /Users/d/esp/v5.3.2/esp-idf/components/esp_system/port/esp_system_chip.c:92
13:50:04 E TRACE 0x4038a891: /Users/d/esp/v5.3.2/esp-idf/components/newlib/assert.c:80
13:50:04 E TRACE 0x4200fd57: /Users/d/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs.c:217 (discriminator 1)
13:50:05 E TRACE 0x42013d21: /Users/d/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_gap.c:660
13:50:05 E TRACE 0x42013d5d: /Users/d/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_gap.c:917
13:50:05 E TRACE 0x4201463f: /Users/d/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_gap.c:2511
13:50:05 E TRACE 0x420109f4: /Users/d/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_hci_evt.c:719
13:50:05 E TRACE 0x42010422: /Users/d/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_hci_evt.c:446
13:50:05 E TRACE 0x42010b16: /Users/d/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_hci_evt.c:1180
13:50:05 E TRACE 0x4200fb4e: /Users/d/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs.c:531
13:50:05 E TRACE 0x42070fab: /Users/d/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/porting/npl/freertos/src/npl_os_freertos.c:451
13:50:05 E TRACE 0x403769f6: /Users/d/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/porting/npl/freertos/include/nimble/nimble_npl_os.h:185
13:50:05 E TRACE 0x42008d28: /Users/d/Documents/Altrix/FarmerNoah/git/farmer-noah/firmware/animal/main/subsystems/bluetooth.c:626
13:50:05 E TRACE 0x403838d1: /Users/d/esp/v5.3.2/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:139

More Information.

This seems like the same issue that was fixed here: Failed assert in BLE NIMBLE during init: ble_hs_locked_by_cur_task (IDFGH-12275) #13317

Did that possibly come back in IDF 5.3.2? Running the same code in IDF 5.3.1 does not assert.

[rahult-github]

Hi @danfleck ,

Can you share more information on how to reproduce this issue ? Are you using any nimble application that is showing this behaviour ? The fix in #13317 is different from the issue mentioned here .

Are there any application changes done at your end that reproduces this issue ? Can you possibly share the same with us which will assist us to debug this quicker ?

[danfleck]

Yes.

The following is called from main.c:

void BleMain(void) {
  int rc;
  esp_err_t espErr;

  // ESP_ERROR_CHECK(esp_nimble_hci_and_controller_init());

  espErr = nimble_port_init();
  if (espErr != ESP_OK) {
    FLogErrorCd(MSG_CODE_ERROR_BLE_START, "Unable to start BLE!");
    return;
  }

  /* Initialize the NimBLE host configuration. */
  ble_hs_cfg.reset_cb = BleOnReset;
  ble_hs_cfg.sync_cb = BleOnSync;
  ble_hs_cfg.gatts_register_cb = GattSvrRegisterCb;
  ble_hs_cfg.store_status_cb = ble_store_util_status_rr;
  ble_hs_cfg.sm_io_cap = BLE_SM_IO_CAP_DISP_ONLY;  // --> BLE_SM_IOACT_DISP;
  // ble_hs_cfg.sm_io_cap = BLE_SM_IO_CAP_NO_IO;  // JUST WORKS(?)
  // ble_hs_cfg.sm_io_cap = BLE_SM_IO_CAP_DISP_YES_NO;  // --> BLE_SM_IOACT_NUMCMP
  // ble_hs_cfg.sm_io_cap = BLE_SM_IO_CAP_KEYBOARD_ONLY;  // --> BLE_SM_IOACT_INPUT

  // BLE security manager (sm) config
  ble_hs_cfg.sm_bonding = 1;
  ble_hs_cfg.sm_mitm = 1;  // Off means we can do just works pairing, on not really.
  ble_hs_cfg.sm_sc = 1;    // Use BLE secure connections
  ble_hs_cfg.sm_our_key_dist = BLE_SM_PAIR_KEY_DIST_ENC | BLE_SM_PAIR_KEY_DIST_ID;
  ble_hs_cfg.sm_their_key_dist = BLE_SM_PAIR_KEY_DIST_ENC | BLE_SM_PAIR_KEY_DIST_ID;

  // ble_hs_cfg.sm_oob_data_flag = BLE_SM_PAIR_OOB_YES;  // Use OOB pairing

  rc = GattSvrInit();
  assert(rc == 0);

  /* Set the default device name. */
  rc = ble_svc_gap_device_name_set(BLE_DEVICE_NAME);
  assert(rc == 0);

  /* XXX Need to have template for store */
  ble_store_config_init();

  nimble_port_freertos_init(BleHostTask);
}

Then the assert happens in BleHostTask:

static void BleHostTask(void *param) {
  CLogDebug("BLE Host Task Started");
  /* This function will return only when nimble_port_stop() is executed */
  nimble_port_run(); // <<<---- Assert is caused by this line.

  nimble_port_freertos_deinit();
}

[kaylyun]

我也遇到了同样的问题，我猜测问题出现在 ble_gap.c 文件中，ble_gap_rx_rd_rem_sup_feat_complete 函数的修改。

在此函数中，新增了投递事件
ble_gap_rx_rd_rem_sup_feat_complete
....
ble_hs_lock();
...
ble_gap_event_listener_call(&event);
ble_gap_call_conn_event_cb(&event, conn_handle);
...
ble_hs_unlock();

但是在ble_gap_call_conn_event_cb -> ble_gap_extract_conn_cb 中也会调用ble_hs_lock(), 导致两次加锁，ble_hs_locked_by_cur_task 触发断言。

[rahult-github]

Hi @danfleck , @kaylyun ,

Please help check if this patch helps when applied to $IDF_PATH/components/bt/host/nimble/nimble branch
ble_hs_locked_cur_task.txt

[danfleck]

Unfortunately, no. I get the same assert after applying the patch: 09:52:24 assert failed: ble_hs_conn_find ble_hs_conn.c:301 (ble_hs_locked_by_cur_task()) 09:52:24 (1) 09:52:24 Backtrace: 0x4037665a:0x3fce3680 0x403841c9:0x3fce36a0 0x4038c6ba:0x3fce36c0 0x420297cb:0x3fce37e0 0x42021398:0x3fce3800 0x4201dc34:0x3fce3860 0x4201d9fb:0x3fce3880 0x4201e115:0x3fce38a0 0x4201d309:0x3fce38c0 0x420c379b:0x3fce38e0 0x403783a9:0x3fce3900 0x4200a099:0x3fce3920 0x40384d19:0x3fce3940 09:52:24 (3) 09:52:24 ELF file SHA256: f78d3fc383f7386e 09:52:24 09:52:24 Entering gdb stub now. 09:52:24 E TRACE 0x4037665a: /Users/REDACTED/esp/v5.3.2/esp-idf/components/esp_system/panic.c:463 09:52:24 E TRACE 0x403841c9: /Users/REDACTED/esp/v5.3.2/esp-idf/components/esp_system/port/esp_system_chip.c:92 09:52:24 E TRACE 0x4038c6ba: /Users/REDACTED/esp/v5.3.2/esp-idf/components/newlib/assert.c:80 09:52:25 E TRACE 0x420297cb: /Users/REDACTED/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_conn.c:301 (discriminator 1) 09:52:25 E TRACE 0x42021398: /Users/REDACTED/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_gap.c:2497 09:52:25 E TRACE 0x4201dc34: /Users/REDACTED/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_hci_evt.c:719 09:52:25 E TRACE 0x4201d9fb: /Users/REDACTED/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_hci_evt.c:446 09:52:25 E TRACE 0x4201e115: /Users/REDACTED/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_hci_evt.c:1180 09:52:25 E TRACE 0x4201d309: /Users/REDACTED/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/nimble/host/src/ble_hs.c:531 09:52:25 E TRACE 0x420c379b: /Users/REDACTED/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/porting/npl/freertos/src/npl_os_freertos.c:451 09:52:25 E TRACE 0x403783a9: /Users/REDACTED/esp/v5.3.2/esp-idf/components/bt/host/nimble/nimble/porting/npl/freertos/include/nimble/nimble_npl_os.h:185 09:52:25 E TRACE 0x4200a099: /Users/REDACTED/Documents/Altrix/AED/git/smartaed-firmware/cproc_firmware/main/subsystems/bluetooth/bluetooth.c:663 09:52:25 E TRACE 0x40384d19: /Users/REDACTED/esp/v5.3.2/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:139 From: Rahul ***@***.***> Date: Tuesday, December 31, 2024 at 10:31 PM To: espressif/esp-idf ***@***.***> Cc: Dan F. ***@***.***>, Mention ***@***.***> Subject: Re: [espressif/esp-idf] ESP IDF 5.3.2 assert ble_hs_locked_by_cur_task (IDFGH-14217) (Issue #15014) Hi @danfleck<https://github.com/danfleck> , @kaylyun<https://github.com/kaylyun> , Please help check if this patch helps when applied to $IDF_PATH/components/bt/host/nimble/nimble branch ble_hs_locked_cur_task.txt<https://github.com/user-attachments/files/18284363/ble_hs_locked_cur_task.txt> — Reply to this email directly, view it on GitHub<#15014 (comment)>, or unsubscribe<https://github.com/notifications/unsubscribe-auth/ABEC2NUC52REGMMJSVNV5N32INOS3AVCNFSM6AAAAABTL3CD2KVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDKNRWHAZDOOJYGE>. You are receiving this because you were mentioned.Message ID: ***@***.***>

[rahult-github]

Hello @danfleck ,

Ok, so i replaced your application code in the existing nimble examples and ran it and found no issues. Is it possible for you to use existing examples in IDF to check if they work OK or can you share your complete application code that i can use to reproduce the issue.

From logs, it looks like an event has been received, while some operations are still in progress ( hence ongoing operation has already taken a lock) .

[filzek]

@rahult-github same problem if we enable assertion on SDK 5.4, something in the BLE task is not acting correct.

BLE Nimble is running in core 0.

Just to call the BLE connection from the BLE device and send data the task crashes. If disable assertion works normally.

So, there is something wrong with the Nimble code.

assert failed: ble_hs_lock ble_hs.c:217
assert failed: ble_hs_lock ble_hs.c:217 (!ble_hs_locked_by_cur_task())

Backtrace: 0x40082418:0x3ffe6150 0x40098ef9:0x3ffe6170 0x4009cf29:0x3ffe6190 0x40135fd9:0x3ffe62c0 0x4013b2ef:0x3ffe62e0 0x4013baeb:0x3ffe6300 0x40136598:0x3ffe6360 0x40136447:0x3ffe6380 0x40136b1b:0x3ffe63a0 0x40135c51:0x3ffe63c0 0x401fe80b:0x3ffe63e0 0x40087ccd:0x3ffe6400 0x400dd3f1:0x3ffe6430
--- 0x40082418: panic_abort at C:/Espressif/frameworks/esp-idf-v5.4/components/esp_system/panic.c:454
0x40098ef9: esp_system_abort at C:/Espressif/frameworks/esp-idf-v5.4/components/esp_system/port/esp_system_chip.c:92
0x4009cf29: __assert_func at C:/Espressif/frameworks/esp-idf-v5.4/components/newlib/assert.c:80
0x40135fd9: ble_hs_lock at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/nimble/host/src/ble_hs.c:217 (discriminator 1)
0x4013b2ef: ble_gap_extract_conn_cb at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/nimble/host/src/ble_gap.c:660
(inlined by) ble_gap_call_conn_event_cb at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/nimble/host/src/ble_gap.c:917
0x4013baeb: ble_gap_rx_rd_rem_sup_feat_complete at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/nimble/host/src/ble_gap.c:2511
0x40136598: ble_hs_hci_evt_le_rd_rem_used_feat_complete at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_hci_evt.c:719
0x40136447: ble_hs_hci_evt_le_meta at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_hci_evt.c:446
0x40136b1b: ble_hs_hci_evt_process at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_hci_evt.c:1180
0x40135c51: ble_hs_event_rx_hci_ev at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/nimble/host/src/ble_hs.c:531
0x401fe80b: npl_freertos_event_run at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/porting/npl/freertos/src/npl_os_freertos.c:451
0x40087ccd: ble_npl_event_run at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/porting/npl/freertos/include/nimble/nimble_npl_os.h:185
(inlined by) nimble_port_run at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/porting/nimble/src/nimble_port.c:309

[filzek]

I am debugging the currently locked

LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]

So, what seens is okay, for the BLE Scan, Ble change parameters, all runs okay, but when try to iniate the SPP it does act as:

LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
INFO connection established; status=0
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
INFO handle=0 our_ota_addr_type=0 our_ota_addr=INFO our_id_addr_type=0 our_id_addr=INFO peer_ota_addr_type=1 peer_ota_addr=INFO peer_id_addr_type=1 peer_id_addr=INFO conn_itvl=24 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
INFO
name ble is [Wise:OK:n9i2fYu7] [ble_spp_server_advertise] [1002]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [0] ble_hs_task_handle[0] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]
LINE [149] ble_hs_mutex_locked [1] ble_hs_task_handle[1073620408] xTaskGetCurrentTaskHandle[1073620408]

assert failed: ble_hs_lock ble_hs.c:218 (!ble_hs_locked_by_cur_task())

Backtrace: 0x40082418:0x3ffe6150 0x40098ef9:0x3ffe6170 0x4009cf29:0x3ffe6190 0x40135fec:0x3ffe62c0 0x4013b303:0x3ffe62e0 0x4013baff:0x3ffe6300 0x401365ac:0x3ffe6360 0x4013645b:0x3ffe6380 0x40136b2f:0x3ffe63a0 0x40135c55:0x3ffe63c0 0x401fe81f:0x3ffe63e0 0x40087ccd:0x3ffe6400 0x400dd3f1:0x3ffe6430
--- 0x40082418: panic_abort at C:/Espressif/frameworks/esp-idf-v5.4/components/esp_system/panic.c:454
0x40098ef9: esp_system_abort at C:/Espressif/frameworks/esp-idf-v5.4/components/esp_system/port/esp_system_chip.c:92
0x4009cf29: __assert_func at C:/Espressif/frameworks/esp-idf-v5.4/components/newlib/assert.c:80
0x40135fec: ble_hs_lock at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/nimble/host/src/ble_hs.c:218 (discriminator 1)
0x4013b303: ble_gap_extract_conn_cb at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/nimble/host/src/ble_gap.c:660
(inlined by) ble_gap_call_conn_event_cb at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/nimble/host/src/ble_gap.c:917
0x4013baff: ble_gap_rx_rd_rem_sup_feat_complete at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/nimble/host/src/ble_gap.c:2511
0x401365ac: ble_hs_hci_evt_le_rd_rem_used_feat_complete at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_hci_evt.c:719
0x4013645b: ble_hs_hci_evt_le_meta at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_hci_evt.c:446
0x40136b2f: ble_hs_hci_evt_process at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/nimble/host/src/ble_hs_hci_evt.c:1180
0x40135c55: ble_hs_event_rx_hci_ev at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/nimble/host/src/ble_hs.c:532
0x401fe81f: npl_freertos_event_run at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/porting/npl/freertos/src/npl_os_freertos.c:451
0x40087ccd: ble_npl_event_run at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/porting/npl/freertos/include/nimble/nimble_npl_os.h:185
(inlined by) nimble_port_run at C:/Espressif/frameworks/esp-idf-v5.4/components/bt/host/nimble/nimble/porting/nimble/src/nimble_port.c:309
0x400dd3f1: ble_spp_server_host_task at D:/Dropbox/Dev/Producao5/main/include/ble_init.c:1209

[filzek]

So, my conclusion is that no matter how its runs the ASSERT is made wrong in the port of NIMBLE to ESP-IDF

/**

• Locks the BLE host mutex. Nested locks not allowed.
  */
  void
  ble_hs_lock(void)
  {
  BLE_HS_DBG_ASSERT(!ble_hs_locked_by_cur_task());
  #if MYNEWT_VAL(BLE_HS_DEBUG)
  if (!ble_npl_os_started()) {
  BLE_HS_DBG_ASSERT(!ble_hs_dbg_mutex_locked);
  }
  #endif

  ble_hs_lock_nested();
  }

This doesnt work so far.

[imdahisaria]

Any update on this topic ? I am using the example of wifi provisioning using BLE and security type 1.
As soon as the IOS App connects the esp32s3 crashes with error

assert failed: ble_hs_lock ble_hs.c:216 (!ble_hs_locked_by_cur_task())<\r><\n>

[filzek]

there is some error on the BLE that causes this behavior, some part of the assert are not correct and cause this invalid. If assert are enable the system will abort because it. If you need assert enable in the firmware, you need to comment the line BLE_HS_DBG_ASSERT(!ble_hs_locked_by_cur_task()); so there will ne no problem at all.