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

Reboot/Crash after Pause command #559

Closed harryberlin closed 1 month ago

harryberlin commented 1 month ago

Problem Description

Sometimes the device reboots or crashes after pause command. Tried to get esp-idf-monitor installed, but without success at the moment.

22:22:45.977> ets Jun  8 2016 00:22:57
22:22:45.977> 
22:22:45.977> rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
22:22:45.977> flash read err, 1000
22:22:45.977> ets_main.c 371 
22:22:46.346> ets Jun  8 2016 00:22:57
22:22:46.346> 
22:22:46.346> rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
22:22:46.346> configsip: 0, SPIWP:0xee
22:22:46.346> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
22:22:46.346> mode:DIO, clock div:1
22:22:46.346> load:0x3fff0018,len:4
22:22:46.346> load:0x3fff001c,len:1216
22:22:46.346> ho 0 tail 12 room 4
22:22:46.346> load:0x40078000,len:10944
22:22:46.346> load:0x40080400,len:6388
22:22:46.346> entry 0x400806b4
22:22:48.314> Connecting
22:22:49.838> Connected
22:22:57.176> Started
22:23:15.824> Suspended
22:23:19.668> Started
22:23:45.127> Suspended
22:23:45.127> Guru Meditation Error: Core  1 panic'ed (LoadProhibited). Exception was unhandled.
22:23:45.127> Core 1 register dump:
22:23:45.127> PC      : 0x401620c6  PS      : 0x00060d30  A0      : 0x800d2265  A1      : 0x3fff06c0  
22:23:45.127> A2      : 0x00000000  A3      : 0x3ffed84c  A4      : 0x00000200  A5      : 0x3fff06f4  
22:23:45.196> A6      : 0xffffffff  A7      : 0x00000000  A8      : 0x00000001  A9      : 0x00000002  
22:23:45.196> A10     : 0x3fff06f8  A11     : 0x00000010  A12     : 0x00000005  A13     : 0x00000020  
22:23:45.196> A14     : 0x00000020  A15     : 0x3ffbbdf9  SAR     : 0x00000000  EXCCAUSE: 0x0000001c  
22:23:45.196> EXCVADDR: 0x00000018  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0x00000000  
22:23:45.196> 
22:23:45.196> ELF file SHA256: 0000000000000000
22:23:45.196> 
22:23:45.196> Backtrace: 0x401620c6:0x3fff06c0 0x400d2262:0x3fff06f0 0x400d2315:0x3fff0760 0x4019bdd5:0x3fff0780 0x400d4c89:0x3fff07a0 0x400d4b50:0x3fff07c0 0x400d4d86:0x3fff07e0 0x400d4b19:0x3fff0810 0x40090caa:0x3fff0830
22:23:45.196> 
22:23:45.196> Rebooting...
22:23:45.196> ets Jun  8 2016 00:22:57
22:23:45.196> 
22:23:45.196> rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
22:23:45.196> configsip: 0, SPIWP:0xee
22:23:45.196> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
22:23:45.328> mode:DIO, clock div:1
22:23:45.328> load:0x3fff0018,len:4
22:23:45.328> load:0x3fff001c,len:1216
22:23:45.328> ho 0 tail 12 room 4
22:23:45.328> load:0x40078000,len:10944
22:23:45.328> load:0x40080400,len:6388
22:23:45.328> entry 0x400806b4
22:23:47.075> Connecting
22:23:48.445> Connected
22:23:58.125> Started

Device Description

ESP32 WROOM 32D DevKitC_V4 + purple PCM 5102A Arduino IDE with ESP32 by Espressif Systems - Board Library V1.0.6 -> because V2.0.16 gets flash size overflow after compiling BT Audio Device: Umidigi A9 Pro, Andorid11

Sketch

/*
  Streaming Music from Bluetooth

  Copyright (C) 2020 Phil Schatzmann
  This program is free software: you can redistribute it and/or modify
  it under the terms of the GNU General Public License as published by
  the Free Software Foundation, either version 3 of the License, or
  (at your option) any later version.
  This program is distributed in the hope that it will be useful,
  but WITHOUT ANY WARRANTY; without even the implied warranty of
  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  GNU General Public License for more details.
  You should have received a copy of the GNU General Public License
  along with this program.  If not, see <http://www.gnu.org/licenses/>.
*/

// ==> Example which shows how to use the built in ESP32 I2S < 3.0.0
#include "AudioTools.h"
#include "BluetoothA2DPSinkQueued.h"

I2SStream i2s;
BluetoothA2DPSinkQueued a2dp_sink(i2s);

// for esp_a2d_connection_state_t see https://docs.espressif.com/projects/esp-idf/en/latest/esp32/api-reference/bluetooth/esp_a2dp.html#_CPPv426esp_a2d_connection_state_t
void connection_state_changed(esp_a2d_connection_state_t state, void *ptr){
  Serial.println(a2dp_sink.to_str(state));
}

// for esp_a2d_audio_state_t see https://docs.espressif.com/projects/esp-idf/en/latest/esp32/api-reference/bluetooth/esp_a2dp.html#_CPPv421esp_a2d_audio_state_t
void audio_state_changed(esp_a2d_audio_state_t state, void *ptr){
  Serial.println(a2dp_sink.to_str(state));
}

void setup() {
  Serial.begin(115200);

  auto cfg = i2s.defaultConfig();
  cfg.pin_bck = 26;
  cfg.pin_ws = 25;
  cfg.pin_data = 22;
  i2s.begin(cfg);

  a2dp_sink.set_on_connection_state_changed(connection_state_changed);
  a2dp_sink.set_on_audio_state_changed(audio_state_changed);
  a2dp_sink.set_auto_reconnect(true);
  a2dp_sink.start("AVR-IBus-BT");

  delay(50);
  a2dp_sink.set_volume(0xFF);

}

void loop() {
  if (Serial.available()) {
    switch (Serial.read()) {
      case 'n':
        a2dp_sink.next();
        break;
      case 'p':
        a2dp_sink.previous();
        break;
      case 'r':
        a2dp_sink.rewind();
        break;
      case 'f':
        a2dp_sink.fast_forward();
        break;
      case 's':
        a2dp_sink.pause();
        break;
      case 'm':
        a2dp_sink.play();
        break;

    }
  }
}


### Other Steps to Reproduce

_No response_

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

1.0.6

### I have checked existing issues, discussions and online documentation

- [X] I confirm I have checked existing issues, discussions and online documentation
pschatzmann commented 1 month ago

Please decode your Backtrace to determine where your issue is coming from ? What partition scheme did you select ? I suggest to use an actual Version: 1.0.6 does not make any sense. The actual version is 2.0.17 !

harryberlin commented 1 month ago

Thanks for reply.

So, i did set partition to Huge APP (3MB/1MB). Updated esp32 to 2.0.16 Updated ESP32_A2DP to last commit, since 3 days Did install Exception Decoder: https://github.com/me-no-dev/EspExceptionDecoder

Could you help to find the roblem?

PC: 0x400d9352: i2s_write at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/driver/i2s.c line 2129
EXCVADDR: 0x00000018

Decoding stack results
0x400d934f: i2s_write at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/driver/i2s.c line 2129
0x400d2e1d: audio_tools::I2SDriverESP32::writeBytes(void const*, unsigned int) at C:\Users\Christian\Documents\Arduino\libraries\arduino-audio-tools\src/AudioI2S/I2SESP32.h line 100
0x400d2ed5: audio_tools::I2SStream::write(unsigned char const*, unsigned int) at C:\Users\Christian\Documents\Arduino\libraries\arduino-audio-tools\src/AudioI2S/I2SStream.h line 115
0x401bbabd: BluetoothA2DPOutputAudioTools::write(unsigned char const*, unsigned int) at C:\Users\Christian\Documents\Arduino\libraries\ESP32-A2DP\src\BluetoothA2DPOutput.cpp line 213
0x400d5945: BluetoothA2DPOutputDefault::write(unsigned char const*, unsigned int) at C:\Users\Christian\Documents\Arduino\libraries\ESP32-A2DP\src/BluetoothA2DPOutput.h line 178
0x400d57fe: BluetoothA2DPSink::i2s_write_data(unsigned char const*, unsigned int) at C:\Users\Christian\Documents\Arduino\libraries\ESP32-A2DP\src\BluetoothA2DPSink.cpp line 1241
0x400d5a42: BluetoothA2DPSinkQueued::i2s_task_handler(void*) at C:\Users\Christian\Documents\Arduino\libraries\ESP32-A2DP\src\BluetoothA2DPSinkQueued.cpp line 74
0x400d57c9: ccall_i2s_task_handler(void*) at C:\Users\Christian\Documents\Arduino\libraries\ESP32-A2DP\src\BluetoothA2DPSink.cpp line 1171
pschatzmann commented 1 month ago

Hmm, it's crashing in some Espressif functionality. Did you try to replace the BluetoothA2DPSinkQueued with BluetoothA2DPSink to reduce the complexity ?

Maybe setting the log level to info for the A2DP and the AudioTools might reveal a bit better what is going on...

harryberlin commented 1 month ago

I will try, but i switched to queue, because had few crackle before during playback

pschatzmann commented 1 month ago

I committed a correction to the AudioTools which would prevent that any data is written to i2s when it is not active, or there is no valid data.

Just as a wild guess that maybe this might help...

harryberlin commented 1 month ago

added some prints about the state. without queue. did not crash during last 10min test, but few crackle in the audio.

swapped back to queue and got the error

PC: 0x400d9252: i2s_write at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/driver/i2s.c line 2129
EXCVADDR: 0x00000018

Decoding stack results
0x400d924f: i2s_write at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/driver/i2s.c line 2129
0x400d2d81: audio_tools::I2SDriverESP32::writeBytes(void const*, unsigned int) at C:\Users\Christian\Documents\Arduino\libraries\arduino-audio-tools\src/AudioI2S/I2SESP32.h line 100
0x400d2e39: audio_tools::I2SStream::write(unsigned char const*, unsigned int) at C:\Users\Christian\Documents\Arduino\libraries\arduino-audio-tools\src/AudioI2S/I2SStream.h line 115
0x401bb92d: BluetoothA2DPOutputAudioTools::write(unsigned char const*, unsigned int) at C:\Users\Christian\Documents\Arduino\libraries\ESP32-A2DP\src\BluetoothA2DPOutput.cpp line 213
0x400d58e1: BluetoothA2DPOutputDefault::write(unsigned char const*, unsigned int) at C:\Users\Christian\Documents\Arduino\libraries\ESP32-A2DP\src/BluetoothA2DPOutput.h line 178
0x400d579a: BluetoothA2DPSink::i2s_write_data(unsigned char const*, unsigned int) at C:\Users\Christian\Documents\Arduino\libraries\ESP32-A2DP\src\BluetoothA2DPSink.cpp line 1241
0x400d59de: BluetoothA2DPSinkQueued::i2s_task_handler(void*) at C:\Users\Christian\Documents\Arduino\libraries\ESP32-A2DP\src\BluetoothA2DPSinkQueued.cpp line 74
0x400d5765: ccall_i2s_task_handler(void*) at C:\Users\Christian\Documents\Arduino\libraries\ESP32-A2DP\src\BluetoothA2DPSink.cpp line 1171

log from serial port

21:01:16.923 -> ets Jun  8 2016 00:22:57
21:01:16.923 -> 
21:01:16.923 -> rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
21:01:16.923 -> configsip: 0, SPIWP:0xee
21:01:16.923 -> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
21:01:16.923 -> mode:DIO, clock div:1
21:01:16.923 -> load:0x3fff0030,len:1344
21:01:16.923 -> load:0x40078000,len:13964
21:01:16.923 -> load:0x40080400,len:3600
21:01:16.923 -> entry 0x400805f0
21:01:32.946 -> Connecting
21:01:33.046 -> Connected
21:01:40.810 -> Started
21:01:48.768 -> CMD:pause
21:01:51.316 -> CMD:play
21:01:56.073 -> CMD:pause
21:01:59.223 -> Suspended
21:02:00.677 -> CMD:play
21:02:00.877 -> Started
21:02:07.180 -> CMD:prev
21:02:09.426 -> CMD:prev
21:02:09.526 -> CMD:prev
21:02:13.425 -> CMD:pause
21:02:16.577 -> Suspended
21:02:18.202 -> CMD:pause
21:02:19.703 -> CMD:play
21:02:19.850 -> Started
21:02:22.251 -> CMD:pause
21:02:22.351 -> CMD:pause
21:02:22.451 -> CMD:pause
21:02:24.552 -> CMD:play
21:02:57.642 -> CMD:pause
21:03:00.792 -> Suspended
21:03:02.693 -> CMD:play
21:03:02.846 -> Started
21:03:27.824 -> CMD:next
21:03:27.924 -> CMD:pause
21:03:31.026 -> Suspended
21:03:32.027 -> CMD:play
21:03:32.127 -> Started
21:03:36.581 -> CMD:pause
21:03:39.686 -> Suspended
21:03:39.686 -> Guru Meditation Error: Core  1 panic'ed (LoadProhibited). Exception was unhandled.
21:03:39.686 -> 
21:03:39.686 -> Core  1 register dump:
21:03:39.686 -> PC      : 0x400d9252  PS      : 0x00060030  A0      : 0x800d2d84  A1      : 0x3fff3100  
21:03:39.686 -> A2      : 0x00000000  A3      : 0x3ffed7e4  A4      : 0x000001a0  A5      : 0x3fff3144  
21:03:39.733 -> A6      : 0xffffffff  A7      : 0x3ffc40b4  A8      : 0x00000000  A9      : 0x3fff3100  
21:03:39.733 -> A10     : 0x3fff3148  A11     : 0x00000010  A12     : 0x8008401e  A13     : 0x3ffcbb20  
21:03:39.733 -> A14     : 0x00000001  A15     : 0x3fff2b00  SAR     : 0x00000000  EXCCAUSE: 0x0000001c  
21:03:39.733 -> EXCVADDR: 0x00000018  LBEG    : 0x40091448  LEND    : 0x4009145e  LCOUNT  : 0x00000000  
21:03:39.733 -> 
21:03:39.733 -> 
21:03:39.733 -> Backtrace: 0x400d924f:0x3fff3100 0x400d2d81:0x3fff3140 0x400d2e39:0x3fff31b0 0x401bb92d:0x3fff31d0 0x400d58e1:0x3fff31f0 0x400d579a:0x3fff3210 0x400d59de:0x3fff3230 0x400d5765:0x3fff3260
21:03:39.786 -> 
21:03:39.786 -> 
21:03:39.786 -> 
21:03:39.786 -> 
21:03:39.786 -> ELF file SHA256: 5892bcc32f74a630
21:03:39.786 -> 
21:03:39.933 -> Rebooting...
21:03:39.933 -> ets Jun  8 2016 00:22:57
21:03:39.986 -> 
21:03:39.986 -> rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
21:03:39.986 -> configsip: 0, SPIWP:0xee
21:03:39.986 -> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
21:03:39.986 -> mode:DIO, clock div:1
21:03:39.986 -> load:0x3fff0030,len:1344
21:03:39.986 -> load:0x40078000,len:13964
21:03:39.986 -> load:0x40080400,len:3600
21:03:39.986 -> entry 0x400805f0
harryberlin commented 1 month ago

oh moment, did not update audio tools. thouht the change was integrated already.

pschatzmann commented 1 month ago

I have the feeling that the Suspended is closing i2s and because there is a queue there is still some data sent afterwards. You can try to confirm this by activating the logging in the AudioTools.

My latest correction might help. Did you already try ?

harryberlin commented 1 month ago

i'm testing, give me some minutes.

audio-tools is updated now. how to enable logging? did add these lines to my sketch, but no extra messages in serial monitor.

#define USE_AUDIO_LOGGING true

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

#define LOG_LEVEL AudioLogger::Debug
#define LOG_STREAM Serial
pschatzmann commented 1 month ago

AudioLogger::instance().begin(Serial, AudioLogger::Info);

harryberlin commented 1 month ago

no crashes during the last 5 minutes, but no audio from 21:39:45.145 -> Started to 21:40:28.541 -> Disconnected

log: .... can't copy the full logged rows from serial monitor :(

harryberlin commented 1 month ago

i think there are some bad chars included sorry for the scrrenshots:

grafik

grafik

grafik

grafik

grafik

grafik

grafik

grafik

grafik

grafik

grafik

pschatzmann commented 1 month ago

I did some testing today and did not notice any issues.

Please use the latest changes in the A2DP library and explain again what you think is still wrong...

harryberlin commented 1 month ago

i will test some more time. after this i will place reply.

harryberlin commented 1 month ago

should be fine now. thank you for your help. :)