espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.23k stars 7.18k forks source link

bt classic discoveries (starting / stopping) causes unexpected reset (IDFGH-4967) #6759

Closed andurbal closed 2 years ago

andurbal commented 3 years ago

Problem Description

bluetooth classic discovery. Launching discoveries periodically on BT CLASSIC via esp_bt_gap_start_discovery(..) produces an unexpected RESET.

Our application is starting BT Classic discoveries. For example Start a Discovery of aprox 2 seconds each 3 seconds. All works OK (devices are founded, events are coming etc...), but in a not predictable time, can be 2 hours, can be 7 hours, the ESP32 Resets because of Guru Meditation Error: Core 0 panic'ed (Interrupt wdt timeout on CPU0)

Expected Behavior

No unexpected RESETS

Actual Behavior

The Device resets in a unpredicable way.

Debug Logs

ASSERT_ERR(0), in lm_task.c at line 3997 Guru Meditation Error: Core 0 panic'ed (Interrupt wdt timeout on CPU0).

Core 0 register dump: PC : 0x400848e9 PS : 0x00060234 A0 : 0x8005351c A1 : 0x3ffd4620
A2 : 0x00000001 A3 : 0x00000000 A4 : 0x60008048 A5 : 0x3ffbdc0c
A6 : 0x3ffbdc0c A7 : 0x00000001 A8 : 0x800848e4 A9 : 0x3ffd4600
A10 : 0x00000029 A11 : 0x00000029 A12 : 0x00000010 A13 : 0xffffffff
A14 : 0x00000000 A15 : 0xfffffffb SAR : 0x00000004 EXCCAUSE: 0x00000005
EXCVADDR: 0x00000000 LBEG : 0x4008488c LEND : 0x40084893 LCOUNT : 0x00000000

Backtrace:0x400848e6:0x3ffd4620 0x40053519:0x3ffd4640 0x40085866:0x3ffd4660 0x40019d11:0x3ffd4690 0x40055b4d:0x3ffd46b0 0x4012f503:0x3ffd46d0 0x4012faf5:0x3ffd46f0 0x40090af9:0x3ffd4720 Core 1 register dump: PC : 0x4016a3f2 PS : 0x00060834 A0 : 0x800d4799 A1 : 0x3ffbc620
A2 : 0x00000000 A3 : 0x00000001 A4 : 0x00000014 A5 : 0x000000a5
A6 : 0x000000a5 A7 : 0x00060023 A8 : 0x800d46ea A9 : 0x3ffbc5f0
A10 : 0x00000000 A11 : 0x00000001 A12 : 0x37802c72 A13 : 0x00000027
A14 : 0x37802c61 A15 : 0x00060023 SAR : 0x00000000 EXCCAUSE: 0x00000005
EXCVADDR: 0x00000000 LBEG : 0x4000c46c LEND : 0x4000c477 LCOUNT : 0xffffffff

Backtrace:0x4016a3ef:0x3ffbc620 0x400d4796:0x3ffbc640 0x40091521:0x3ffbc660 0x40090af9:0x3ffbc680

ELF file SHA256: fd18d8c99fa86b43

Rebooting... ets Jul 29 2019 12:21:46

andurbal commented 3 years ago

In order to add some more info another strange behaviour is

Repeat the process but now change rsplimit in order to limit the Classic Devices. (I have tried this to see if it avoids or changes the behaviour of the unexpected reset). What I have found is that in a not predictable time, BLE devices reports stopped and are not reported any more.

andurbal commented 3 years ago

THIS EXAMPLE CODE CRASHES AT NOT PREDICTABLE TIME

`#include

include

include

include

include "nvs.h"

include "nvs_flash.h"

include "freertos/FreeRTOS.h"

include "freertos/task.h"

include "esp_system.h"

include "sdkconfig.h"

include "esp_log.h"

include "esp_bt.h"

include "esp_bt_main.h"

include "esp_gap_bt_api.h"

include "esp_spp_api.h"

include "esp32/rom/rtc.h"

const char *TAG_MAIN = "MINIMAL_CODE_TEST_RESET.CPP"; uint32_t InqCycles = 0;

// Relaunch a INQUIRY in BT CLASSIC each , for example 3 seconds void vTaskControlBluetooth(void* pvParameters) {

define INQUIRY_SECONDS_ON 1

#define INQUIRY_SECONDS_OFF 2
static int8_t InquirySlot = 0;
esp_err_t res;

for (;;) {

    // Start a CLASSIC DISCOVERY
    if (InquirySlot==0){
        res =  esp_bt_gap_start_discovery(ESP_BT_INQ_MODE_GENERAL_INQUIRY, 3, 0);
        if (res!=ESP_OK) ESP_LOGI(TAG_MAIN,"BT Launch Result %d, code %s", res, esp_err_to_name(res));
    }
    // Cancel a Classic DISCOVERY
    if (InquirySlot==INQUIRY_SECONDS_ON){
        res =  esp_bt_gap_cancel_discovery();
        if (res!=ESP_OK) ESP_LOGI(TAG_MAIN,"BT Stop Result %d, code %s", res, esp_err_to_name(res));
    }
    // Move Time SLOT
    if (++InquirySlot>=(INQUIRY_SECONDS_ON+INQUIRY_SECONDS_OFF)){
        InquirySlot=0;
        InqCycles++;
    }

    // Suspend 1sec
    vTaskDelay(pdMS_TO_TICKS(1000));
}
vTaskDelete(NULL);

}

// Periodic Report Last Reset Cause void vTaskReportOnTerminal(void pvParameters) { for (;;) { printf("LAST RESET CAUSED BY REASON CODE : %d (Core0) %d (Core1), Inq Cycles %d\r\n", rtc_get_reset_reason(0),rtc_get_reset_reason(1), InqCycles); vTaskDelay(pdMS_TO_TICKS(601000)); } vTaskDelete(NULL); }

void NVS_InitNVS() { esp_err_t ret = nvs_flash_init(); if (ret == ESP_ERR_NVS_NO_FREE_PAGES) { ESP_LOGI(TAG_MAIN, "NO FREE en NVS FLASH INIT %d", ret); ESP_ERROR_CHECK(nvs_flash_erase()); ret = nvs_flash_init(); } ESP_LOGI(TAG_MAIN, "NVS FLASH INIT result %d", ret); }

extern "C" void app_main(void) {

BaseType_t xReturned;

esp_log_level_set(TAG_MAIN, ESP_LOG_INFO);          // Set LOG LEVEL
NVS_InitNVS();                                      // Init NVS

// Init Btooth
esp_bt_controller_config_t cfg = BT_CONTROLLER_INIT_CONFIG_DEFAULT();
ESP_ERROR_CHECK(esp_bt_controller_init(&cfg));
ESP_ERROR_CHECK(esp_bt_controller_enable(ESP_BT_MODE_BTDM));
ESP_ERROR_CHECK(esp_bluedroid_init());
ESP_ERROR_CHECK(esp_bluedroid_enable());
//ESP_ERROR_CHECK(esp_spp_init(ESP_SPP_MODE_CB));       // esto no influye

// Launch periodic Logs on Monitor
xReturned = xTaskCreate(vTaskReportOnTerminal,"TASKREPORT",3*1024,NULL,tskIDLE_PRIORITY,NULL);
configASSERT((xReturned == pdPASS));

// Launch Task to Restart BT CLASSIC each XX Seconds
xReturned = xTaskCreate(vTaskControlBluetooth,"TASKLAUNCHBT",3*1024,NULL,tskIDLE_PRIORITY,NULL);
configASSERT((xReturned == pdPASS));

}

//---------------------------------------------------------------------------------------------------- //---------------------------------------------------------------------------------------------------- //---------------------------------------------------------------------------------------------------- //---------------------------------------------------------------------------------------------------- //---------------------------------------------------------------------------------------------------- // START STOP INQUIRY + SPP NO STARTED ----- CRASH //---------------------------------------------------------------------------------------------------- //---------------------------------------------------------------------------------------------------- //---------------------------------------------------------------------------------------------------- //---------------------------------------------------------------------------------------------------- //---------------------------------------------------------------------------------------------------- // ASSERT_ERR(0), in lm_task.c at line 3997 // Guru Meditation Error: Core 0 panic'ed (Interrupt wdt timeout on CPU0).

// Core 0 register dump: // PC : 0x40082f08 PS : 0x00060d34 A0 : 0x8005351c A1 : 0x3ffd0500
// A2 : 0x00000001 A3 : 0x00000000 A4 : 0x60008048 A5 : 0x3ffbdc0c
// A6 : 0x3ffbdc0c A7 : 0x00000001 A8 : 0x80082f08 A9 : 0x3ffd04e0
// A10 : 0x00000029 A11 : 0x00000029 A12 : 0x00000010 A13 : 0xffffffff
// A14 : 0x00000000 A15 : 0xfffffffb SAR : 0x00000004 EXCCAUSE: 0x00000005
// EXCVADDR: 0x00000000 LBEG : 0x40082eb0 LEND : 0x40082eb7 LCOUNT : 0x00000000

// Backtrace: // 0x40082f05:0x3ffd0500
// 0x40053519:0x3ffd0520 // 0x40083e92:0x3ffd0540 // 0x40019d11:0x3ffd0570 // 0x40055b4d:0x3ffd0590 // 0x40127f4f:0x3ffd05b0 // 0x40128541:0x3ffd05d0 // 0x4008ddb5:0x3ffd0600 // // 0x40082f05: r_assert_err at ??:? // 0x40053519: ?? ??:0 // 0x4008ddb5: vPortTaskWrapper at C:/Users/anurb/esp/esp-idf/components/freertos/xtensa/port.c:143 // 0x40019d11: ?? ??:0 // 0x40055b4d: ?? ??:0 // 0x40127f4f: r_rw_schedule at ??:? // 0x40128541: btdm_controller_task at ??:? // 0x4008ddb5: vPortTaskWrapper at C:/Users/anurb/esp/esp-idf/components/freertos/xtensa/port.c:143 // // Core 1 register dump: // PC : 0x4015df9a PS : 0x00060034 A0 : 0x800d42ad A1 : 0x3ffbc460
// A2 : 0x00000000 A3 : 0x00000000 A4 : 0x00000001 A5 : 0x80000001
// A6 : 0x00000003 A7 : 0x00060023 A8 : 0x800d41fe A9 : 0x3ffbc430
// A10 : 0x00000000 A11 : 0x00060a23 A12 : 0x00060a20 A13 : 0x00060a23
// A14 : 0x00000001 A15 : 0x00000000 SAR : 0x00000000 EXCCAUSE: 0x00000005
// EXCVADDR: 0x00000000 LBEG : 0x00000000 LEND : 0x00000000 LCOUNT : 0x00000000

// Backtrace:0x4015df97:0x3ffbc460 0x400d42aa:0x3ffbc480 0x4008e745:0x3ffbc4a0 0x4008ddb5:0x3ffbc4c0

// ELF file SHA256: 54387e1c21c6e4cd `

munho-espressif commented 3 years ago

Hi @andurbal

Have you solved this problem?

Thanks

andurbal commented 3 years ago

Hi @munho-espressif

No. The Esp resets in a not predictable time. I have worked on isolating the problem and the Code I have upload crashes. It seems that is related with starting and stopping ckassic Discovery. I am not registering to any Gap event in this Code to better isolate the source of the error.

Any ideas Will be welcome, thanks for your message and let me know if you have seen similar behaviour...

ghost commented 3 years ago

Hi, @andurbal

Is it possible to delay about 1s before you call esp_bt_gap_start_scanning(); ? I have met another issue about discovery and the delay fix that on the app layer.

May it helps.

Thanks

andurbal commented 3 years ago

Hi, @Wth-Esp

we are doing it. For example 2 seconds scanning, 2 seconds standby..., and start again. The ASSERT_ERR(0), in lm_task.c at line 3997 appears in a random time . Thanks for your interest.

Maybe the esspressif team should have a look to this ASSERT fail, beacause I think something is not working as expected in the lm_task.

Again, thanks, your help and interest is welcomed.

ghost commented 3 years ago

Hi, @andurbal

This ASSERT means that BT Controller has done the inquiry procedure and set the LM Inquiry status to Idle, but still receives an Inquiry Response again. I think a practical solution is to ignore the Inquiry Response and return when the LM Inquiry status is Idle.

I will give you a patch to do implement this solution, please wait my update.

Thanks

ghost commented 3 years ago

Hi , @andurbal

Here is the patch lib, please replace the lib in path $IDF_PATH/components/bt/controller/lib/esp32 with it. libbtdm_app.zip

Thanks

andurbal commented 3 years ago

Many thanks, I will put it under test inmediately. I will tell you results.

andurbal commented 3 years ago

All weekend working without any assert error, thanks for your help. I think this change needs to be included in a Esp Idf release.

ghost commented 3 years ago

@andurbal Thanks for your effort to verify the fix, I will fix this in the release IDF ASAP.

andurbal commented 2 years ago

Dear @Wth-Esp

do you know if this issue was solved in ESP IDF 4.3 ?

Thanks in advance.

andurbal commented 2 years ago

The bug is still present in ESP-IDF 4.3

ASSERT_ERR(0), in lm_task.c at line 3997 occurs AGAIN....

But replacing libbtdm_app.zip as I have done in previous version ESP-IDF 4.2 gives a Bluetooth Controller initialization error....

esp_bt_controller_config_t cfg = BT_CONTROLLER_INIT_CONFIG_DEFAULT(); BT_result = esp_bt_controller_init(&cfg));

Gives a BT_result of ESP_ERR_INVALID_ARG

Any ideas?

ghost commented 2 years ago

Hi, @andurbal

We have fixed it on the internal branch, but may it hasn't synced on Github. Please wait several days and then update your working branch.

Thanks

andurbal commented 2 years ago

Thanks.

We work only with stable versions...as our development is focused on a commercial product. This means that the patch wont be available on 4.3 ?

ghost commented 2 years ago

We should merge it on the master branch and if the master branch have this fix and we can raise an MR for branch release/v4.3 and run a test case before the commit is added on the release version.

We provide you another lib for the release/v4.3 branch, and we will also fix the issue on the next version of release v4.3 and all other release version.

andurbal commented 2 years ago

OK. Thanks for your work. Meanwhile I wait for the another lib for the release/v4.3 branch

xiongweichao commented 2 years ago

Hi @andurbal ,

Here is the patch lib, please replace the lib in path $IDF_PATH/components/bt/controller/lib_esp32/esp32 with it. This patch lib is based on release/v4.3 branch. libbtdm_app.zip

Thanks