espressif / esp-adf

Espressif Audio Development Framework
Other
1.54k stars 677 forks source link

When running VoIP example in LyraT_Mini_v1.2 get this Runtime error: ***ERROR*** A stack overflow in task OUT_iis has been detected. (AUD-5273) #1169

Closed migmelccs closed 6 months ago

migmelccs commented 6 months ago

Environment

Problem Description

I have been trying to run the VoIP example and cannot success in make it to behave as it is suppose to. First I used ESP-IDF v5.2.1 combined with ESP-ADF master. There is a runtime problem because of mixing between deprecated i2s.h and the new headers i2s_std.h, etc., that depend on the framework and there is nothing I can do about. ESP-IDF framework uses the new headers, while ESP-ADF (stream.h or so) still uses the deprecated one.

But the report is about this: I have moved to ESP-IDF v4.4.7 combined with esp-adf-master, followed all the recommended in the README file, but a new problem arose (as shown in the title) even when I applied the recommended patch idf_v4.4_freertos.patch as suggested. The device keeps rebooting after the stack overflow message and after several reboots, finally it hangs so it is necessary to manually reset it to start over. By repeatedly pressing the keys randomly it sometimes stops rebooting and then is possible to make calls to a client such as Zoiper. However after some time it starts rebooting again. Also, calling from Zoiper to esp32 cause the device start rebooting again.

Expected Behavior

After initialization it should be ready to make and receive calls

Actual Behavior

Application periodically resets after "A stack overflow in task OUT_iis has been detected" message, and eventually hangs

Steps to Reproduce

  1. step1: setup SIP server previously (If SIP server(FreeSWTICH) is not set, neither stack overflow nor rebooting happens)
  2. ... Upload the code and set monitor. It will immediately start rebooting

VoIP Setup

Code to Reproduce This Issue

The code is the unmodified example loaded with ESP ADF at: examples/protocols/voip The only modification is relative to WiFi credentials and SIP ID/SIP server IP

Debug Logs

I added 2 cycles because the first time looks different from the others

E:\esp-idf-v4.4.7\esp-adf-master\examples\protocols\voip>idf.py flash -p COM5 -b 921600 monitor
Executing action: flash
Running ninja in directory E:\esp-idf-v4.4.7\esp-adf-master\examples\protocols\voip\build
Executing "ninja flash"...
[0/1] Re-running CMake...
-- ccache will be used for faster recompilation
-- Building ESP-IDF components for target esp32
NOTICE: Skipping optional dependency: espressif/jsmn
NOTICE: Skipping optional dependency: espressif/nghttp
NOTICE: Skipping optional dependency: espressif/usb_stream
Processing 3 dependencies:
[1/3] espressif/esp-dsp (1.4.12)
[2/3] espressif/esp32-camera (2.0.8)
[3/3] idf (4.4.7)
NOTICE: Skipping optional dependency: espressif/jsmn
NOTICE: Skipping optional dependency: espressif/nghttp
NOTICE: Skipping optional dependency: espressif/usb_stream
-- Project sdkconfig file E:/esp-idf-v4.4.7/esp-adf-master/examples/protocols/voip/sdkconfig
Loading defaults file E:/esp-idf-v4.4.7/esp-adf-master/examples/protocols/voip/sdkconfig.defaults...
E:/esp-idf-v4.4.7/esp-adf-master/examples/protocols/voip/sdkconfig.defaults:2 CONFIG_FLASHMODE_QIO was replaced with CONFIG_ESPTOOLPY_FLASHMODE_QIO
E:/esp-idf-v4.4.7/esp-adf-master/examples/protocols/voip/sdkconfig.defaults:27 CONFIG_SPIRAM_SUPPORT was replaced with CONFIG_ESP32_SPIRAM_SUPPORT
E:/esp-idf-v4.4.7/esp-adf-master/examples/protocols/voip/sdkconfig.defaults:52 CONFIG_UDP_RECVMBOX_SIZE was replaced with CONFIG_LWIP_UDP_RECVMBOX_SIZE
Loading defaults file E:/esp-idf-v4.4.7/esp-adf-master/examples/protocols/voip/sdkconfig.defaults.esp32...
-- App "voip_app" version: v2.6-84-g75c9aed9-dirty
-- Adding linker script E:/esp-idf-v4.4.7/esp-adf-master/examples/protocols/voip/build/esp-idf/esp_system/ld/memory.ld
-- Adding linker script E:/esp-idf-v4.4.7/components/esp_system/ld/esp32/sections.ld.in
-- Adding linker script E:/esp-idf-v4.4.7/components/esp_rom/esp32/ld/esp32.rom.ld
-- Adding linker script E:/esp-idf-v4.4.7/components/esp_rom/esp32/ld/esp32.rom.api.ld
-- Adding linker script E:/esp-idf-v4.4.7/components/esp_rom/esp32/ld/esp32.rom.libgcc.ld
-- Adding linker script E:/esp-idf-v4.4.7/components/esp_rom/esp32/ld/esp32.rom.newlib-data.ld
-- Adding linker script E:/esp-idf-v4.4.7/components/esp_rom/esp32/ld/esp32.rom.syscalls.ld
-- Adding linker script E:/esp-idf-v4.4.7/components/soc/esp32/ld/esp32.peripherals.ld
-- Chip is esp32, E:/esp-idf-v4.4.7/esp-adf-master/components/esp-adf-libs
-- Current board name is CONFIG_ESP_LYRAT_MINI_V1_1_BOARD
-- Components: adf_utils app_trace app_update asio audio_board audio_flash_tone audio_hal audio_pipeline audio_recorder audio_sal audio_stream av_stream battery_service bluetooth_service bootloader bootloader_support bt cbor clouds cmock coap console coredump_upload_service cxx display_service driver dueros_service efuse esp-adf-libs esp-sr esp-tls esp32 esp_actions esp_adc_cal esp_codec_dev esp_common esp_dispatcher esp_eth esp_event esp_event_cast esp_gdbstub esp_hid esp_http_client esp_http_server esp_https_ota esp_https_server esp_hw_support esp_ipc esp_lcd esp_local_ctrl esp_netif esp_peripherals esp_phy esp_pm esp_ringbuf esp_rom esp_serial_slave_link esp_system esp_timer esp_websocket_client esp_wifi espcoredump espressif__esp-dsp espressif__esp32-camera esptool_py expat fatfs freemodbus freertos hal heap idf_test ieee802154 input_key_service jsmn json libsodium log lwip main mbedtls mdns mqtt newlib nghttp nvs_flash openssl openthread ota_service partition_table perfmon playlist protobuf-c protocomm pthread sdmmc soc spi_flash spiffs tcp_transport tcpip_adapter tinyusb tone_partition ulp unity usb vfs wear_levelling wifi_provisioning wifi_service wpa_supplicant xtensa
-- Component paths: E:/esp-idf-v4.4.7/esp-adf-master/components/adf_utils E:/esp-idf-v4.4.7/components/app_trace E:/esp-idf-v4.4.7/components/app_update E:/esp-idf-v4.4.7/components/asio E:/esp-idf-v4.4.7/esp-adf-master/components/audio_board E:/esp-idf-v4.4.7/esp-adf-master/examples/protocols/components/audio_flash_tone E:/esp-idf-v4.4.7/esp-adf-master/components/audio_hal E:/esp-idf-v4.4.7/esp-adf-master/components/audio_pipeline E:/esp-idf-v4.4.7/esp-adf-master/components/audio_recorder E:/esp-idf-v4.4.7/esp-adf-master/components/audio_sal E:/esp-idf-v4.4.7/esp-adf-master/components/audio_stream E:/esp-idf-v4.4.7/esp-adf-master/examples/protocols/components/av_stream E:/esp-idf-v4.4.7/esp-adf-master/components/battery_service E:/esp-idf-v4.4.7/esp-adf-master/components/bluetooth_service E:/esp-idf-v4.4.7/components/bootloader E:/esp-idf-v4.4.7/components/bootloader_support E:/esp-idf-v4.4.7/components/bt E:/esp-idf-v4.4.7/components/cbor E:/esp-idf-v4.4.7/esp-adf-master/components/clouds E:/esp-idf-v4.4.7/components/cmock E:/esp-idf-v4.4.7/components/coap E:/esp-idf-v4.4.7/components/console E:/esp-idf-v4.4.7/esp-adf-master/components/coredump_upload_service E:/esp-idf-v4.4.7/components/cxx E:/esp-idf-v4.4.7/esp-adf-master/components/display_service E:/esp-idf-v4.4.7/components/driver E:/esp-idf-v4.4.7/esp-adf-master/components/dueros_service E:/esp-idf-v4.4.7/components/efuse E:/esp-idf-v4.4.7/esp-adf-master/components/esp-adf-libs E:/esp-idf-v4.4.7/esp-adf-master/components/esp-sr E:/esp-idf-v4.4.7/components/esp-tls E:/esp-idf-v4.4.7/components/esp32 E:/esp-idf-v4.4.7/esp-adf-master/components/esp_actions E:/esp-idf-v4.4.7/components/esp_adc_cal E:/esp-idf-v4.4.7/esp-adf-master/components/esp_codec_dev E:/esp-idf-v4.4.7/components/esp_common E:/esp-idf-v4.4.7/esp-adf-master/components/esp_dispatcher E:/esp-idf-v4.4.7/components/esp_eth E:/esp-idf-v4.4.7/components/esp_event E:/esp-idf-v4.4.7/esp-adf-master/components/esp_event_cast E:/esp-idf-v4.4.7/components/esp_gdbstub E:/esp-idf-v4.4.7/components/esp_hid E:/esp-idf-v4.4.7/components/esp_http_client E:/esp-idf-v4.4.7/components/esp_http_server E:/esp-idf-v4.4.7/components/esp_https_ota E:/esp-idf-v4.4.7/components/esp_https_server E:/esp-idf-v4.4.7/components/esp_hw_support E:/esp-idf-v4.4.7/components/esp_ipc E:/esp-idf-v4.4.7/components/esp_lcd E:/esp-idf-v4.4.7/components/esp_local_ctrl E:/esp-idf-v4.4.7/components/esp_netif E:/esp-idf-v4.4.7/esp-adf-master/components/esp_peripherals E:/esp-idf-v4.4.7/components/esp_phy E:/esp-idf-v4.4.7/components/esp_pm E:/esp-idf-v4.4.7/components/esp_ringbuf E:/esp-idf-v4.4.7/components/esp_rom E:/esp-idf-v4.4.7/components/esp_serial_slave_link E:/esp-idf-v4.4.7/components/esp_system E:/esp-idf-v4.4.7/components/esp_timer E:/esp-idf-v4.4.7/components/esp_websocket_client E:/esp-idf-v4.4.7/components/esp_wifi E:/esp-idf-v4.4.7/components/espcoredump E:/esp-idf-v4.4.7/esp-adf-master/examples/protocols/voip/managed_components/espressif__esp-dsp E:/esp-idf-v4.4.7/esp-adf-master/examples/protocols/voip/managed_components/espressif__esp32-camera E:/esp-idf-v4.4.7/components/esptool_py E:/esp-idf-v4.4.7/components/expat E:/esp-idf-v4.4.7/components/fatfs E:/esp-idf-v4.4.7/components/freemodbus E:/esp-idf-v4.4.7/components/freertos E:/esp-idf-v4.4.7/components/hal E:/esp-idf-v4.4.7/components/heap E:/esp-idf-v4.4.7/components/idf_test E:/esp-idf-v4.4.7/components/ieee802154 E:/esp-idf-v4.4.7/esp-adf-master/components/input_key_service E:/esp-idf-v4.4.7/components/jsmn E:/esp-idf-v4.4.7/components/json E:/esp-idf-v4.4.7/components/libsodium E:/esp-idf-v4.4.7/components/log E:/esp-idf-v4.4.7/components/lwip E:/esp-idf-v4.4.7/esp-adf-master/examples/protocols/voip/main E:/esp-idf-v4.4.7/components/mbedtls E:/esp-idf-v4.4.7/components/mdns E:/esp-idf-v4.4.7/components/mqtt E:/esp-idf-v4.4.7/components/newlib E:/esp-idf-v4.4.7/components/nghttp E:/esp-idf-v4.4.7/components/nvs_flash E:/esp-idf-v4.4.7/components/openssl E:/esp-idf-v4.4.7/components/openthread E:/esp-idf-v4.4.7/esp-adf-master/components/ota_service E:/esp-idf-v4.4.7/components/partition_table E:/esp-idf-v4.4.7/components/perfmon E:/esp-idf-v4.4.7/esp-adf-master/components/playlist E:/esp-idf-v4.4.7/components/protobuf-c E:/esp-idf-v4.4.7/components/protocomm E:/esp-idf-v4.4.7/components/pthread E:/esp-idf-v4.4.7/components/sdmmc E:/esp-idf-v4.4.7/components/soc E:/esp-idf-v4.4.7/components/spi_flash E:/esp-idf-v4.4.7/components/spiffs E:/esp-idf-v4.4.7/components/tcp_transport E:/esp-idf-v4.4.7/components/tcpip_adapter E:/esp-idf-v4.4.7/components/tinyusb E:/esp-idf-v4.4.7/esp-adf-master/components/tone_partition E:/esp-idf-v4.4.7/components/ulp E:/esp-idf-v4.4.7/components/unity E:/esp-idf-v4.4.7/components/usb E:/esp-idf-v4.4.7/components/vfs E:/esp-idf-v4.4.7/components/wear_levelling E:/esp-idf-v4.4.7/components/wifi_provisioning E:/esp-idf-v4.4.7/esp-adf-master/components/wifi_service E:/esp-idf-v4.4.7/components/wpa_supplicant E:/esp-idf-v4.4.7/components/xtensa
-- Configuring done
-- Generating done
-- Build files have been written to: E:/esp-idf-v4.4.7/esp-adf-master/examples/protocols/voip/build
[1/8] Performing build step for 'bootloader'
[0/1] Re-running CMake...
-- Building ESP-IDF components for target esp32
-- Project sdkconfig file E:/esp-idf-v4.4.7/esp-adf-master/examples/protocols/voip/sdkconfig
-- Adding linker script E:/esp-idf-v4.4.7/components/soc/esp32/ld/esp32.peripherals.ld
-- Adding linker script E:/esp-idf-v4.4.7/components/esp_rom/esp32/ld/esp32.rom.ld
-- Adding linker script E:/esp-idf-v4.4.7/components/esp_rom/esp32/ld/esp32.rom.api.ld
-- Adding linker script E:/esp-idf-v4.4.7/components/esp_rom/esp32/ld/esp32.rom.libgcc.ld
-- Adding linker script E:/esp-idf-v4.4.7/components/esp_rom/esp32/ld/esp32.rom.newlib-funcs.ld
-- Adding linker script E:/esp-idf-v4.4.7/components/bootloader/subproject/main/ld/esp32/bootloader.ld
-- Adding linker script E:/esp-idf-v4.4.7/components/bootloader/subproject/main/ld/esp32/bootloader.rom.ld
-- Components: bootloader bootloader_support efuse esp32 esp_common esp_hw_support esp_rom esp_system esptool_py freertos hal log main micro-ecc newlib partition_table soc spi_flash xtensa
-- Component paths: E:/esp-idf-v4.4.7/components/bootloader E:/esp-idf-v4.4.7/components/bootloader_support E:/esp-idf-v4.4.7/components/efuse E:/esp-idf-v4.4.7/components/esp32 E:/esp-idf-v4.4.7/components/esp_common E:/esp-idf-v4.4.7/components/esp_hw_support E:/esp-idf-v4.4.7/components/esp_rom E:/esp-idf-v4.4.7/components/esp_system E:/esp-idf-v4.4.7/components/esptool_py E:/esp-idf-v4.4.7/components/freertos E:/esp-idf-v4.4.7/components/hal E:/esp-idf-v4.4.7/components/log E:/esp-idf-v4.4.7/components/bootloader/subproject/main E:/esp-idf-v4.4.7/components/bootloader/subproject/components/micro-ecc E:/esp-idf-v4.4.7/components/newlib E:/esp-idf-v4.4.7/components/partition_table E:/esp-idf-v4.4.7/components/soc E:/esp-idf-v4.4.7/components/spi_flash E:/esp-idf-v4.4.7/components/xtensa
-- Configuring done
-- Generating done
-- Build files have been written to: E:/esp-idf-v4.4.7/esp-adf-master/examples/protocols/voip/build/bootloader
[1/1] cmd.exe /C "cd /D E:\esp-idf-v4.4.7\esp-adf-master\examples\protocols\voip\build\bootloader\esp-idf\esptool_py && E:\Espressif\python_env\idf4.4_py3.11_env\Scripts\python.exe E:/esp-idf-v4.4.7/components/partition_table/check_sizes.py --offset 0x8000 bootloader 0x1000 E:/esp-idf-v4.4.7/esp-adf-master/examples/protocols/voip/build/bootloader/bootloader.bin"
Bootloader binary size 0x6b10 bytes. 0x4f0 bytes (4%) free.
[4/6] Generating binary image from built executable
esptool.py v3.3.4-dev
Creating esp32 image...
Merged 27 ELF sections
Successfully created esp32 image.
Generated E:/esp-idf-v4.4.7/esp-adf-master/examples/protocols/voip/build/voip_app.bin
[5/6] cmd.exe /C "cd /D E:\esp-idf-v4.4.7\esp-adf-master\exampl....4.7/esp-adf-master/examples/protocols/voip/build/voip_app.bin" 
voip_app.bin binary size 0x1411c0 bytes. Smallest app partition is 0x200000 bytes. 0xbee40 bytes (37%) free.
[5/6] cmd.exe /C "cd /D E:\esp-idf-v4.4.7\components\esptool_py... E:/esp-idf-v4.4.7/components/esptool_py/run_serial_tool.cmake" 
esptool.py esp32 -p COM5 -b 921600 --before=default_reset --after=hard_reset write_flash --flash_mode dio --flash_freq 80m --flash_size 8MB 0x1000 bootloader/bootloader.bin 0x10000 voip_app.bin 0x8000 partition_table/partition-table.bin
esptool.py v3.3.4-dev
Serial port COM5
Connecting....
Chip is ESP32-D0WD-V3 (revision v3.1)
Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None
Crystal is 40MHz
MAC: a0:a3:b3:8b:49:80
Uploading stub...
Running stub...
Stub running...
Changing baud rate to 921600
Changed.
Configuring flash size...
Flash will be erased from 0x00001000 to 0x00007fff...
Flash will be erased from 0x00010000 to 0x00151fff...
Flash will be erased from 0x00008000 to 0x00008fff...
Compressed 27408 bytes to 17201...
Writing at 0x00001000... (50 %)
Writing at 0x0000770e... (100 %)
Wrote 27408 bytes (17201 compressed) at 0x00001000 in 0.5 seconds (effective 417.8 kbit/s)...
Hash of data verified.
Compressed 1315264 bytes to 813082...
Writing at 0x00010000... (2 %)
Writing at 0x0001f623... (4 %)
Writing at 0x000291f9... (6 %)
Writing at 0x000350e4... (8 %)
Writing at 0x0003fe10... (10 %)
Writing at 0x0004a838... (12 %)
Writing at 0x000506b9... (14 %)
Writing at 0x000567fe... (16 %)
Writing at 0x0005d637... (18 %)
Writing at 0x0006328d... (20 %)
Writing at 0x0006904a... (22 %)
Writing at 0x0006e436... (24 %)
Writing at 0x00073637... (26 %)
Writing at 0x00078da8... (28 %)
Writing at 0x0007e651... (30 %)
Writing at 0x00084ab1... (32 %)
Writing at 0x00089b0e... (34 %)
Writing at 0x0008edac... (36 %)
Writing at 0x00095272... (38 %)
Writing at 0x0009bb99... (40 %)
Writing at 0x000a221a... (42 %)
Writing at 0x000a834b... (44 %)
Writing at 0x000adff4... (46 %)
Writing at 0x000b3ee2... (48 %)
Writing at 0x000b9853... (50 %)
Writing at 0x000bf45d... (52 %)
Writing at 0x000c5057... (54 %)
Writing at 0x000cabaa... (56 %)
Writing at 0x000d13da... (58 %)
Writing at 0x000d7265... (60 %)
Writing at 0x000dce2f... (62 %)
Writing at 0x000e22cb... (64 %)
Writing at 0x000e755d... (66 %)
Writing at 0x000ec9f7... (68 %)
Writing at 0x000f1e1a... (70 %)
Writing at 0x000f74ac... (72 %)
Writing at 0x000fcd59... (74 %)
Writing at 0x00102b8d... (76 %)
Writing at 0x00108388... (78 %)
Writing at 0x0010dd71... (80 %)
Writing at 0x00113a44... (82 %)
Writing at 0x001193de... (84 %)
Writing at 0x0011ede3... (86 %)
Writing at 0x00127d3e... (88 %)
Writing at 0x00130c49... (90 %)
Writing at 0x00137090... (92 %)
Writing at 0x0013c2d3... (94 %)
Writing at 0x00142320... (96 %)
Writing at 0x00147a1e... (98 %)
Writing at 0x0014d47f... (100 %)
Wrote 1315264 bytes (813082 compressed) at 0x00010000 in 11.8 seconds (effective 891.0 kbit/s)...
Hash of data verified.
Compressed 3072 bytes to 125...
Writing at 0x00008000... (100 %)
Wrote 3072 bytes (125 compressed) at 0x00008000 in 0.0 seconds (effective 530.6 kbit/s)...
Hash of data verified.

Leaving...
Hard resetting via RTS pin...
Executing action: monitor
Running idf_monitor in directory E:\esp-idf-v4.4.7\esp-adf-master\examples\protocols\voip
Executing "E:\Espressif\python_env\idf4.4_py3.11_env\Scripts\python.exe E:\esp-idf-v4.4.7\tools/idf_monitor.py -p COM5 -b 115200 --toolchain-prefix xtensa-esp32-elf- --target esp32 --revision 0 E:\esp-idf-v4.4.7\esp-adf-master\examples\protocols\voip\build\voip_app.elf -m 'E:\Espressif\python_env\idf4.4_py3.11_env\Scripts\python.exe' 'E:\esp-idf-v4.4.7\tools\idf.py'"...
--- WARNING: GDB cannot open serial ports accessed as COMx
--- Using \\.\COM5 instead...
--- idf_monitor on \\.\COM5 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
5e18I (11) boot: ESP-IDF v4.4.7-dirty 2nd stage bootloader
I (11) boot: compile time 22:58:08
I (11) boot: Multicore bootloader
I (13) boot: chip revision: v3.1
I (17) qio_mode: Enabling default flash chip QIO
I (22) boot.esp32: SPI Speed      : 80MHz
I (27) boot.esp32: SPI Mode       : QIO
I (32) boot.esp32: SPI Flash Size : 8MB
I (36) boot: Enabling RNG early entropy source...
I (42) boot: Partition Table:
I (45) boot: ## Label            Usage          Type ST Offset   Length
I (52) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (60) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (67) boot:  2 factory          factory app      00 00 00010000 00200000
I (75) boot:  3 flash_tone       Unknown data     01 ff 00210000 0007d000
I (82) boot: End of partition table
I (86) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=35df0h (220656) map
I (156) esp_image: segment 1: paddr=00045e18 vaddr=3ffb0000 size=03750h ( 14160) load
I (160) esp_image: segment 2: paddr=00049570 vaddr=40080000 size=06aa8h ( 27304) load
I (170) esp_image: segment 3: paddr=00050020 vaddr=400d0020 size=f0fd4h (987092) map
I (443) esp_image: segment 4: paddr=00140ffc vaddr=40086aa8 size=10198h ( 65944) load
I (475) boot: Loaded app from partition at offset 0x10000
I (475) boot: Disabling RNG early entropy source...
I (487) cpu_start: Multicore app
I (487) psram: This chip is ESP32-D0WD
I (488) spiram: Found 64MBit SPI RAM device
I (489) spiram: SPI RAM mode: flash 80m sram 80m
I (494) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (501) cpu_start: Pro cpu up.
I (505) cpu_start: Starting app cpu, entry point is 0x40081534
0x40081534: call_start_cpu1 at E:/esp-idf-v4.4.7/components/esp_system/port/cpu_start.c:151

I (0) cpu_start: App cpu up.
I (1008) spiram: SPI SRAM memory test OK
I (1016) cpu_start: Pro cpu start user code
I (1016) cpu_start: cpu freq: 240000000
I (1016) cpu_start: Application information:
I (1019) cpu_start: Project name:     voip_app
I (1024) cpu_start: App version:      v2.6-84-g75c9aed9-dirty
I (1031) cpu_start: Compile time:     Mar 13 2024 22:57:52
I (1037) cpu_start: ELF file SHA256:  44c960785f1493af...
I (1043) cpu_start: ESP-IDF:          v4.4.7-dirty
I (1048) cpu_start: Min chip rev:     v0.0
I (1053) cpu_start: Max chip rev:     v3.99
I (1058) cpu_start: Chip rev:         v3.1
I (1063) heap_init: Initializing. RAM available for dynamic allocation:
I (1070) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (1076) heap_init: At 3FFB4EB8 len 0002B148 (172 KiB): DRAM
I (1083) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1089) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1096) heap_init: At 40096C40 len 000093C0 (36 KiB): IRAM
I (1102) spiram: Adding pool of 4082K of external SPI memory to heap allocator
I (1110) spi_flash: detected chip: gd
I (1114) spi_flash: flash io: qio
I (1119) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (1134) spiram: Reserving pool of 18K of internal memory for DMA/internal allocations
I (1142) VoIP_EXAMPLE: Func:app_main, Line:149, MEM Total:4447227 Bytes, Inter:323763 Bytes, Dram:286743 Bytes

I (1169) VoIP_EXAMPLE: [1.0] Initialize peripherals management
I (1169) VoIP_EXAMPLE: [1.1] Initialize and start peripherals
I (1172) AUDIO_THREAD: The button_task task allocate stack on internal memory
I (1178) AUDIO_THREAD: The esp_periph task allocate stack on internal memory
I (1186) VoIP_EXAMPLE: [1.2] Create and start input key service
I (1193) AUDIO_THREAD: The input_key_service task allocate stack on external memory
I (1201) VoIP_EXAMPLE: [ 2 ] Initialize av stream
I (1207) I2S: DMA Malloc info, datalen=blocksize=128, dma_buf_count=8
I (1214) I2S: DMA Malloc info, datalen=blocksize=128, dma_buf_count=8
I (1221) I2S: I2S0, MCLK output by GPIO0
I (1231) DRV8311: ES8311 in Slave mode
I (1244) gpio: GPIO[21]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
W (1289) I2C_BUS: I2C bus has been already created, [port:0]
I (1293) I2S: DMA Malloc info, datalen=blocksize=256, dma_buf_count=8
I (1293) I2S: DMA Malloc info, datalen=blocksize=256, dma_buf_count=8
I (1298) I2S: I2S1, MCLK output by GPIO0
I (1303) AUDIO_HAL: Codec mode is 3, Ctrl:1
I (1315) VoIP_EXAMPLE: [ 3 ] Initialize tone player
I (1316) AUDIO_THREAD: The media_task task allocate stack on external memory
I (1321) ESP_AUDIO_TASK: media_ctrl_task running...,0x3f805464

----------------------------- ESP Audio Platform -----------------------------
|                                                                            |
|                 ESP_AUDIO-v1.7.3-22-ga3cf4e4-9f1d1e8-e2f9463               |
|                     Compile date: Feb  5 2024-12:23:16                     |
------------------------------------------------------------------------------
I (1362) ESP_AUDIO_CTRL: Func:media_ctrl_create, Line:355, MEM Total:4418775 Bytes, Inter:298431 Bytes, Dram:261411 Bytes

I (1375) MP3_DECODER: MP3 init
E (1378) I2S: register I2S object to platform failed
I (1384) I2S: I2S0, MCLK output by GPIO0
E (1388) I2S_STREAM: i2s_set_clk failed, type = 2,port:0
I (1394) VoIP_EXAMPLE: [ 4 ] Create Wi-Fi service instance
E (1400) DISPATCHER: exe first list: 0x0
I (1405) DISPATCHER: dispatcher_event_task is running...
I (1411) AUDIO_THREAD: The esp_dispatcher task allocate stack on internal memory
I (1422) AUDIO_THREAD: The wifi_serv task allocate stack on external memory
I (1430) wifi:wifi driver task: 3ffc7404, prio:23, stack:6656, core=0
I (1433) system_api: Base MAC address is not set
I (1438) system_api: read default base MAC address from EFUSE
I (1447) wifi:wifi firmware version: 1fd20f4
I (1449) wifi:wifi certification version: v7.0
I (1453) wifi:config NVS flash: enabled
I (1456) wifi:config nano formating: disabled
I (1460) wifi:Init data frame dynamic rx buffer num: 128
I (1466) wifi:Init static rx mgmt buffer num: 5
I (1470) wifi:Init management short buffer num: 32
I (1474) wifi:Init static tx buffer num: 9
I (1479) wifi:Init tx cache buffer num: 32
I (1482) wifi:Init static rx buffer size: 1600
I (1486) wifi:Init static rx buffer num: 9
I (1490) wifi:Init dynamic rx buffer num: 128
I (1495) wifi_init: rx ba win: 16
I (1498) wifi_init: tcpip mbox: 64
I (1502) wifi_init: udp mbox: 64
I (1506) wifi_init: tcp mbox: 64
I (1510) wifi_init: tcp tx win: 65535
I (1514) wifi_init: tcp rx win: 65535
I (1518) wifi_init: tcp mss: 1440
I (1522) wifi_init: WiFi/LWIP prefer SPIRAM
I (1528) phy_init: phy_version 4791,2c4672b,Dec 20 2023,16:06:06
I (1597) wifi:mode : sta (a0:a3:b3:8b:49:80)
I (1597) wifi:enable tsf
I (1606) WIFI_SERV: Connect to wifi ssid: rebit-mesh, pwd: b039320822
I (1612) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
I (1781) wifi:state: init -> auth (b0)
I (2603) AUDIO_SYS: | Task              | Run Time    | Per | Prio | HWM       | State   | CoreId   | Stack 
I (2603) AUDIO_SYS: | main              | 1860        | 0%  | 1    | 1504      | Running | 0        | Intr
I (2613) AUDIO_SYS: | IDLE1             | 1163805     |49%  | 0    | 1008      | Ready   | 1        | Intr
I (2623) AUDIO_SYS: | IDLE0             | 798608      |34%  | 0    | 924       | Ready   | 0        | Intr
I (2634) AUDIO_SYS: | esp_periph        | 2577        | 0%  | 5    | 2180      | Blocked | 0        | Intr
I (2644) AUDIO_SYS: | button_task       | 20647       | 0%  | 10   | 1660      | Blocked | 0        | Intr
I (2654) AUDIO_SYS: | tiT               | 924         | 0%  | 18   | 2940      | Blocked | 7fffffff | Intr
I (2665) AUDIO_SYS: | esp_dispatcher    | 40583       | 1%  | 10   | 2308      | Blocked | 0        | Intr
I (2675) AUDIO_SYS: | Tmr Svc           | 0           | 0%  | 1    | 1460      | Blocked | 0        | Intr
I (2685) AUDIO_SYS: | ipc0              | 0           | 0%  | 1    | 948       | Blocked | 0        | Intr
I (2696) AUDIO_SYS: | input_key_servi   | 0           | 0%  | 5    | 3448      | Blocked | 1        | Extr
I (2706) AUDIO_SYS: | media_task        | 0           | 0%  | 6    | 2084      | Blocked | 0        | Extr
I (2716) AUDIO_SYS: | ipc1              | 9846        | 0%  | 24   | 952       | Blocked | 1        | Intr
I (2727) AUDIO_SYS: | sys_evt           | 456         | 0%  | 20   | 2936      | Blocked | 0        | Intr
I (2737) AUDIO_SYS: | wifi              | 307029      |13%  | 23   | 6016      | Blocked | 0        | Intr
I (2747) AUDIO_SYS: | wifi_serv         | 1004        | 0%  | 6    | 2156      | Blocked | 0        | Extr
I (2758) AUDIO_SYS: | esp_timer         | 143         | 0%  | 22   | 3556      | Suspended | 0        | Intr

I (2768) VoIP_EXAMPLE: Func:app_main, Line:209, MEM Total:4299007 Bytes, Inter:244831 Bytes, Dram:207811 Bytes

I (2782) wifi:state: auth -> init (200)
I (2783) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
I (2789) WIFI_SERV: STA Auth Error, reason:2
W (2794) WIFI_SERV: STATE type:3, pdata:0x0, len:0
W (2799) WIFI_SERV: Disconnect reason 2
I (2804) VoIP_EXAMPLE: PERIPH_WIFI_DISCONNECTED [109]
I (2809) ESP_AUDIO_CTRL: Enter play procedure, src:0
I (2815) ESP_AUDIO_CTRL: Play procedure, URL is ok, src:0
I (2821) ESP_AUDIO_CTRL: Request_CMD_Queue CMD:0, Available:5, que:0x3ffc1b34
I (2829) ESP_AUDIO_TASK: It's a decoder
I (2834) ESP_AUDIO_TASK: 1.CUR IN:[IN_flash],CODEC:[DEC_mp3],RESAMPLE:[8000],OUT:[OUT_iis],rate:0,ch:0,pos:0
I (2830) ESP_AUDIO_CTRL: Func:_ctrl_play, Line:776, MEM Total:4299011 Bytes, Inter:244903 Bytes, Dram:207883 Bytes

I (2845) ESP_AUDIO_TASK: 2.Handles,IN:0x3f806724,CODEC:0x3f8068bc,FILTER:0x3f80799c,OUT:0x3f806a70
I (2865) ESP_AUDIO_TASK: 2.2 Update all pipeline
I (2870) ESP_AUDIO_TASK: 2.3 Linked new pipeline
I (2876) AUDIO_PIPELINE: link el->rb, el:0x3f806724, tag:IN_flash, rb:0x3f816d90
I (2884) AUDIO_PIPELINE: link el->rb, el:0x3f8068bc, tag:DEC_mp3, rb:0x3f8195d8
I (2892) AUDIO_PIPELINE: link el->rb, el:0x3f80799c, tag:Audio_forge, rb:0x3f81b620
I (2900) ESP_AUDIO_TASK: 3. Previous starting...
I (2906) AUDIO_THREAD: The IN_flash task allocate stack on internal memory
I (2913) AUDIO_THREAD: The DEC_mp3 task allocate stack on external memory
I (2914) TONE_PARTITION: tone partition format 1, total 7
I (2921) MP3_DECODER: MP3 opened
I (2921) ESP_AUDIO_TASK: Blocking play until received AEL_MSG_CMD_REPORT_MUSIC_INFO
I (2931) TONE_STREAM: Tone offset:00014680, Tone length:25259, pos:4

I (2946) ESP_AUDIO_TASK: Recv Element[IN_flash-0x3f806724] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
         (2947) CODEC_ELEMENT_HELPER: The element is 0x3f8068bc. The reserve data 2 is 0x0.
I (2968) ESP_AUDIO_TASK: Recv Element[DEC_mp3-0x3f8068bc] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
I (2977) ESP_AUDIO_TASK: Received muisc info then on play
I (2983) ESP_AUDIO_TASK: On event play, status:UNKNOWN, 0
I (2989) AUDIO_THREAD: The Audio_forge task allocate stack on external memory
I (2997) AUDIO_FORGE: audio_forge opened
I (2997) AUDIO_THREAD: The OUT_iis task allocate stack on external memory
I (3009) I2S_STREAM: AUDIO_STREAM_WRITER
I (3013) ESP_AUDIO_TASK: Recv Element[OUT_iis-0x3f806a70] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING

***ERROR*** A stack overflow in task OUT_iis has been detected.

Backtrace: 0x400821fd:0x3f82b880 0x40090ac9:0x3f82b8a0 0x400911c5:0x3f82b8c0 0x400922f9:0x3f82b940 0x40090bc4:0x3f82b960 0x40090b76:0xbf5d3838 |<-CORRUPTED
0x400821fd: panic_abort at E:/esp-idf-v4.4.7/components/esp_system/panic.c:408
0x40090ac9: esp_system_abort at E:/esp-idf-v4.4.7/components/esp_system/esp_system.c:137
0x400911c5: vApplicationStackOverflowHook at E:/esp-idf-v4.4.7/components/freertos/port/xtensa/port.c:407
0x400922f9: vTaskSwitchContext at E:/esp-idf-v4.4.7/components/freertos/tasks.c:3664
0x40090bc4: _frxt_dispatch at E:/esp-idf-v4.4.7/components/freertos/port/xtensa/portasm.S:436
0x40090b76: _frxt_int_exit at E:/esp-idf-v4.4.7/components/freertos/port/xtensa/portasm.S:231

ELF file SHA256: 44c960785f1493af

Rebooting...
I (10) boot: ESP-IDF v4.4.7-dirty 2nd stage bootloader
I (10) boot: compile time 22:58:08
I (10) boot: Multicore bootloader
I (13) boot: chip revision: v3.1
I (17) qio_mode: Enabling default flash chip QIO
I (22) boot.esp32: SPI Speed      : 80MHz
I (27) boot.esp32: SPI Mode       : QIO
I (31) boot.esp32: SPI Flash Size : 8MB
I (36) boot: Enabling RNG early entropy source...
I (41) boot: Partition Table:
I (45) boot: ## Label            Usage          Type ST Offset   Length
I (52) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (60) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (67) boot:  2 factory          factory app      00 00 00010000 00200000
I (74) boot:  3 flash_tone       Unknown data     01 ff 00210000 0007d000
I (82) boot: End of partition table
I (86) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=35df0h (220656) map
I (155) esp_image: segment 1: paddr=00045e18 vaddr=3ffb0000 size=03750h ( 14160) load
I (160) esp_image: segment 2: paddr=00049570 vaddr=40080000 size=06aa8h ( 27304) load
I (170) esp_image: segment 3: paddr=00050020 vaddr=400d0020 size=f0fd4h (987092) map
I (442) esp_image: segment 4: paddr=00140ffc vaddr=40086aa8 size=10198h ( 65944) load
I (475) boot: Loaded app from partition at offset 0x10000
I (475) boot: Disabling RNG early entropy source...
I (486) cpu_start: Multicore app
I (487) psram: This chip is ESP32-D0WD
I (487) spiram: Found 64MBit SPI RAM device
I (488) spiram: SPI RAM mode: flash 80m sram 80m
I (494) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (501) cpu_start: Pro cpu up.
I (505) cpu_start: Starting app cpu, entry point is 0x40081534
0x40081534: call_start_cpu1 at E:/esp-idf-v4.4.7/components/esp_system/port/cpu_start.c:151

I (506) cpu_start: App cpu up.
I (1007) spiram: SPI SRAM memory test OK
I (1015) cpu_start: Pro cpu start user code
I (1015) cpu_start: cpu freq: 240000000
I (1015) cpu_start: Application information:
I (1018) cpu_start: Project name:     voip_app
I (1024) cpu_start: App version:      v2.6-84-g75c9aed9-dirty
I (1030) cpu_start: Compile time:     Mar 13 2024 22:57:52
I (1036) cpu_start: ELF file SHA256:  44c960785f1493af...
I (1042) cpu_start: ESP-IDF:          v4.4.7-dirty
I (1048) cpu_start: Min chip rev:     v0.0
I (1053) cpu_start: Max chip rev:     v3.99 
I (1057) cpu_start: Chip rev:         v3.1
I (1062) heap_init: Initializing. RAM available for dynamic allocation:
I (1070) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (1076) heap_init: At 3FFB4EB8 len 0002B148 (172 KiB): DRAM
I (1082) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1088) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1095) heap_init: At 40096C40 len 000093C0 (36 KiB): IRAM
I (1101) spiram: Adding pool of 4082K of external SPI memory to heap allocator
I (1110) spi_flash: detected chip: gd
I (1114) spi_flash: flash io: qio
I (1118) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (1133) spiram: Reserving pool of 18K of internal memory for DMA/internal allocations
I (1141) VoIP_EXAMPLE: Func:app_main, Line:149, MEM Total:4447227 Bytes, Inter:323763 Bytes, Dram:286743 Bytes

I (1168) VoIP_EXAMPLE: [1.0] Initialize peripherals management
I (1168) VoIP_EXAMPLE: [1.1] Initialize and start peripherals
I (1171) AUDIO_THREAD: The button_task task allocate stack on internal memory
I (1177) AUDIO_THREAD: The esp_periph task allocate stack on internal memory
I (1185) VoIP_EXAMPLE: [1.2] Create and start input key service
I (1192) AUDIO_THREAD: The input_key_service task allocate stack on external memory
I (1200) VoIP_EXAMPLE: [ 2 ] Initialize av stream
I (1206) I2S: DMA Malloc info, datalen=blocksize=128, dma_buf_count=8
I (1213) I2S: DMA Malloc info, datalen=blocksize=128, dma_buf_count=8
I (1220) I2S: I2S0, MCLK output by GPIO0
I (1230) DRV8311: ES8311 in Slave mode
I (1243) gpio: GPIO[21]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
W (1288) I2C_BUS: I2C bus has been already created, [port:0]
I (1292) I2S: DMA Malloc info, datalen=blocksize=256, dma_buf_count=8
I (1292) I2S: DMA Malloc info, datalen=blocksize=256, dma_buf_count=8
I (1297) I2S: I2S1, MCLK output by GPIO0
I (1302) AUDIO_HAL: Codec mode is 3, Ctrl:1
I (1314) VoIP_EXAMPLE: [ 3 ] Initialize tone player
I (1315) AUDIO_THREAD: The media_task task allocate stack on external memory
I (1320) ESP_AUDIO_TASK: media_ctrl_task running...,0x3f805464

----------------------------- ESP Audio Platform -----------------------------
|                                                                            |
|                 ESP_AUDIO-v1.7.3-22-ga3cf4e4-9f1d1e8-e2f9463               |
|                     Compile date: Feb  5 2024-12:23:16                     |
------------------------------------------------------------------------------
I (1361) ESP_AUDIO_CTRL: Func:media_ctrl_create, Line:355, MEM Total:4418775 Bytes, Inter:298431 Bytes, Dram:261411 Bytes

I (1374) MP3_DECODER: MP3 init
E (1377) I2S: register I2S object to platform failed
I (1383) I2S: I2S0, MCLK output by GPIO0
E (1387) I2S_STREAM: i2s_set_clk failed, type = 2,port:0
I (1393) VoIP_EXAMPLE: [ 4 ] Create Wi-Fi service instance
E (1399) DISPATCHER: exe first list: 0x0
I (1404) DISPATCHER: dispatcher_event_task is running...
I (1410) AUDIO_THREAD: The esp_dispatcher task allocate stack on internal memory
I (1425) AUDIO_THREAD: The wifi_serv task allocate stack on external memory
I (1429) wifi:wifi driver task: 3ffc7404, prio:23, stack:6656, core=0
I (1432) system_api: Base MAC address is not set
I (1437) system_api: read default base MAC address from EFUSE
I (1446) wifi:wifi firmware version: 1fd20f4
I (1448) wifi:wifi certification version: v7.0
I (1452) wifi:config NVS flash: enabled
I (1455) wifi:config nano formating: disabled
I (1460) wifi:Init data frame dynamic rx buffer num: 128
I (1465) wifi:Init static rx mgmt buffer num: 5
I (1469) wifi:Init management short buffer num: 32
I (1473) wifi:Init static tx buffer num: 9
I (1478) wifi:Init tx cache buffer num: 32
I (1481) wifi:Init static rx buffer size: 1600
I (1485) wifi:Init static rx buffer num: 9
I (1489) wifi:Init dynamic rx buffer num: 128
I (1494) wifi_init: rx ba win: 16
I (1497) wifi_init: tcpip mbox: 64
I (1501) wifi_init: udp mbox: 64
I (1505) wifi_init: tcp mbox: 64
I (1509) wifi_init: tcp tx win: 65535
I (1513) wifi_init: tcp rx win: 65535
I (1517) wifi_init: tcp mss: 1440
I (1521) wifi_init: WiFi/LWIP prefer SPIRAM
I (1527) phy_init: phy_version 4791,2c4672b,Dec 20 2023,16:06:06
I (1596) wifi:mode : sta (a0:a3:b3:8b:49:80)
I (1597) wifi:enable tsf
I (1605) WIFI_SERV: Connect to wifi ssid: rebit-mesh, pwd: b039320822
I (1611) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
I (1780) wifi:state: init -> auth (b0)
I (1783) wifi:state: auth -> assoc (0)
I (1788) wifi:state: assoc -> run (10)
I (1814) wifi:connected with rebit-mesh, aid = 3, channel 1, BW20, bssid = fc:7f:f1:4c:da:22
I (1814) wifi:security: WPA2-PSK, phy: bgn, rssi: -72
I (1816) wifi:pm start, type: 1

W (1821) WIFI_SERV: WiFi Event cb, Unhandle event_base:WIFI_EVENT, event_id:4
I (1829) wifi:<ba-add>idx:0 (ifx:0, fc:7f:f1:4c:da:22), tid:0, ssn:2, winSize:64
I (1894) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (2602) AUDIO_SYS: | Task              | Run Time    | Per | Prio | HWM       | State   | CoreId   | Stack 
I (2602) AUDIO_SYS: | main              | 1872        | 0%  | 1    | 1504      | Running | 0        | Intr
I (2612) AUDIO_SYS: | IDLE1             | 1160607     |49%  | 0    | 1008      | Ready   | 1        | Intr
I (2622) AUDIO_SYS: | IDLE0             | 752528      |32%  | 0    | 972       | Ready   | 0        | Intr
I (2633) AUDIO_SYS: | esp_periph        | 2842        | 0%  | 5    | 2180      | Blocked | 0        | Intr
I (2643) AUDIO_SYS: | button_task       | 22373       | 0%  | 10   | 1660      | Blocked | 0        | Intr
I (2653) AUDIO_SYS: | tiT               | 4110        | 0%  | 18   | 2940      | Blocked | 7fffffff | Intr
I (2664) AUDIO_SYS: | esp_dispatcher    | 40457       | 1%  | 10   | 2308      | Blocked | 0        | Intr
I (2674) AUDIO_SYS: | Tmr Svc           | 0           | 0%  | 1    | 1460      | Blocked | 0        | Intr
I (2684) AUDIO_SYS: | ipc0              | 0           | 0%  | 1    | 948       | Blocked | 0        | Intr
I (2695) AUDIO_SYS: | input_key_servi   | 0           | 0%  | 5    | 3448      | Blocked | 1        | Extr
I (2705) AUDIO_SYS: | media_task        | 0           | 0%  | 6    | 2084      | Blocked | 0        | Extr
I (2715) AUDIO_SYS: | ipc1              | 9787        | 0%  | 24   | 968       | Blocked | 1        | Intr
I (2726) AUDIO_SYS: | sys_evt           | 6588        | 0%  | 20   | 2936      | Blocked | 0        | Intr
I (2736) AUDIO_SYS: | wifi              | 343674      |14%  | 23   | 6016      | Blocked | 0        | Intr
I (2746) AUDIO_SYS: | wifi_serv         | 1009        | 0%  | 6    | 2156      | Blocked | 0        | Extr
I (2757) AUDIO_SYS: | esp_timer         | 1637        | 0%  | 22   | 3556      | Suspended | 0        | Intr

I (2767) VoIP_EXAMPLE: Func:app_main, Line:209, MEM Total:4298211 Bytes, Inter:244771 Bytes, Dram:207751 Bytes

I (2822) esp_netif_handlers: sta ip: 192.168.130.121, mask: 255.255.255.0, gw: 192.168.130.254
I (2823) WIFI_SERV: Got ip:192.168.130.121
W (2825) WIFI_SERV: STATE type:2, pdata:0x0, len:0
I (2846) VoIP_EXAMPLE: PERIPH_WIFI_CONNECTED [104]
I (2846) VoIP_EXAMPLE: [ 5 ] Create SIP Service
I (2846) ESP_RTC_CORE: esp_rtc ver: 1.1.0 compile date: Feb  5 2024-12:23:15
I (2854) SIP: Conecting...
I (2857) ESP_RTC_CORE: esp_rtc_init done
W (2857) SIP: CHANGE STATE FROM 0, TO 1, :func: sip_connect:1835
I (2868) SIP: [1970-01-01/00:00:02]=======WRITE 0605 bytes>>
I (2874) SIP:

REGISTER sip:192.168.130.156:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.130.121:17034;branch=z9hG4bK-1675992588;rport
From: <sip:1001@192.168.130.156:5060>;tag=951152052
To: <sip:1001@192.168.130.156:5060>
Contact: <sip:1001@192.168.130.121:17034;transport=UDP>
Max-Forwards: 70
Call-ID: E660DE1E085D020A28B47E4720E12CEEE48AD4211E00
CSeq: 1 REGISTER
Expires: 3600
User-Agent: ESP32 SIP/2.0
Content-Length: 0
Allow: INVITE, ACK, CANCEL, BYE, UPDATE, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE
Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri
Allow-Events: presence, kpml

I (2931) SIP: [1970-01-01/00:00:02]=======================>>
I (2994) SIP: [1970-01-01/00:00:02]<<=====READ 0668 bytes==
I (2994) SIP:

SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.130.121:17034;branch=z9hG4bK-1675992588;rport=17034
From: <sip:1001@192.168.130.156:5060>;tag=951152052
To: <sip:1001@192.168.130.156:5060>;tag=24X7N9eX4687p
Call-ID: E660DE1E085D020A28B47E4720E12CEEE48AD4211E00
CSeq: 1 REGISTER
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-cab1565 2010-05-18 10-42-16 -0400
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
WWW-Authenticate: Digest realm="192.168.130.156", nonce="d6260482-d31a-458c-b53e-b9ad10511a91", algorithm=MD5, qop="auth"
Content-Length: 0

I (3051) SIP: [1970-01-01/00:00:02]<<======================
I (3058) SIP: Required authentication
I (3064) SIP: [1970-01-01/00:00:02]=======WRITE 0858 bytes>>
I (3068) SIP:

REGISTER sip:192.168.130.156:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.130.121:17034;branch=z9hG4bK-1350549152;rport
From: <sip:1001@192.168.130.156:5060>;tag=1611299899
To: <sip:1001@192.168.130.156:5060>
Contact: <sip:1001@192.168.130.121:17034;transport=UDP>
Max-Forwards: 70
Call-ID: E660DE1E085D020A28B47E4720E12CEEE48AD4211E00
CSeq: 2 REGISTER
Expires: 3600
User-Agent: ESP32 SIP/2.0
Content-Length: 0
Allow: INVITE, ACK, CANCEL, BYE, UPDATE, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE
Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri
Allow-Events: presence, kpml
Authorization: Digest username="1001", realm="192.168.130.156", nonce="d6260482-d31a-458c-b53e-b9ad10511a91", uri="sip:192.168.130.156:5060", response="47034182a0f6fb0f520974de83bcb2d7", algorithm=MD5, qop=auth, nc=00000001, cnonce="80cfd95704a27ae4"

I (3147) SIP: [1970-01-01/00:00:02]=======================>>
I (3183) SIP: [1970-01-01/00:00:02]<<=====READ 0643 bytes==
I (3184) SIP:

SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.130.121:17034;branch=z9hG4bK-1350549152;rport=17034
From: <sip:1001@192.168.130.156:5060>;tag=1611299899
To: <sip:1001@192.168.130.156:5060>;tag=4pgSSZg4yrNDe
Call-ID: E660DE1E085D020A28B47E4720E12CEEE48AD4211E00
CSeq: 2 REGISTER
Contact: <sip:1001@192.168.130.121:17034;transport=UDP>;expires=3600
Date: Wed, 14 Mar 2024 07:02:20 GMT
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-cab1565 2010-05-18 10-42-16 -0400
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Content-Length: 0

I (3238) SIP: [1970-01-01/00:00:02]<<======================
I (3246) SIP_SERVICE: ESP_RTC_EVENT_REGISTERED
I (3250) ESP_AUDIO_CTRL: Enter play procedure, src:0
I (3256) ESP_AUDIO_CTRL: Play procedure, URL is ok, src:0
I (3262) ESP_AUDIO_CTRL: Request_CMD_Queue CMD:0, Available:5, que:0x3ffc1b34
I (3269) ESP_AUDIO_CTRL: Func:_ctrl_play, Line:776, MEM Total:4275935 Bytes, Inter:243587 Bytes, Dram:206567 Bytes

I (3281) ESP_AUDIO_TASK: It's a decoder
I (3285) ESP_AUDIO_TASK: 1.CUR IN:[IN_flash],CODEC:[DEC_mp3],RESAMPLE:[8000],OUT:[OUT_iis],rate:0,ch:0,pos:0
I (3296) ESP_AUDIO_TASK: 2.Handles,IN:0x3f806724,CODEC:0x3f8068bc,FILTER:0x3f81bea0,OUT:0x3f806a70
I (3305) ESP_AUDIO_TASK: 2.2 Update all pipeline
I (3311) ESP_AUDIO_TASK: 2.3 Linked new pipeline
I (3316) AUDIO_PIPELINE: link el->rb, el:0x3f806724, tag:IN_flash, rb:0x3f81c28c
I (3324) AUDIO_PIPELINE: link el->rb, el:0x3f8068bc, tag:DEC_mp3, rb:0x3f81ead4
I (3332) AUDIO_PIPELINE: link el->rb, el:0x3f81bea0, tag:Audio_forge, rb:0x3f820b1c
I (3341) ESP_AUDIO_TASK: 3. Previous starting...
I (3346) AUDIO_THREAD: The IN_flash task allocate stack on internal memory
I (3353) AUDIO_THREAD: The DEC_mp3 task allocate stack on external memory
I (3354) TONE_PARTITION: tone partition format 1, total 7
I (3362) MP3_DECODER: MP3 opened
I (3362) ESP_AUDIO_TASK: Blocking play until received AEL_MSG_CMD_REPORT_MUSIC_INFO
I (3371) TONE_STREAM: Tone offset:0001A92C, Tone length:21212, pos:5

I (3386) ESP_AUDIO_TASK: Recv Element[IN_flash-0x3f806724] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
I (3387) CODEC_ELEMENT_HELPER: The lement is 0x3f8068bc. The reserve data 2 is 0x0.
I (3409) ESP_AUDIO_TASK: Recv Element[DEC_mp3-0x3f8068bc] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING
I (3418) ESP_AUDIO_TASK: Received muisc info then on play
I (3423) ESP_AUDIO_TASK: On event play, status:UNKNOWN, 0
I (3429) AUDIO_THREAD: The Audio_forge task allocate stack on external memory
I (3438) AUDIO_FORGE: audio_forge opened[0m
I (3438) AUDIO_THREAD: The OUT_iis task allocate stack on external memory
I (3449) I2S_STREAM: AUDIO_STREAM_WRITER
I (3454) ESP_AUDIO_TASK: Recv Element[OUT_iis-0x3f806a70] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING

***ERROR*** A stack overflow in task OUT_iis has been detected.

Backtrace: 0x400821fd:0x3f830d80 0x40090ac9:0x3f830da0 0x400911c5:0x3f830dc0 0x400922f9:0x3f830e40 0x40090bc4:0x3f830e60 0x40090b76:0xbf5ad281 |<-CORRUPTED
0x400821fd: panic_abort at E:/esp-idf-v4.4.7/components/esp_system/panic.c:408
0x40090ac9: esp_system_abort at E:/esp-idf-v4.4.7/components/esp_system/esp_system.c:137
0x400911c5: vApplicationStackOverflowHook at E:/esp-idf-v4.4.7/components/freertos/port/xtensa/port.c:407
0x400922f9: vTaskSwitchContext at E:/esp-idf-v4.4.7/components/freertos/tasks.c:3664
0x40090bc4: _frxt_dispatch at E:/esp-idf-v4.4.7/components/freertos/port/xtensa/portasm.S:436
0x40090b76: _frxt_int_exit at E:/esp-idf-v4.4.7/components/freertos/port/xtensa/portasm.S:231

ELF file SHA256: 44c960785f1493af

Rebooting...

Eventually after several reboots it will stop here:

I (3378) ESP_AUDIO_TASK: Recv Element[IN_flash-0x3f806724] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING I (3379) CODEC_ELEMENT_HELPER: Th element is 0x3f8068bc. The reserve data 2 is 0x0. I (3401) ESP_AUDIO_TASK: Recv Element[DEC_mp3-0x3f8068bc] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING I (3410) ESP_AUDIO_TASK: Received muisc info then on play I (3415) ESP_AUDIO_TASK: On event play, status:UNKNOWN, 0 I (3421) AUDIO_THREAD: The Audio_forge task allocate stack on external memory I (3431) AUDIO_FORGE: audio_forge opened I (3431) AUDIO_THREAD: The OUT_iis task allocate stack on external memory I (3442) I2S_STREAM: AUDIO_STREAM_WRITER I (3446) ESP_AUDIO_TASK: Recv Element[OUT_iis-0x3f806a70] MSG,type:20000,cmd:8,len:4,status:AEL_STATUS_STATE_RUNNING

Other Items If Possible

s [Uploading voip_app.elf.txt…]() dkconfig.txt

laodi-chen commented 6 months ago

俺也一样,rtc与voip相关文档严重不足,官方例程也是古老破旧,想要自己实现voip完全无从下手,可以说整个adf就好像没有一样

TempoTian commented 6 months ago

I have checked this issue on IDFv4.4.5 and IDF5.2 both verison can not reproduce the stackoverflow issue. voip.zip To debug overflow issue, you can manually enlarge stack size, for I2s stream, if you do not know where the config come from can manually change code: https://github.com/espressif/esp-adf/blob/master/components/audio_stream/i2s_stream.c#L410C8-L410C41

If it is caused by memory overwrote you can turn on the watch point CONFIG_FREERTOS_WATCHPOINT_END_OF_STACK to check where the overwrote come from in tasks.c

#ifdef ESP_PLATFORM
        xSwitchingContext[ xPortGetCoreID() ] = pdFALSE;
        #if CONFIG_FREERTOS_WATCHPOINT_END_OF_STACK
        vPortSetStackWatchpoint(pxCurrentTCB[xPortGetCoreID()]->pxStack);
        #endif
#else
migmelccs commented 6 months ago

I have checked this issue on IDFv4.4.5 and IDF5.2 both verison can not reproduce the stackoverflow issue.

Thank you, it's kind of weird. I tried first using v5.2 and got a runtime incompatibility error between i2s.h(deprecated) and the new i2s headers. This is the runtime error I get when using IDF v5.2.1: E (966) i2s(legacy): CONFLICT! The new i2s driver can't work along with the legacy i2s driver Apparently there are still some code using the old headers in the ADF framework.

Have you been able to establish a real call? Now, moving to IDF v4.4.7 I have realized that the error someway comes from the embedded audio tones, because when the tones are not uploaded I just receive the errors about it not being able to read flash tone partition, but when uploading the tones i get the mentioned overflow errors and I get some sounds such as cracking or bubbles exploding. I don't know what i am doing so wrong, because this is the original partition file:

# Name, Type, SubType, Offset, Size, Flags nvs, data, nvs, 0x9000, 0x6000, phy_init, data, phy, 0xf000, 0x1000, factory, app, factory, 0x10000, 2M, flash_tone,data, 0xff, 0x210000 , 500K,

And this is the command to upload the tones to the flash:

python E:/esp-idf-v4.4.7/esp-adf-master/esp-idf/components/esptool_py/esptool/esptool.py --chip esp32 --port COM12 --baud 921600 --before default_reset --after hard_reset write_flash -z --flash_mode dio --flash_freq 40m --flash_size detect 0x210000 ../components/audio_flash_tone/bin/audio-esp.bin

As I understand it, the command is in accordance with the memory position of the partition. So, it should not be memory conflict in this case. All attempts I've made have used both ESP32-LyraT-Mini-v1.2 and ESP32-S3-Korvo-2 v3.1 and with both idfv4.4 and idfv5.2 with the original example packed with its respective IDF/ADF versions. All don't run as expected without modification. If you have a code that actually runs without errors, would you please share it with me ?

TempoTian commented 6 months ago

I will try the latest ADF and the default IDF in it and share with you the test results

laodi-chen commented 6 months ago

不要下载flash提示音就不会产生堆栈溢出,清空分区后重新编译下载,使用idf4.4.7可以正常运行

TempoTian commented 6 months ago

We always use idf.py to flash binary, I think can try idf.py firstly to check whether it is all right or not. 可以先试下用 idf.py 来下载程序,看能否正常 idf.py -p *** flash monitor

TempoTian commented 6 months ago

I have reproduced on latest version. Bug is caused by change: https://github.com/espressif/esp-adf/commit/8cc2edc693c4faa4152ced42bf0ce34664723c7b#diff-e8182213449674e98ba2e7dc27c0ef07ce53499f3de4a59b238614825f6da771 which cause infinite recursive call. You can rollback audio_player_init_tone.c or use follow code:

/*
 * ESPRESSIF MIT License
 *
 * Copyright (c) 2021 <ESPRESSIF SYSTEMS (SHANGHAI) CO., LTD>
 *
 * Permission is hereby granted for use on all ESPRESSIF SYSTEMS products, in which case,
 * it is free of charge, to any person obtaining a copy of this software and associated
 * documentation files (the "Software"), to deal in the Software without restriction, including
 * without limitation the rights to use, copy, modify, merge, publish, distribute, sublicense,
 * and/or sell copies of the Software, and to permit persons to whom the Software is furnished
 * to do so, subject to the following conditions:
 *
 * The above copyright notice and this permission notice shall be included in all copies or
 * substantial portions of the Software.
 *
 * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
 * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, FITNESS
 * FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR
 * COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER
 * IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN
 * CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
 *
 */
#include <string.h>

#include "esp_log.h"
#include "audio_error.h"
#include "esp_audio.h"
#include "tone_stream.h"
#include "mp3_decoder.h"
#include "i2s_stream.h"
#include "algorithm_stream.h"
#include "audio_player_int_tone.h"

static const char *TAG = "PLAYER_INT_TONE";

static esp_audio_handle_t player;
static stream_func origin_write_cb;

static int i2s_write_cb(audio_element_handle_t el, char *buf, int len, TickType_t wait_time, void *ctx)
{
    size_t bytes_write = 0, size = len;

#ifndef CONFIG_ESP32_S3_KORVO2L_V1_BOARD
    /* Drop right channel */
    int16_t *tmp = (int16_t *)buf;
    for (int i = 0; i < len / 4; i++) {
        tmp[i] = tmp[i << 1];
    }
    size = len / 2;
#endif

#if CONFIG_IDF_TARGET_ESP32
    algorithm_mono_fix((uint8_t *)buf, size);
#endif
    if (origin_write_cb) {
        bytes_write = origin_write_cb(el, buf, len, wait_time, ctx);
    }
    return bytes_write;
}

audio_err_t audio_player_int_tone_init(int sample_rate, int channel_format, int bits_per_sample)
{
    esp_audio_cfg_t cfg = DEFAULT_ESP_AUDIO_CONFIG();
    cfg.prefer_type = ESP_AUDIO_PREFER_MEM;
    cfg.resample_rate = sample_rate;
    player = esp_audio_create(&cfg);
    AUDIO_MEM_CHECK(TAG, player, return ESP_FAIL;);

    // Create readers and add to esp_audio
    tone_stream_cfg_t tn_reader = TONE_STREAM_CFG_DEFAULT();
    tn_reader.type = AUDIO_STREAM_READER;
    tn_reader.task_core = 1;
    esp_audio_input_stream_add(player, tone_stream_init(&tn_reader));

    // Add decoders and encoders to esp_audio
    mp3_decoder_cfg_t mp3_dec_cfg = DEFAULT_MP3_DECODER_CONFIG();
    mp3_dec_cfg.task_core = 1;
    mp3_dec_cfg.task_prio = 20;
    esp_audio_codec_lib_add(player, AUDIO_CODEC_TYPE_DECODER, mp3_decoder_init(&mp3_dec_cfg));

    i2s_stream_cfg_t i2s_writer_cfg = I2S_STREAM_CFG_DEFAULT();
    i2s_writer_cfg.type = AUDIO_STREAM_WRITER;
    i2s_writer_cfg.stack_in_ext = true;
    i2s_writer_cfg.i2s_config.sample_rate = sample_rate;
    i2s_writer_cfg.i2s_config.channel_format = channel_format;
    i2s_writer_cfg.i2s_config.bits_per_sample = bits_per_sample;
    i2s_writer_cfg.task_core = 1;
    audio_element_handle_t i2s_writer = i2s_stream_init(&i2s_writer_cfg);
    origin_write_cb = audio_element_get_write_cb(i2s_writer);
    esp_audio_output_stream_add(player, i2s_writer);
    audio_element_set_write_cb(i2s_writer, i2s_write_cb, NULL);
    audio_element_set_output_timeout(i2s_writer, portMAX_DELAY);

    return ESP_OK;
}

audio_err_t audio_player_int_tone_stop()
{
    esp_audio_stop(player, TERMINATION_TYPE_NOW);
    return ESP_OK;
}

audio_err_t audio_player_int_tone_play(const char *url)
{
    esp_audio_play(player, AUDIO_CODEC_TYPE_DECODER, url, 0);
    return ESP_OK;
}
migmelccs commented 6 months ago

可以先试下用 idf.py 来下载程序,看能否正常

Yes, it works without uploading the tones( as also suggested by @chen-laodi). It does not work as it should, but I have managed to make it work fine without having to modify IDF files. I can make calls and even receive calls from a SIP client such as Zoiper, the only problem is that without the tones there is not ringing when incoming calls arrive. I am currently customizing a ringing function, however it would have been better and cleaner if the example tones worked as expected.

migmelccs commented 6 months ago

You can rollback audio_player_init_tone.c or use follow code

Thank you, I will try it and let you know the results

migmelccs commented 6 months ago

Thank you, I will try it and let you know the results

Well, it worked! Thank you. Although the alarm wouldn't be my first option for ringing but I guess I cam make my own set of tones. The most important is the failure was solved. Thank you again

laodi-chen commented 6 months ago

@TempoTian 顺便再问一下,声音很小怎么回事,喇叭是4Ω3w钕磁铁品质很好,声音已经调到最大了,使用pipeline_http_mp3例程声音也不是很大,有没有什么办法可以再加大一些声音

TempoTian commented 6 months ago

看下你的PA的实际增益是放大多少,目前对不同的板子增益配置的不一样,要匹配下,对 layrtmini设置的是 20db https://github.com/espressif/esp-adf/blob/master/components/audio_board/lyrat_mini_v1_1/board_def.h#L62 如果没有增益这么多可以把这个值调小,这样同样的音量映射到 codec 的音量就会变大 (避免由于PA导致的饱和现象) 之前加这个是为了解决不同平台同一音量下连接相同 codec 和喇叭,声音不一致的问题

laodi-chen commented 6 months ago

@TempoTian 那再请教一下麦克风拾音大小怎么能调整一下:)

TempoTian commented 6 months ago

对于8311录制播放公用的,目前ADF没对外释放API调mic的音量可以手动到函数里面改,对于mini的板子可以用get到codec hal的handle然后通过hal的API来调节

audio_hal_set_volume(audio_board_get_handle()->adc_hal, vol)
laodi-chen commented 6 months ago

https://github.com/espressif/esp-adf/assets/40551848/0ac581ca-60d2-46e3-b86d-e4335e49dbec

@TempoTian 对于mp3播放他听起来噪音很大,我很能确定我的网络无比的通常,这是音频地址https://static-web-file-001.obs.cn-north-4.myhuaweicloud.com/bin/Me.mp3

TempoTian commented 6 months ago

建议你单独开一个issue来追踪这个问题,听起来像是decoder的问题

laodi-chen commented 6 months ago

@TempoTian 老哥,audio_hal_set_volume我看只是设置了喇叭声音的大小,并没有直接改变麦克风拾音的大小呢,另外我提交了关于噪音的议题你那里有人方便帮看看呗

TempoTian commented 6 months ago

dac是输出的,adc是输入的,有两个handle是可以调节的 audio_board_get_handle()->adc_hal, mini用的是es7243最后会设定到 https://github.com/espressif/esp-adf/blob/master/components/audio_hal/driver/es7243/es7243.c#L147 noise会有另外的同事来看

laodi-chen commented 6 months ago

@TempoTian esp_err_t es7243_adc_set_voice_volume(int volume);我已经在内部修改成了100,但声音依旧不是很大,距离麦克风10厘米远,linPhone那里喇叭显示的最高也就30%那样,mini板子用的麦克风灵敏度信噪比多少跟麦克风有关系么

TempoTian commented 6 months ago

i2s stream config有一个配置可以使能ALC 来用软件改变增益, 可以用软件来增大下音量 0 以上属于增加增益,对应也有API可以调节

typedef struct {
    bool                  use_alc;         /*!< It is a flag for ALC. If use ALC, the value is true. Or the value is false */
    int                   volume;          /*!< The volume of audio input data will be set. */
must be a multiple of 3. The recommended value is 3600 */
} i2s_stream_cfg_t;
laodi-chen commented 6 months ago

@TempoTian 老哥,我将代码回滚到了https://github.com/espressif/esp-adf/issues/1169#issuecomment-2011127152,但是提示音听起来很慢就像是sample rate没有设置正常一样,idf-4.4.7 adf-master

jason-mao commented 6 months ago

@chen-laodi 由于你的问题和这个问题的标题不符,我将关闭这个问题。你的问题我会在https://github.com/espressif/esp-adf/issues/1174 里面回复。