search

pschatzmann / ESP32-A2DP

A Simple ESP32 Bluetooth A2DP Library (to implement a Music Receiver or Sender) that supports Arduino, PlatformIO and Espressif IDF
Apache License 2.0
1.55k stars 261 forks source link

Freezes on init_bluetooth(): [BT_AV] init_bluetooth #565

Closed theminp closed 1 month ago

theminp commented 1 month ago

Problem Description

Freezes on init_bluetooth(): [BT_AV] init_bluetooth

Device Description

ESP32 WROOM TYPEC

Sketch

rst:0xc (SW_CPU_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:1
load:0x3fff0030,len:1344
load:0x40078000,len:13964
load:0x40080400,len:3600
entry 0x400805f0
[    18][D][esp32-hal-cpu.c:244] setCpuFrequencyMhz(): PLL: 480 / 2 = 240 Mhz, APB: 80000000 Hz
[    33][D][BluetoothA2DPSink.cpp:90] start(): [BT_AV] start
[    38][I][BluetoothA2DPCommon.cpp:246] log_free_heap(): [BT_AV] Available Heap: 252048
[    48][I][BluetoothA2DPSink.cpp:102] start(): [BT_AV] Device name will be set to 'InternalDAC'
[    59][D][BluetoothA2DPSink.cpp:1063] init_nvs(): [BT_AV] init_nvs
[    67][D][BluetoothA2DPCommon.cpp:152] get_last_connection(): [BT_AV] get_last_connection
[    78][I][BluetoothA2DPCommon.cpp:166] get_last_connection(): [BT_AV] nvs_blob does not exist
[    88][D][BluetoothA2DPCommon.cpp:175] get_last_connection(): [BT_AV] => 00:00:00:00:00:00
[    99][I][BluetoothA2DPSink.cpp:165] init_i2s(): [BT_AV] init_i2s
[   107][I][BluetoothA2DPOutput.cpp:199] begin(): [BT_AV] begin
[   116][D][BluetoothA2DPSink.cpp:186] init_bluetooth(): [BT_AV] init_bluetooth

Other Steps to Reproduce

Test all

Provide your Version of the EP32 Arduino Core (or the IDF Version)

2.0.16

I have checked existing issues, discussions and online documentation

pschatzmann commented 1 month ago

You did not indicate what sketch or conditions are causing this so I assume it is a simple A2DP Sink w/o any additional logic. I have never seen anything like this, so I would guess that it is a hardware issue. Did you try with another ESP32 ?

loganYdid commented 1 month ago

I am seeing the exact same issue. Strangely it was working before but yesterday after reflashing the code I stopped being able to connect over bluetooth so I reverted back to one of your examples to try and diagnose the issue. I also tried running on 2 other ESP32-WROOM-32 modules but I got the same result every time. SKETCH:

#include "AudioTools.h"
#include "BluetoothA2DPSink.h"

AnalogAudioStream out;
BluetoothA2DPSink a2dp_sink(out);

void setup() {
    a2dp_sink.start("MyMusic");
}

void loop() {
  delay(10);
}

PIO CONFIGURATION

[platformio]
description = A2DP Example
default_envs = esp32dev

[env:esp32dev]
platform = espressif32
board = esp32dev
framework = arduino
lib_deps = 
    https://github.com/pschatzmann/ESP32-A2DP
    https://github.com/pschatzmann/arduino-audio-tools.git

build_flags = -DCORE_DEBUG_LEVEL=5
monitor_speed = 115200
monitor_filters = esp32_exception_decoder
board_build.partitions = huge_app.csv

CONSOLE OUTPUT

--- Terminal on COM3 | 115200 8-N-1
--- Available filters and text transformations: colorize, debug, default, direct, esp32_exception_decoder, hexlify, log2file, nocontrol, printable, send_on_enter, time
--- More details at https://bit.ly/pio-monitor-filters
--- Quit: Ctrl+C | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H
[    10][D][esp32-hal-cpu.c:244] setCpuFrequencyMhz(): PLL: 480 / 2 = 240 Mhz, APB: 80000000 Hz
[    27][D][BluetoothA2DPSink.cpp:90] start(): [BT_AV] start
[    33][I][BluetoothA2DPCommon.cpp:246] log_free_heap(): [BT_AV] Available Heap: 254928
[    43][I][BluetoothA2DPSink.cpp:102] start(): [BT_AV] Device name will be set to 'MyMusic'
[    53][D][BluetoothA2DPSink.cpp:1063] init_nvs(): [BT_AV] init_nvs
[    62][D][BluetoothA2DPCommon.cpp:152] get_last_connection(): [BT_AV] get_last_connection
[    72][I][BluetoothA2DPCommon.cpp:166] get_last_connection(): [BT_AV] nvs_blob does not exist
[    83][D][BluetoothA2DPCommon.cpp:175] get_last_connection(): [BT_AV] => 00:00:00:00:00:00
[    93][I][BluetoothA2DPSink.cpp:165] init_i2s(): [BT_AV] init_i2s
[   101][I][BluetoothA2DPOutput.cpp:199] begin(): [BT_AV] begin
[   111][D][BluetoothA2DPSink.cpp:186] init_bluetooth(): [BT_AV] init_bluetooth
loganYdid commented 1 month ago

I followed the thread to BluetoothA2DPCommon.cpp where in the the bt_start() function there is a while loop that is meant to hang until esp_bt_controller_get_status() == ESP_BT_CONTROLLER_STATUS_IDLE. In our case it seems esp_bt_controller_init(&cfg) seems to be unsuccessful so we never clear that loop. I printed the results from esp_bt_controller_init and I get ERROR: 259 which is ESP_ERR_INVALID_STATE I am not sure what this means.

THE FUNCTION IN QUESTION

/**
 * @brief Startup logic as implemented by Arduino - This is not available if we use this library outside of Arduino
 * 
 * @return true 
 * @return false 
 */
bool BluetoothA2DPCommon::bt_start(){
    esp_bt_controller_config_t cfg = BT_CONTROLLER_INIT_CONFIG_DEFAULT();
    if(esp_bt_controller_get_status() == ESP_BT_CONTROLLER_STATUS_ENABLED){
        ESP_LOGI(BT_APP_TAG, "BT was already enabled");
        return true;
    }
    if(esp_bt_controller_get_status() == ESP_BT_CONTROLLER_STATUS_IDLE){
        esp_err_t error = esp_bt_controller_init(&cfg);
        printf("ERROR: %d\n", error);
        while(esp_bt_controller_get_status() == ESP_BT_CONTROLLER_STATUS_IDLE){}
    }
    if(esp_bt_controller_get_status() == ESP_BT_CONTROLLER_STATUS_INITED){
        if (esp_bt_controller_enable(bt_mode)) {
            ESP_LOGE(BT_APP_TAG, "BT Enable failed");
            return false;
        }
    }
    if(esp_bt_controller_get_status() == ESP_BT_CONTROLLER_STATUS_ENABLED){
        ESP_LOGI(BT_APP_TAG, "BT enabled");
        return true;
    }
    ESP_LOGE(BT_APP_TAG, "BT Start failed");
    return false;
}

RESULT

[    10][D][esp32-hal-cpu.c:244] setCpuFrequencyMhz(): PLL: 480 / 2 = 240 Mhz, APB: 80000000 Hz
[    27][D][BluetoothA2DPSink.cpp:90] start(): [BT_AV] start
[    33][I][BluetoothA2DPCommon.cpp:246] log_free_heap(): [BT_AV] Available Heap: 254928
[    43][I][BluetoothA2DPSink.cpp:102] start(): [BT_AV] Device name will be set to 'MyMusic'
[    53][D][BluetoothA2DPSink.cpp:1063] init_nvs(): [BT_AV] init_nvs
[    62][D][BluetoothA2DPCommon.cpp:152] get_last_connection(): [BT_AV] get_last_connection
[    72][I][BluetoothA2DPCommon.cpp:166] get_last_connection(): [BT_AV] nvs_blob does not exist
[    83][D][BluetoothA2DPCommon.cpp:175] get_last_connection(): [BT_AV] => 00:00:00:00:00:00
[    93][I][BluetoothA2DPSink.cpp:165] init_i2s(): [BT_AV] init_i2s
[   101][I][BluetoothA2DPOutput.cpp:199] begin(): [BT_AV] begin
[   111][D][BluetoothA2DPSink.cpp:186] init_bluetooth(): [BT_AV] init_bluetooth
ERROR: 259
pschatzmann commented 1 month ago

It seems that this is a bug that has been introduced in one of my last commits. I committed a correction which is calling the Arduino btStart() again...

theminp commented 1 month ago

It seems that this is a bug that has been introduced in one of my last commits. I committed a correction which is calling the Arduino btStart() again...

Thank you very much for the decision. I'll be at the computer for a couple of hours and check. That's exactly what this problem looked like, I added blink to the Loop loop for the test, and it didn't work when I started Bluetooth

pschatzmann commented 1 month ago

For the initialization outside of Arduino, I am printing the error codes now as well

In Arduino I am getting the expected output now:


09:33:40.950 -> [    18][I][BluetoothA2DPCommon.cpp:246] log_free_heap(): [BT_AV] Available Heap: 207452
09:33:40.983 -> [    26][I][BluetoothA2DPSink.cpp:102] start(): [BT_AV] Device name will be set to 'AudioKit'
09:33:40.983 -> [    35][I][BluetoothA2DPCommon.cpp:166] get_last_connection(): [BT_AV] nvs_blob does not exist
09:33:40.983 -> [    43][I][BluetoothA2DPSink.cpp:165] init_i2s(): [BT_AV] init_i2s
09:33:40.983 -> [    49][I][BluetoothA2DPOutput.cpp:199] begin(): [BT_AV] begin
09:33:41.014 -> [    56][I][esp32-hal-i2c.c:75] i2cInit(): Initialising I2C Master: sda=33 scl=32 freq=100000
09:33:41.110 -> [   159][I][BluetoothA2DPSink.cpp:191] init_bluetooth(): [BT_AV] controller initialized
09:33:41.433 -> [   484][I][BluetoothA2DPSink.cpp:200] init_bluetooth(): [BT_AV] bluedroid initialized
09:33:41.497 -> [   555][I][BluetoothA2DPSink.cpp:209] init_bluetooth(): [BT_AV] bluedroid enabled
09:33:41.497 -> [   563][I][BluetoothA2DPCommon.cpp:347] set_scan_mode_connectable(): [BT_AV] set_scan_mode_connectable true
09:33:41.528 -> [   571][I][BluetoothA2DPSink.cpp:433] app_gap_callback(): [BT_AV] event: 10
09:33:41.528 -> [   579][I][BluetoothA2DPSink.cpp:516] av_hdl_a2d_evt(): [BT_AV] A2DP PROF STATE: Init Compl
09:33:41.528 -> 
09:33:41.528 -> [   579][I][BluetoothA2DPSink.cpp:433] app_gap_callback(): [BT_AV] event: 10
09:33:41.528 -> [   595][I][BluetoothA2DPSink.cpp:433] app_gap_callback(): [BT_AV] event: 10
09:33:41.560 -> [   595][I][BluetoothA2DPSink.cpp:160] start(): [BT_AV] IDF Version 4.4
09:33:41.560 -> [   608][I][BluetoothA2DP[S i n k6.0c8p]p[:I4]3[3B]l uaeptpo_ogtahpA_2cDaPlClobmamcokn(.)c:p p[:B2T4_6A]V ]l oegv_efnrte:e _1h0e
09:33:41.560 -> p(): [BT_AV] Available Heap: 79580